Thanks Fabrice raddebug output:
(727) Mon Oct 26 15:54:22 2020: Debug: Received Access-Request Id 132 from X.X.X.X:55645 to X.X.X.X:1812 length 191 (727) Mon Oct 26 15:54:22 2020: Debug: Service-Type = Framed-User (727) Mon Oct 26 15:54:22 2020: Debug: Framed-Protocol = PPP (727) Mon Oct 26 15:54:22 2020: Debug: NAS-Port = 39 (727) Mon Oct 26 15:54:22 2020: Debug: NAS-Port-Type = Virtual (727) Mon Oct 26 15:54:22 2020: Debug: User-Name = "coyo" (727) Mon Oct 26 15:54:22 2020: Debug: Calling-Station-Id = "X.X.X.X" (727) Mon Oct 26 15:54:22 2020: Debug: Called-Station-Id = "X.X.X.X" (727) Mon Oct 26 15:54:22 2020: Debug: Acct-Session-Id = "81d00cdf" (727) Mon Oct 26 15:54:22 2020: Debug: MS-CHAP-Challenge = 0xebf6d832753d4fdf8383548a74da2637 (727) Mon Oct 26 15:54:22 2020: Debug: MS-CHAP2-Response = 0x0100abb873a94cda9a306246c4fef05e7a900000000000000000b44e09097c106ee6479636c7545e3fdd9b27a86cdbfa77a5 (727) Mon Oct 26 15:54:22 2020: Debug: NAS-Identifier = "MK-IBERA2" (727) Mon Oct 26 15:54:22 2020: Debug: NAS-IP-Address = X.X.X.X (727) Mon Oct 26 15:54:22 2020: Debug: # Executing section authorize from file /usr/local/pf/raddb/sites-enabled/packetfence (727) Mon Oct 26 15:54:22 2020: Debug: authorize { (727) Mon Oct 26 15:54:22 2020: Debug: policy packetfence-nas-ip-address { (727) Mon Oct 26 15:54:22 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0"){ (727) Mon Oct 26 15:54:22 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0") -> FALSE (727) Mon Oct 26 15:54:22 2020: Debug: } # policy packetfence-nas-ip-address = notfound (727) Mon Oct 26 15:54:22 2020: Debug: update { (727) Mon Oct 26 15:54:22 2020: Debug: EXPAND %{Packet-Src-IP-Address} (727) Mon Oct 26 15:54:22 2020: Debug: --> X.X.X.X (727) Mon Oct 26 15:54:22 2020: Debug: EXPAND %{Packet-Dst-IP-Address} (727) Mon Oct 26 15:54:22 2020: Debug: --> X.X.X.X (727) Mon Oct 26 15:54:22 2020: Debug: EXPAND %l (727) Mon Oct 26 15:54:22 2020: Debug: --> 1603738462 (727) Mon Oct 26 15:54:22 2020: Debug: } # update = noop (727) Mon Oct 26 15:54:22 2020: Debug: policy packetfence-set-realm-if-machine { (727) Mon Oct 26 15:54:22 2020: Debug: if (User-Name =~ /host\/([a-z0-9_-]*)[\.](.*)/i) { (727) Mon Oct 26 15:54:22 2020: Debug: if (User-Name =~ /host\/([a-z0-9_-]*)[\.](.*)/i) -> FALSE (727) Mon Oct 26 15:54:22 2020: Debug: } # policy packetfence-set-realm-if-machine = noop (727) Mon Oct 26 15:54:22 2020: Debug: policy packetfence-balanced-key-policy { (727) Mon Oct 26 15:54:22 2020: Debug: if (&PacketFence-KeyBalanced && (&PacketFence-KeyBalanced =~ /^(.*)(.)$/i)) { (727) Mon Oct 26 15:54:22 2020: Debug: if (&PacketFence-KeyBalanced && (&PacketFence-KeyBalanced =~ /^(.*)(.)$/i)) -> FALSE (727) Mon Oct 26 15:54:22 2020: Debug: else { (727) Mon Oct 26 15:54:22 2020: Debug: update { (727) Mon Oct 26 15:54:22 2020: Debug: EXPAND %{md5:%{Calling-Station-Id}%{User-Name}} (727) Mon Oct 26 15:54:22 2020: Debug: --> 865fdf018805bc0bc5fbb22eaa6b0a60 (727) Mon Oct 26 15:54:22 2020: Debug: EXPAND %{md5:%{Calling-Station-Id}%{User-Name}} (727) Mon Oct 26 15:54:22 2020: Debug: --> 865fdf018805bc0bc5fbb22eaa6b0a60 (727) Mon Oct 26 15:54:22 2020: Debug: } # update = noop (727) Mon Oct 26 15:54:22 2020: Debug: } # else = noop (727) Mon Oct 26 15:54:22 2020: Debug: } # policy packetfence-balanced-key-policy = noop (727) Mon Oct 26 15:54:22 2020: Debug: policy packetfence-set-tenant-id { (727) Mon Oct 26 15:54:22 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0"){ (727) Mon Oct 26 15:54:22 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0") -> FALSE (727) Mon Oct 26 15:54:22 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") { (727) Mon Oct 26 15:54:22 2020: Debug: EXPAND %{%{control:PacketFence-Tenant-Id}:-0} (727) Mon Oct 26 15:54:22 2020: Debug: --> 0 (727) Mon Oct 26 15:54:22 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") -> TRUE (727) Mon Oct 26 15:54:22 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") { (727) Mon Oct 26 15:54:22 2020: Debug: update control { (727) Mon Oct 26 15:54:22 2020: Debug: EXPAND %{User-Name} (727) Mon Oct 26 15:54:22 2020: Debug: --> coyo (727) Mon Oct 26 15:54:22 2020: Debug: SQL-User-Name set to 'coyo' (727) Mon Oct 26 15:54:22 2020: Debug: Executing select query: SELECT IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname = 'X.X.X.X'), 0) (727) Mon Oct 26 15:54:22 2020: Debug: EXPAND %{sql: SELECT IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname = '%{NAS-IP-Address}'), 0)} (727) Mon Oct 26 15:54:22 2020: Debug: --> 1 (727) Mon Oct 26 15:54:22 2020: Debug: } # update control = noop (727) Mon Oct 26 15:54:22 2020: Debug: } # if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") = noop (727) Mon Oct 26 15:54:22 2020: Debug: if ( &control:PacketFence-Tenant-Id == 0 ) { (727) Mon Oct 26 15:54:22 2020: Debug: if ( &control:PacketFence-Tenant-Id == 0 ) -> FALSE (727) Mon Oct 26 15:54:22 2020: Debug: } # policy packetfence-set-tenant-id = noop (727) Mon Oct 26 15:54:22 2020: Debug: policy rewrite_calling_station_id { (727) Mon Oct 26 15:54:22 2020: Debug: if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) { (727) Mon Oct 26 15:54:22 2020: Debug: if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) -> FALSE (727) Mon Oct 26 15:54:22 2020: Debug: else { (727) Mon Oct 26 15:54:22 2020: Debug: [noop] = noop (727) Mon Oct 26 15:54:22 2020: Debug: } # else = noop (727) Mon Oct 26 15:54:22 2020: Debug: } # policy rewrite_calling_station_id = noop (727) Mon Oct 26 15:54:22 2020: Debug: policy rewrite_called_station_id { (727) Mon Oct 26 15:54:22 2020: Debug: if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) { (727) Mon Oct 26 15:54:22 2020: Debug: if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) -> FALSE (727) Mon Oct 26 15:54:22 2020: Debug: else { (727) Mon Oct 26 15:54:22 2020: Debug: [noop] = noop (727) Mon Oct 26 15:54:22 2020: Debug: } # else = noop (727) Mon Oct 26 15:54:22 2020: Debug: } # policy rewrite_called_station_id = noop (727) Mon Oct 26 15:54:22 2020: Debug: if ( "%{client:shortname}" =~ /eduroam_tlrs/ ) { (727) Mon Oct 26 15:54:22 2020: Debug: EXPAND %{client:shortname} (727) Mon Oct 26 15:54:22 2020: Debug: --> X.X.X.X/32 (727) Mon Oct 26 15:54:22 2020: Debug: if ( "%{client:shortname}" =~ /eduroam_tlrs/ ) -> FALSE (727) Mon Oct 26 15:54:22 2020: Debug: policy filter_username { (727) Mon Oct 26 15:54:22 2020: Debug: if (&User-Name) { (727) Mon Oct 26 15:54:22 2020: Debug: if (&User-Name) -> TRUE (727) Mon Oct 26 15:54:22 2020: Debug: if (&User-Name) { (727) Mon Oct 26 15:54:22 2020: Debug: if (&User-Name =~ / /) { (727) Mon Oct 26 15:54:22 2020: Debug: if (&User-Name =~ / /) -> FALSE (727) Mon Oct 26 15:54:22 2020: Debug: if (&User-Name =~ /@[^@]*@/ ) { (727) Mon Oct 26 15:54:22 2020: Debug: if (&User-Name =~ /@[^@]*@/ ) -> FALSE (727) Mon Oct 26 15:54:22 2020: Debug: if (&User-Name =~ /\.\./ ) { (727) Mon Oct 26 15:54:22 2020: Debug: if (&User-Name =~ /\.\./ ) -> FALSE (727) Mon Oct 26 15:54:22 2020: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) { (727) Mon Oct 26 15:54:22 2020: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) -> FALSE (727) Mon Oct 26 15:54:22 2020: Debug: if (&User-Name =~ /\.$/) { (727) Mon Oct 26 15:54:22 2020: Debug: if (&User-Name =~ /\.$/) -> FALSE (727) Mon Oct 26 15:54:22 2020: Debug: if (&User-Name =~ /@\./) { (727) Mon Oct 26 15:54:22 2020: Debug: if (&User-Name =~ /@\./) -> FALSE (727) Mon Oct 26 15:54:22 2020: Debug: } # if (&User-Name) = noop (727) Mon Oct 26 15:54:22 2020: Debug: } # policy filter_username = noop (727) Mon Oct 26 15:54:22 2020: Debug: policy filter_password { (727) Mon Oct 26 15:54:22 2020: Debug: if (&User-Password && (&User-Password != "%{string:User-Password}")) { (727) Mon Oct 26 15:54:22 2020: Debug: if (&User-Password && (&User-Password != "%{string:User-Password}")) -> FALSE (727) Mon Oct 26 15:54:22 2020: Debug: } # policy filter_password = noop (727) Mon Oct 26 15:54:22 2020: Debug: [preprocess] = ok (727) Mon Oct 26 15:54:22 2020: Debug: mschap: Found MS-CHAP attributes. Setting 'Auth-Type = mschap' (727) Mon Oct 26 15:54:22 2020: Debug: [mschap] = ok (727) Mon Oct 26 15:54:22 2020: Debug: suffix: Checking for suffix after "@" (727) Mon Oct 26 15:54:22 2020: Debug: suffix: No '@' in User-Name = "coyo", skipping NULL due to config. (727) Mon Oct 26 15:54:22 2020: Debug: [suffix] = noop (727) Mon Oct 26 15:54:22 2020: Debug: ntdomain: Checking for prefix before "\" (727) Mon Oct 26 15:54:22 2020: Debug: ntdomain: No '\' in User-Name = "coyo", looking up realm NULL (727) Mon Oct 26 15:54:22 2020: Debug: ntdomain: Found realm "null" (727) Mon Oct 26 15:54:22 2020: Debug: ntdomain: Adding Stripped-User-Name = "coyo" (727) Mon Oct 26 15:54:22 2020: Debug: ntdomain: Adding Realm = "null" (727) Mon Oct 26 15:54:22 2020: Debug: ntdomain: Authentication realm is LOCAL (727) Mon Oct 26 15:54:22 2020: Debug: [ntdomain] = ok (727) Mon Oct 26 15:54:22 2020: Debug: if (Realm =~ /default/) { (727) Mon Oct 26 15:54:22 2020: Debug: if (Realm =~ /default/) -> FALSE (727) Mon Oct 26 15:54:22 2020: Debug: elsif (Realm =~ /local/) { (727) Mon Oct 26 15:54:22 2020: Debug: elsif (Realm =~ /local/) -> FALSE (727) Mon Oct 26 15:54:22 2020: Debug: elsif (Realm =~ /null/) { (727) Mon Oct 26 15:54:22 2020: Debug: elsif (Realm =~ /null/) -> TRUE (727) Mon Oct 26 15:54:22 2020: Debug: elsif (Realm =~ /null/) { (727) Mon Oct 26 15:54:22 2020: Debug: PEAP: No EAP-Message, not doing EAP (727) Mon Oct 26 15:54:22 2020: Debug: [PEAP] = noop (727) Mon Oct 26 15:54:22 2020: Debug: } # elsif (Realm =~ /null/) = noop (727) Mon Oct 26 15:54:22 2020: Debug: ... skipping else: Preceding "if" was taken (727) Mon Oct 26 15:54:22 2020: Debug: if ( !EAP-Message && "%{%{Control:Auth-type}:-No-MS_CHAP}" != "MS-CHAP") { (727) Mon Oct 26 15:54:22 2020: Debug: EXPAND %{%{Control:Auth-type}:-No-MS_CHAP} (727) Mon Oct 26 15:54:22 2020: Debug: --> MS-CHAP (727) Mon Oct 26 15:54:22 2020: Debug: if ( !EAP-Message && "%{%{Control:Auth-type}:-No-MS_CHAP}" != "MS-CHAP") -> FALSE (727) Mon Oct 26 15:54:22 2020: Debug: if (Control:Auth-type == "MS-CHAP") { (727) Mon Oct 26 15:54:22 2020: Debug: if (Control:Auth-type == "MS-CHAP") -> TRUE (727) Mon Oct 26 15:54:22 2020: Debug: if (Control:Auth-type == "MS-CHAP") { (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'User-Name'} = &request:User-Name -> 'coyo' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'NAS-IP-Address'} = &request:NAS-IP-Address -> 'X.X.X.X' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'NAS-Port'} = &request:NAS-Port -> '39' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'Service-Type'} = &request:Service-Type -> 'Framed-User' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'Framed-Protocol'} = &request:Framed-Protocol -> 'PPP' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'Called-Station-Id'} = &request:Called-Station-Id -> 'X.X.X.X' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'Calling-Station-Id'} = &request:Calling-Station-Id -> 'X.X.X.X' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'NAS-Identifier'} = &request:NAS-Identifier -> 'MK-IBERA2' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'NAS-Port-Type'} = &request:NAS-Port-Type -> 'Virtual' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'Acct-Session-Id'} = &request:Acct-Session-Id -> '81d00cdf' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'Event-Timestamp'} = &request:Event-Timestamp -> 'Oct 26 2020 15:54:22 -03' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'MS-CHAP-Challenge'} = &request:MS-CHAP-Challenge -> '0xebf6d832753d4fdf8383548a74da2637' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'MS-CHAP2-Response'} = &request:MS-CHAP2-Response -> '0x0100abb873a94cda9a306246c4fef05e7a900000000000000000b44e09097c106ee6479636c7545e3fdd9b27a86cdbfa77a5' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'Stripped-User-Name'} = &request:Stripped-User-Name -> 'coyo' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'Realm'} = &request:Realm -> 'null' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'SQL-User-Name'} = &request:SQL-User-Name -> 'coyo' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'FreeRADIUS-Client-IP-Address'} = &request:FreeRADIUS-Client-IP-Address -> 'X.X.X.X' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'PacketFence-KeyBalanced'} = &request:PacketFence-KeyBalanced -> '865fdf018805bc0bc5fbb22eaa6b0a60' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'PacketFence-Radius-Ip'} = &request:PacketFence-Radius-Ip -> 'X.X.X.X' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_CHECK{'Auth-Type'} = &control:Auth-Type -> 'MS-CHAP' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_CHECK{'Load-Balance-Key'} = &control:Load-Balance-Key -> '865fdf018805bc0bc5fbb22eaa6b0a60' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_CHECK{'Tmp-Integer-0'} = &control:Tmp-Integer-0 -> '1603738462' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_CHECK{'PacketFence-RPC-Server'} = &control:PacketFence-RPC-Server -> '127.0.0.1' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_CHECK{'PacketFence-RPC-Port'} = &control:PacketFence-RPC-Port -> '7070' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_CHECK{'PacketFence-RPC-User'} = &control:PacketFence-RPC-User -> '' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_CHECK{'PacketFence-RPC-Pass'} = &control:PacketFence-RPC-Pass -> '''' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_CHECK{'PacketFence-RPC-Proto'} = &control:PacketFence-RPC-Proto -> 'http' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_CHECK{'PacketFence-Request-Time'} = &control:PacketFence-Request-Time -> '0' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_CHECK{'PacketFence-Tenant-Id'} = &control:PacketFence-Tenant-Id -> '1' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_CONFIG{'Auth-Type'} = &control:Auth-Type -> 'MS-CHAP' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_CONFIG{'Load-Balance-Key'} = &control:Load-Balance-Key -> '865fdf018805bc0bc5fbb22eaa6b0a60' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_CONFIG{'Tmp-Integer-0'} = &control:Tmp-Integer-0 -> '1603738462' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_CONFIG{'PacketFence-RPC-Server'} = &control:PacketFence-RPC-Server -> '127.0.0.1' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_CONFIG{'PacketFence-RPC-Port'} = &control:PacketFence-RPC-Port -> '7070' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_CONFIG{'PacketFence-RPC-User'} = &control:PacketFence-RPC-User -> '' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_CONFIG{'PacketFence-RPC-Pass'} = &control:PacketFence-RPC-Pass -> '''' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_CONFIG{'PacketFence-RPC-Proto'} = &control:PacketFence-RPC-Proto -> 'http' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_CONFIG{'PacketFence-Request-Time'} = &control:PacketFence-Request-Time -> '0' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: $RAD_CONFIG{'PacketFence-Tenant-Id'} = &control:PacketFence-Tenant-Id -> '1' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: &request:NAS-Port-Type = $RAD_REQUEST{'NAS-Port-Type'} -> 'Virtual' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: &request:Acct-Session-Id = $RAD_REQUEST{'Acct-Session-Id'} -> '81d00cdf' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: &request:PacketFence-Radius-Ip = $RAD_REQUEST{'PacketFence-Radius-Ip'} -> 'X.X.X.X' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: &request:Service-Type = $RAD_REQUEST{'Service-Type'} -> 'Framed-User' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: &request:Called-Station-Id = $RAD_REQUEST{'Called-Station-Id'} -> 'X.X.X.X' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: &request:Realm = $RAD_REQUEST{'Realm'} -> 'null' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: &request:NAS-IP-Address = $RAD_REQUEST{'NAS-IP-Address'} -> 'X.X.X.X' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: &request:SQL-User-Name = $RAD_REQUEST{'SQL-User-Name'} -> 'coyo' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: &request:PacketFence-NTLMv2-Only = $RAD_REQUEST{'PacketFence-NTLMv2-Only'} -> '' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: &request:Calling-Station-Id = $RAD_REQUEST{'Calling-Station-Id'} -> 'X.X.X.X' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: &request:PacketFence-KeyBalanced = $RAD_REQUEST{'PacketFence-KeyBalanced'} -> '865fdf018805bc0bc5fbb22eaa6b0a60' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: &request:FreeRADIUS-Client-IP-Address = $RAD_REQUEST{'FreeRADIUS-Client-IP-Address'} -> 'X.X.X.X' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: &request:MS-CHAP-Challenge = $RAD_REQUEST{'MS-CHAP-Challenge'} -> '0xebf6d832753d4fdf8383548a74da2637' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: &request:Framed-Protocol = $RAD_REQUEST{'Framed-Protocol'} -> 'PPP' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: &request:User-Name = $RAD_REQUEST{'User-Name'} -> 'coyo' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: &request:NAS-Identifier = $RAD_REQUEST{'NAS-Identifier'} -> 'MK-IBERA2' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: &request:Event-Timestamp = $RAD_REQUEST{'Event-Timestamp'} -> 'Oct 26 2020 15:54:22 -03' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: &request:MS-CHAP2-Response = $RAD_REQUEST{'MS-CHAP2-Response'} -> '0x0100abb873a94cda9a306246c4fef05e7a900000000000000000b44e09097c106ee6479636c7545e3fdd9b27a86cdbfa77a5' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: &request:NAS-Port = $RAD_REQUEST{'NAS-Port'} -> '39' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: &request:Stripped-User-Name = $RAD_REQUEST{'Stripped-User-Name'} -> 'coyo' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: &control:Load-Balance-Key = $RAD_CHECK{'Load-Balance-Key'} -> '865fdf018805bc0bc5fbb22eaa6b0a60' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: &control:PacketFence-RPC-Server = $RAD_CHECK{'PacketFence-RPC-Server'} -> '127.0.0.1' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: &control:PacketFence-Tenant-Id = $RAD_CHECK{'PacketFence-Tenant-Id'} -> '1' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: &control:PacketFence-RPC-User = $RAD_CHECK{'PacketFence-RPC-User'} -> '' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: &control:PacketFence-Request-Time = $RAD_CHECK{'PacketFence-Request-Time'} -> '0' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: &control:Auth-Type = $RAD_CHECK{'Auth-Type'} -> 'MS-CHAP' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: &control:PacketFence-RPC-Pass = $RAD_CHECK{'PacketFence-RPC-Pass'} -> '''' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: &control:Tmp-Integer-0 = $RAD_CHECK{'Tmp-Integer-0'} -> '1603738462' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: &control:PacketFence-RPC-Proto = $RAD_CHECK{'PacketFence-RPC-Proto'} -> 'http' (727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain: &control:PacketFence-RPC-Port = $RAD_CHECK{'PacketFence-RPC-Port'} -> '7070' (727) Mon Oct 26 15:54:22 2020: Debug: [packetfence-multi-domain] = updated (727) Mon Oct 26 15:54:22 2020: Debug: } # if (Control:Auth-type == "MS-CHAP") = updated (727) Mon Oct 26 15:54:22 2020: Debug: policy packetfence-eap-mac-policy { (727) Mon Oct 26 15:54:22 2020: Debug: if ( &EAP-Type ) { (727) Mon Oct 26 15:54:22 2020: Debug: if ( &EAP-Type ) -> FALSE (727) Mon Oct 26 15:54:22 2020: Debug: [noop] = noop (727) Mon Oct 26 15:54:22 2020: Debug: } # policy packetfence-eap-mac-policy = noop (727) Mon Oct 26 15:54:22 2020: WARNING: pap: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! (727) Mon Oct 26 15:54:22 2020: WARNING: pap: !!! Ignoring control:User-Password. Update your !!! (727) Mon Oct 26 15:54:22 2020: WARNING: pap: !!! configuration so that the "known good" clear text !!! (727) Mon Oct 26 15:54:22 2020: WARNING: pap: !!! password is in Cleartext-Password and NOT in !!! (727) Mon Oct 26 15:54:22 2020: WARNING: pap: !!! User-Password. !!! (727) Mon Oct 26 15:54:22 2020: WARNING: pap: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! (727) Mon Oct 26 15:54:22 2020: Debug: [pap] = noop (727) Mon Oct 26 15:54:22 2020: Debug: } # authorize = updated (727) Mon Oct 26 15:54:22 2020: Debug: Found Auth-Type = MS-CHAP (727) Mon Oct 26 15:54:22 2020: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/packetfence (727) Mon Oct 26 15:54:22 2020: Debug: Auth-Type MS-CHAP { (727) Mon Oct 26 15:54:22 2020: Debug: policy packetfence-mschap-authenticate { (727) Mon Oct 26 15:54:22 2020: Debug: if (PacketFence-Domain) { (727) Mon Oct 26 15:54:22 2020: Debug: if (PacketFence-Domain) -> FALSE (727) Mon Oct 26 15:54:22 2020: Debug: else { (727) Mon Oct 26 15:54:22 2020: Debug: if ( "%{User-Name}" =~ /^host\/.*/) { (727) Mon Oct 26 15:54:22 2020: Debug: EXPAND %{User-Name} (727) Mon Oct 26 15:54:22 2020: Debug: --> coyo (727) Mon Oct 26 15:54:22 2020: Debug: if ( "%{User-Name}" =~ /^host\/.*/) -> FALSE (727) Mon Oct 26 15:54:22 2020: Debug: else { (727) Mon Oct 26 15:54:22 2020: Debug: mschap: Creating challenge hash with username: coyo (727) Mon Oct 26 15:54:22 2020: Debug: mschap: Client is using MS-CHAPv2 (727) Mon Oct 26 15:54:22 2020: Debug: mschap: Executing: /usr/local/pf/bin/ntlm_auth_wrapper -p 8125 -- --request-nt-key --username=%{%{control:AD-Samaccountname}:-%{%{Stripped-User-Name}:-%{mschap:User-Name:-None}}} --challenge=%{mschap:Challenge:-00} --nt-response=%{mschap:NT-Response:-00}: (727) Mon Oct 26 15:54:22 2020: Debug: mschap: EXPAND --username=%{%{control:AD-Samaccountname}:-%{%{Stripped-User-Name}:-%{mschap:User-Name:-None}}} (727) Mon Oct 26 15:54:22 2020: Debug: mschap: --> --username=coyo (727) Mon Oct 26 15:54:22 2020: Debug: mschap: Creating challenge hash with username: coyo (727) Mon Oct 26 15:54:22 2020: Debug: mschap: EXPAND --challenge=%{mschap:Challenge:-00} (727) Mon Oct 26 15:54:22 2020: Debug: mschap: --> --challenge=1f4bcfae02f18a60 (727) Mon Oct 26 15:54:22 2020: Debug: mschap: EXPAND --nt-response=%{mschap:NT-Response:-00} (727) Mon Oct 26 15:54:22 2020: Debug: mschap: --> --nt-response=b44e09097c106ee6479636c7545e3fdd9b27a86cdbfa77a5 (727) Mon Oct 26 15:54:22 2020: ERROR: mschap: Program returned code (1) and output 'Reading winbind reply failed! (0xc0000001)' (727) Mon Oct 26 15:54:22 2020: ERROR: mschap: Reading winbind reply failed! (0xc0000001) (727) Mon Oct 26 15:54:22 2020: Debug: mschap: Authentication failed (727) Mon Oct 26 15:54:22 2020: Debug: [mschap] = fail (727) Mon Oct 26 15:54:22 2020: Debug: } # else = fail (727) Mon Oct 26 15:54:22 2020: Debug: } # else = fail (727) Mon Oct 26 15:54:22 2020: Debug: } # policy packetfence-mschap-authenticate = fail (727) Mon Oct 26 15:54:22 2020: Debug: } # Auth-Type MS-CHAP = fail (727) Mon Oct 26 15:54:22 2020: Debug: Failed to authenticate the user (727) Mon Oct 26 15:54:22 2020: Debug: Using Post-Auth-Type Reject (727) Mon Oct 26 15:54:22 2020: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/packetfence (727) Mon Oct 26 15:54:22 2020: Debug: Post-Auth-Type REJECT { (727) Mon Oct 26 15:54:22 2020: Debug: policy packetfence-set-tenant-id { (727) Mon Oct 26 15:54:22 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0"){ (727) Mon Oct 26 15:54:22 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0") -> FALSE (727) Mon Oct 26 15:54:22 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") { (727) Mon Oct 26 15:54:22 2020: Debug: EXPAND %{%{control:PacketFence-Tenant-Id}:-0} (727) Mon Oct 26 15:54:22 2020: Debug: --> 1 (727) Mon Oct 26 15:54:22 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") -> FALSE (727) Mon Oct 26 15:54:22 2020: Debug: if ( &control:PacketFence-Tenant-Id == 0 ) { (727) Mon Oct 26 15:54:22 2020: Debug: if ( &control:PacketFence-Tenant-Id == 0 ) -> FALSE (727) Mon Oct 26 15:54:22 2020: Debug: } # policy packetfence-set-tenant-id = noop (727) Mon Oct 26 15:54:22 2020: Debug: update { (727) Mon Oct 26 15:54:22 2020: Debug: } # update = noop (727) Mon Oct 26 15:54:22 2020: Debug: if (! EAP-Type || (EAP-Type != TTLS && EAP-Type != PEAP) ) { (727) Mon Oct 26 15:54:22 2020: Debug: if (! EAP-Type || (EAP-Type != TTLS && EAP-Type != PEAP) ) -> TRUE (727) Mon Oct 26 15:54:22 2020: Debug: if (! EAP-Type || (EAP-Type != TTLS && EAP-Type != PEAP) ) { (727) Mon Oct 26 15:54:22 2020: Debug: policy packetfence-audit-log-reject { (727) Mon Oct 26 15:54:22 2020: Debug: if (&User-Name && (&User-Name == "dummy")) { (727) Mon Oct 26 15:54:22 2020: Debug: if (&User-Name && (&User-Name == "dummy")) -> FALSE (727) Mon Oct 26 15:54:22 2020: Debug: else { (727) Mon Oct 26 15:54:22 2020: Debug: policy request-timing { (727) Mon Oct 26 15:54:22 2020: Debug: if ("%{%{control:PacketFence-Request-Time}:-0}" != 0) { (727) Mon Oct 26 15:54:22 2020: Debug: EXPAND %{%{control:PacketFence-Request-Time}:-0} (727) Mon Oct 26 15:54:22 2020: Debug: --> 0 (727) Mon Oct 26 15:54:22 2020: Debug: if ("%{%{control:PacketFence-Request-Time}:-0}" != 0) -> FALSE (727) Mon Oct 26 15:54:22 2020: Debug: } # policy request-timing = noop (727) Mon Oct 26 15:54:22 2020: Debug: sql_reject: EXPAND type.reject.query (727) Mon Oct 26 15:54:22 2020: Debug: sql_reject: --> type.reject.query (727) Mon Oct 26 15:54:22 2020: Debug: sql_reject: Using query template 'query' (727) Mon Oct 26 15:54:22 2020: Debug: sql_reject: EXPAND %{User-Name} (727) Mon Oct 26 15:54:22 2020: Debug: sql_reject: --> coyo (727) Mon Oct 26 15:54:22 2020: Debug: sql_reject: SQL-User-Name set to 'coyo' (727) Mon Oct 26 15:54:22 2020: Debug: sql_reject: EXPAND INSERT INTO radius_audit_log ( mac, ip, computer_name, user_name, stripped_user_name, realm, event_type, switch_id, switch_mac, switch_ip_address, radius_source_ip_address, called_station_id, calling_station_id, nas_port_type, ssid, nas_port_id, ifindex, nas_port, connection_type, nas_ip_address, nas_identifier, auth_status, reason, auth_type, eap_type, role, node_status, profile, source, auto_reg, is_phone, pf_domain, uuid, radius_request, radius_reply, request_time, tenant_id, radius_ip) VALUES ( '%{request:Calling-Station-Id}', '%{request:Framed-IP-Address}', '%{%{control:PacketFence-Computer-Name}:-N/A}', '%{request:User-Name}', '%{request:Stripped-User-Name}', '%{request:Realm}', 'Radius-Access-Request', '%{%{control:PacketFence-Switch-Id}:-N/A}', '%{%{control:PacketFence-Switch-Mac}:-N/A}', '%{%{control:PacketFence-Switch-Ip-Address}:-N/A}', '%{Packet-Src-IP-Address}', '%{request:Called-Station-Id}', '%{request:Calling-Station-Id}', '%{request:NAS-Port-Type}', '%{request:Called-Station-SSID}', '%{request:NAS-Port-Id}', '%{%{control:PacketFence-IfIndex}:-N/A}', '%{request:NAS-Port}', '%{%{control:PacketFence-Connection-Type}:-N/A}', '%{request:NAS-IP-Address}', '%{request:NAS-Identifier}', 'Reject', '%{request:Module-Failure-Message}', '%{control:Auth-Type}', '%{request:EAP-Type}', '%{%{control:PacketFence-Role}:-N/A}', '%{%{control:PacketFence-Status}:-N/A}', '%{%{control:PacketFence-Profile}:-N/A}', '%{%{control:PacketFence-Source}:-N/A}', '%{%{control:PacketFence-AutoReg}:-0}', '%{%{control:PacketFence-IsPhone}:-0}', '%{request:PacketFence-Domain}', '', '%{pairs:&request:[*]}','%{pairs:&reply:[*]}', '%{%{control:PacketFence-Request-Time}:-N/A}', '%{control:PacketFence-Tenant-Id}', '%{request:PacketFence-Radius-Ip}') (727) Mon Oct 26 15:54:22 2020: Debug: sql_reject: --> INSERT INTO radius_audit_log ( mac, ip, computer_name, user_name, stripped_user_name, realm, event_type, switch_id, switch_mac, switch_ip_address, radius_source_ip_address, called_station_id, calling_station_id, nas_port_type, ssid, nas_port_id, ifindex, nas_port, connection_type, nas_ip_address, nas_identifier, auth_status, reason, auth_type, eap_type, role, node_status, profile, source, auto_reg, is_phone, pf_domain, uuid, radius_request, radius_reply, request_time, tenant_id, radius_ip) VALUES ( 'X.X.X.X', '', 'N/A', 'coyo', 'coyo', 'null', 'Radius-Access-Request', 'N/A', 'N/A', 'N/A', 'X.X.X.X', 'X.X.X.X', 'X.X.X.X', 'Virtual', '', '', 'N/A', '39', 'N/A', 'X.X.X.X', 'MK-IBERA2', 'Reject', 'mschap: Program returned code (1) and output =27Reading winbind reply failed=21 (0xc0000001)=27', 'MS-CHAP', '', 'N/A', 'N/A', 'N/A', 'N/A', '0', '0', '', '', 'NAS-Port-Type =3D Virtual, Acct-Session-Id =3D =2281d00cdf=22, PacketFence-Radius-Ip =3D =22X.X.X.X=22, Service-Type =3D Framed-User, Called-Station-Id =3D =22X.X.X.X=22, Realm =3D =22null=22, NAS-IP-Address =3D X.X.X.X, PacketFence-NTLMv2-Only =3D =22=22, Calling-Station-Id =3D =22X.X.X.X=22, PacketFence-KeyBalanced =3D =22865fdf018805bc0bc5fbb22eaa6b0a60=22, FreeRADIUS-Client-IP-Address =3D X.X.X.X, MS-CHAP-Challenge =3D 0xebf6d832753d4fdf8383548a74da2637, Framed-Protocol =3D PPP, User-Name =3D =22coyo=22, NAS-Identifier =3D =22MK-IBERA2=22, Event-Timestamp =3D =22Oct 26 2020 15:54:22 -03=22, MS-CHAP2-Response =3D 0x0100abb873a94cda9a306246c4fef05e7a900000000000000000b44e09097c106ee6479636c7545e3fdd9b27a86cdbfa77a5, NAS-Port =3D 39, Stripped-User-Name =3D =22coyo=22, Module-Failure-Message =3D =22mschap: Program returned code (1) and output =27Reading winbind reply failed=21 (0xc0000001)=27=22, Module-Failure-Message =3D =22mschap: Reading winbind reply failed=21 (0xc0000001)=22, User-Password =3D =22=2A=2A=2A=2A=2A=2A=22, SQL-User-Name =3D =22coyo=22','MS-CHAP-Error =3D =22=5C001E=3D691 R=3D0 C=3Dc86ce57de86611d248ddad2f2eb690ab V=3D3 M=3DAuthentication failed=22', '0', '1', 'X.X.X.X') (727) Mon Oct 26 15:54:22 2020: Debug: sql_reject: Executing query: INSERT INTO radius_audit_log ( mac, ip, computer_name, user_name, stripped_user_name, realm, event_type, switch_id, switch_mac, switch_ip_address, radius_source_ip_address, called_station_id, calling_station_id, nas_port_type, ssid, nas_port_id, ifindex, nas_port, connection_type, nas_ip_address, nas_identifier, auth_status, reason, auth_type, eap_type, role, node_status, profile, source, auto_reg, is_phone, pf_domain, uuid, radius_request, radius_reply, request_time, tenant_id, radius_ip) VALUES ( 'X.X.X.X', '', 'N/A', 'coyo', 'coyo', 'null', 'Radius-Access-Request', 'N/A', 'N/A', 'N/A', 'X.X.X.X', 'X.X.X.X', 'X.X.X.X', 'Virtual', '', '', 'N/A', '39', 'N/A', 'X.X.X.X', 'MK-IBERA2', 'Reject', 'mschap: Program returned code (1) and output =27Reading winbind reply failed=21 (0xc0000001)=27', 'MS-CHAP', '', 'N/A', 'N/A', 'N/A', 'N/A', '0', '0', '', '', 'NAS-Port-Type =3D Virtual, Acct-Session-Id =3D =2281d00cdf=22, PacketFence-Radius-Ip =3D =22X.X.X.X=22, Service-Type =3D Framed-User, Called-Station-Id =3D =22X.X.X.X=22, Realm =3D =22null=22, NAS-IP-Address =3D X.X.X.X, PacketFence-NTLMv2-Only =3D =22=22, Calling-Station-Id =3D =22X.X.X.X=22, PacketFence-KeyBalanced =3D =22865fdf018805bc0bc5fbb22eaa6b0a60=22, FreeRADIUS-Client-IP-Address =3D X.X.X.X, MS-CHAP-Challenge =3D 0xebf6d832753d4fdf8383548a74da2637, Framed-Protocol =3D PPP, User-Name =3D =22coyo=22, NAS-Identifier =3D =22MK-IBERA2=22, Event-Timestamp =3D =22Oct 26 2020 15:54:22 -03=22, MS-CHAP2-Response =3D 0x0100abb873a94cda9a306246c4fef05e7a900000000000000000b44e09097c106ee6479636c7545e3fdd9b27a86cdbfa77a5, NAS-Port =3D 39, Stripped-User-Name =3D =22coyo=22, Module-Failure-Message =3D =22mschap: Program returned code (1) and output =27Reading winbind reply failed=21 (0xc0000001)=27=22, Module-Failure-Message =3D =22mschap: Reading winbind reply failed=21 (0xc0000001)=22, User-Password =3D =22=2A=2A=2A=2A=2A=2A=22, SQL-User-Name =3D =22coyo=22','MS-CHAP-Error =3D =22=5C001E=3D691 R=3D0 C=3Dc86ce57de86611d248ddad2f2eb690ab V=3D3 M=3DAuthentication failed=22', '0', '1', 'X.X.X.X') (727) Mon Oct 26 15:54:22 2020: Debug: sql_reject: SQL query returned: success (727) Mon Oct 26 15:54:22 2020: Debug: sql_reject: 1 record(s) updated (727) Mon Oct 26 15:54:22 2020: Debug: [sql_reject] = ok (727) Mon Oct 26 15:54:22 2020: Debug: } # else = ok (727) Mon Oct 26 15:54:22 2020: Debug: } # policy packetfence-audit-log-reject = ok (727) Mon Oct 26 15:54:22 2020: Debug: } # if (! EAP-Type || (EAP-Type != TTLS && EAP-Type != PEAP) ) = ok (727) Mon Oct 26 15:54:22 2020: Debug: if ("%{%{control:PacketFence-Proxied-From}:-False}" == "True") { (727) Mon Oct 26 15:54:22 2020: Debug: EXPAND %{%{control:PacketFence-Proxied-From}:-False} (727) Mon Oct 26 15:54:22 2020: Debug: --> False (727) Mon Oct 26 15:54:22 2020: Debug: if ("%{%{control:PacketFence-Proxied-From}:-False}" == "True") -> FALSE (727) Mon Oct 26 15:54:22 2020: Debug: attr_filter.access_reject: EXPAND %{User-Name} (727) Mon Oct 26 15:54:22 2020: Debug: attr_filter.access_reject: --> coyo (727) Mon Oct 26 15:54:22 2020: Debug: attr_filter.access_reject: Matched entry DEFAULT at line 11 (727) Mon Oct 26 15:54:22 2020: Debug: [attr_filter.access_reject] = updated (727) Mon Oct 26 15:54:22 2020: Debug: attr_filter.packetfence_post_auth: EXPAND %{User-Name} (727) Mon Oct 26 15:54:22 2020: Debug: attr_filter.packetfence_post_auth: --> coyo (727) Mon Oct 26 15:54:22 2020: Debug: attr_filter.packetfence_post_auth: Matched entry DEFAULT at line 10 (727) Mon Oct 26 15:54:22 2020: Debug: [attr_filter.packetfence_post_auth] = updated (727) Mon Oct 26 15:54:22 2020: Debug: [eap] = noop (727) Mon Oct 26 15:54:22 2020: Debug: policy remove_reply_message_if_eap { (727) Mon Oct 26 15:54:22 2020: Debug: if (&reply:EAP-Message && &reply:Reply-Message) { (727) Mon Oct 26 15:54:22 2020: Debug: if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE (727) Mon Oct 26 15:54:22 2020: Debug: else { (727) Mon Oct 26 15:54:22 2020: Debug: [noop] = noop (727) Mon Oct 26 15:54:22 2020: Debug: } # else = noop (727) Mon Oct 26 15:54:22 2020: Debug: } # policy remove_reply_message_if_eap = noop (727) Mon Oct 26 15:54:22 2020: Debug: linelog: EXPAND messages.%{%{reply:Packet-Type}:-default} (727) Mon Oct 26 15:54:22 2020: Debug: linelog: --> messages.Access-Reject (727) Mon Oct 26 15:54:22 2020: Debug: linelog: EXPAND [mac:%{Calling-Station-Id}] Rejected user: %{User-Name} (727) Mon Oct 26 15:54:22 2020: Debug: linelog: --> [mac:X.X.X.X] Rejected user: coyo (727) Mon Oct 26 15:54:22 2020: Debug: [linelog] = ok (727) Mon Oct 26 15:54:22 2020: Debug: } # Post-Auth-Type REJECT = updated (727) Mon Oct 26 15:54:22 2020: Debug: Delaying response for 1.000000 seconds (727) Mon Oct 26 15:54:23 2020: Debug: (727) Discarding duplicate request from client X.X.X.X/32 port 55645 - ID: 132 due to delayed response (727) Mon Oct 26 15:54:23 2020: Debug: Sending delayed response (727) Mon Oct 26 15:54:23 2020: Debug: Sent Access-Reject Id 132 from X.X.X.X:1812 to X.X.X.X:55645 length 101 (727) Mon Oct 26 15:54:23 2020: Debug: MS-CHAP-Error = "\001E=691 R=0 C=c86ce57de86611d248ddad2f2eb690ab V=3 M=Authentication failed" (727) Mon Oct 26 15:54:27 2020: Debug: Cleaning up request packet ID 132 with timestamp +10785 (728) Mon Oct 26 15:54:30 2020: Debug: Received Status-Server Id 199 from 127.0.0.1:50706 to 127.0.0.1:18121 length 50 (728) Mon Oct 26 15:54:30 2020: Debug: Message-Authenticator = 0x746e4169562dc5520ee77b953ef0ac7b (728) Mon Oct 26 15:54:30 2020: Debug: FreeRADIUS-Statistics-Type = 15 (728) Mon Oct 26 15:54:30 2020: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/status (728) Mon Oct 26 15:54:30 2020: Debug: Autz-Type Status-Server { (728) Mon Oct 26 15:54:30 2020: Debug: [ok] = ok (728) Mon Oct 26 15:54:30 2020: Debug: } # Autz-Type Status-Server = ok El lun., 26 oct. 2020 a las 12:39, Fabrice Durand via PacketFence-users (< packetfence-users@lists.sourceforge.net>) escribió: > Hello Enrique, > > can you provide the raddebug output ? > > raddebug -f /usr/local/pf/var/run/radiusd.sock -t 3000 > > > Regards > > Fabrice > > > Le 20-10-26 à 09 h 42, Enrique Gross via PacketFence-users a écrit : > > Hi Packetfence Users, > > > > Hope you are doing fine > > > > I am struggling to authenticate PPP users via MSCHAP with local PF > > authentication, my switch is a Mikrotik device, I am forwarding > > authentication via Radius to packetfence server. > > > > I am getting error > > > > (144) Login incorrect (mschap: Program returned code (1) and output > > 'Reading winbind reply failed! > > > > When I disable MSCHAP/CHAP as an authentication method and use PAP my > > users can authenticate fine. > > > > I have uncomment /usr/local/pf/conf/radiusd/packetfence-tunnel and > > Take care of the "Database passwords hashing method" > > > > I will really appreciate any help > > > > Thanks, Enrique > > > > -- > > > > > > _______________________________________________ > > PacketFence-users mailing list > > PacketFence-users@lists.sourceforge.net > > https://lists.sourceforge.net/lists/listinfo/packetfence-users > > -- > Fabrice Durand > fdur...@inverse.ca :: +1.514.447.4918 (x135) :: www.inverse.ca > Inverse inc. :: Leaders behind SOGo (http://www.sogo.nu) and PacketFence ( > http://packetfence.org) > > > > _______________________________________________ > PacketFence-users mailing list > PacketFence-users@lists.sourceforge.net > https://lists.sourceforge.net/lists/listinfo/packetfence-users > -- [image: Imágenes integradas 1]
_______________________________________________ PacketFence-users mailing list PacketFence-users@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/packetfence-users