Am 13.06.2014 13:42, schrieb Alan DeKok:
Michael Simon wrote:
After running FR 3.0.3 from GIT (FR 3.0.2 as well) for a while (a few hours) lots of “Error: rlm_eap (EAP): No EAP session matching state 0x…” appear in the log file.
A restart of FR and the error messages are gone for the present.
The debug output would be a lot more helpful.
Here is the debug output. The whole log size is 3.7MB (bz2 compressed) I also have a valgrind output. ==00:01:39:12.597 24025== LEAK SUMMARY: ==00:01:39:12.597 24025== definitely lost: 12,573 bytes in 34 blocks ==00:01:39:12.597 24025== indirectly lost: 53,791 bytes in 586 blocks ==00:01:39:12.597 24025== possibly lost: 2,049 bytes in 1 blocks ==00:01:39:12.597 24025== still reachable: 2,363,837 bytes in 22 blocks ==00:01:39:12.597 24025== suppressed: 0 bytes in 0 blocks ==00:01:33:10.179 24025== Conditional jump or move depends on uninitialised value(s) ==00:01:33:10.179 24025== at 0x40F4A4C: ??? (in /usr/lib/i386-linux-gnu/i686/cmov/libcrypto.so.1.0.0) ==00:01:33:10.179 24025== by 0x3801EE69: vgMemCheck_detect_memory_leaks (mc_leakcheck.c:1714) ==00:01:33:10.179 24025== by 0x42BE414: talloc_check_name (in /usr/lib/i386-linux-gnu/libtalloc.so.2.1.1) summary of an example: (1609) Login OK: [user294@uni-wuppertal.de] (from client radius2.eduroam.xy port 34543 cli 0026.08dc.a8eb via TLS tunnel) (1610) Login OK: [user294@uni-wuppertal.de] (from client radius2.eduroam.xy port 34543 cli 0026.08dc.a8eb) (1627) Login OK: [user294@uni-wuppertal.de] (from client radius2.eduroam.xy port 751 cli 00-26-08-DC-A8-EB via TLS tunnel) (1628) Login OK: [user294@uni-wuppertal.de] (from client radius2.eduroam.xy port 751 cli 00-26-08-DC-A8-EB) (1696) Login OK: [user294@uni-wuppertal.de] (from client radius2.eduroam.xy port 34547 cli 80ea.96ad.cae3 via TLS tunnel) (1697) Login OK: [user294@uni-wuppertal.de] (from client radius2.eduroam.xy port 34547 cli 80ea.96ad.cae3) (2132) Login OK: [user294@uni-wuppertal.de] (from client radius2.eduroam.xy port 34566 cli 80ea.96ad.cae3 via TLS tunnel) (2133) Login OK: [user294@uni-wuppertal.de] (from client radius2.eduroam.xy port 34566 cli 80ea.96ad.cae3) (2147) Login OK: [user294@uni-wuppertal.de] (from client radius2.eduroam.xy port 744 cli 80-EA-96-AD-CA-E3 via TLS tunnel) (2148) Login OK: [user294@uni-wuppertal.de] (from client radius2.eduroam.xy port 744 cli 80-EA-96-AD-CA-E3) (2602) Login incorrect: [user294@uni-wuppertal.de] (from client radius2.eduroam.xy port 498 cli 80-EA-96-AD-CA-E3) (2671) Login incorrect: [user294@uni-wuppertal.de] (from client radius2.eduroam.xy port 759 cli 80-EA-96-AD-CA-E3) (2994) Login incorrect: [user294@uni-wuppertal.de] (from client radius2.eduroam.xy port 21111 cli 80-EA-96-AD-CA-E3) (2996) Login incorrect: [user294@uni-wuppertal.de] (from client radius2.eduroam.xy port 21111 cli 80-EA-96-AD-CA-E3) (3002) Login incorrect: [user294@uni-wuppertal.de] (from client radius2.eduroam.xy port 21113 cli 80-EA-96-AD-CA-E3) (3012) Login incorrect: [user294@uni-wuppertal.de] (from client radius2.eduroam.xy port 21113 cli 80-EA-96-AD-CA-E3) (3018) Login incorrect: [user294@uni-wuppertal.de] (from client radius2.eduroam.xy port 48469 cli 80-EA-96-AD-CA-E3) (3019) Login incorrect: [user294@uni-wuppertal.de] (from client radius2.eduroam.xy port 48469 cli 80-EA-96-AD-CA-E3) (3039) Login incorrect: [user294@uni-wuppertal.de] (from client radius2.eduroam.xy port 21118 cli 80-EA-96-AD-CA-E3) (3040) Login incorrect: [user294@uni-wuppertal.de] (from client radius2.eduroam.xy port 21118 cli 80-EA-96-AD-CA-E3) example last "Login OK": (2148) # Executing section authorize from file /etc/freeradius/sites-enabled/default (2148) authorize { (2148) filter_username filter_username { (2148) if (!User-Name) (2148) if (!User-Name) -> FALSE (2148) if (User-Name =~ / /) (2148) if (User-Name =~ / /) -> FALSE (2148) if (User-Name =~ /@.*@/ ) (2148) if (User-Name =~ /@.*@/ ) -> FALSE (2148) if (User-Name =~ /\\.\\./ ) (2148) if (User-Name =~ /\\.\\./ ) -> FALSE (2148) if ((User-Name =~ /@/) && (User-Name !~ /@(.+)\\.(.+)$/)) (2148) if ((User-Name =~ /@/) && (User-Name !~ /@(.+)\\.(.+)$/)) -> FALSE (2148) if (User-Name =~ /\\.$/) (2148) if (User-Name =~ /\\.$/) -> FALSE (2148) if (User-Name =~ /@\\./) (2148) if (User-Name =~ /@\\./) -> FALSE (2148) } # filter_username filter_username = notfound (2148) if ( User-Name && ( User-Name !~ /^([a-z0-9._-]+)@([a-z0-9._-]+)[.]([a-z]{2,4})$/i ) || ( User-Name =~ /@wlan\\.[[:alnum:]]+\\.[[:alnum:]]+\\.3gppnetwork\\.org$/i ) ) (2148) if ( User-Name && ( User-Name !~ /^([a-z0-9._-]+)@([a-z0-9._-]+)[.]([a-z]{2,4})$/i ) || ( User-Name =~ /@wlan\\.[[:alnum:]]+\\.[[:alnum:]]+\\.3gppnetwork\\.org$/i ) ) -> FALSE (2148) [preprocess] = ok (2148) suffix : Looking up realm "uni-wuppertal.de" for User-Name = "user294@uni-wuppertal.de" (2148) suffix : Found realm "uni-wuppertal.de" (2148) suffix : Adding Stripped-User-Name = "user294" (2148) suffix : Adding Realm = "uni-wuppertal.de" (2148) suffix : Authentication realm is LOCAL (2148) [suffix] = ok (2148) eap : EAP packet type response id 12 length 43 (2148) eap : Continuing tunnel setup (2148) [eap] = ok (2148) } # authorize = ok (2148) Found Auth-Type = EAP (2148) # Executing group from file /etc/freeradius/sites-enabled/default (2148) authenticate { Waking up in 0.1 seconds. (2148) eap : Expiring EAP session with state 0x11574ddc115d54e6 (2148) eap : Finished EAP session with state 0x1e66753c156a6c95 (2148) eap : Previous EAP request found for state 0x1e66753c156a6c95, released from the list (2148) eap : Peer sent PEAP (25) (2148) eap : EAP PEAP (25) (2148) eap : Calling eap_peap to process EAP data (2148) eap_peap : processing EAP-TLS (2148) eap_peap : eaptls_verify returned 7 (2148) eap_peap : Done initial handshake (2148) eap_peap : eaptls_process returned 7 (2148) eap_peap : FR_TLS_OK (2148) eap_peap : Session established. Decoding tunneled attributes (2148) eap_peap : Peap state send tlv success (2148) eap_peap : Received EAP-TLV response (2148) eap_peap : Success (2148) eap_peap : Using saved attributes from the original Access-Accept Sending Access-Challenge Id 149 from 0.0.0.0:2083 to 192.178.71.138:27485 EAP-Message = 0x010c002b19001703010020a61f43fe889948870718b6d9a4375a8bc74af77ef47c7c4b6521c5f855157f5f Message-Authenticator = 0x00000000000000000000000000000000 State = 0x1e66753c156a6c9510f0431d79ab79e0 Proxy-State = 0x3130 User-Name = 'user294@uni-wuppertal.de' NAS-IP-Address = 10.41.1.41 NAS-Port = 744 Called-Station-Id = '00-0F-7D-C7-BD-F2:eduroam' Calling-Station-Id = '80-EA-96-AD-CA-E3' Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = 'CONNECT 28Mbps/1Mbps 802.11n' EAP-Message = 0x020c002b19001703010020ef84b95ede65e49ded032fd66b6bdafc81ed37235630c269c9885ecdced372d5 State = 0x1e66753c156a6c9510f0431d79ab79e0 Message-Authenticator = 0xd314db0076e4a7e688ef1a0c3f018b94 Proxy-State = 0x3131 Stripped-User-Name = 'user294' User-Name = 'user294@uni-wuppertal.de' (2148) eap : Freeing handler (2148) [eap] = ok (2148) } # authenticate = ok (2148) Login OK: [user294@uni-wuppertal.de] (from client radius2.eduroam.xy port 744 cli 80-EA-96-AD-CA-E3) (2148) # Executing section post-auth from file /etc/freeradius/sites-enabled/default (2148) post-auth { (2148) remove_reply_message_if_eap remove_reply_message_if_eap { (2148) if (reply:EAP-Message && reply:Reply-Message) (2148) if (reply:EAP-Message && reply:Reply-Message) -> FALSE (2148) else else { (2148) [noop] = noop (2148) } # else else = noop (2148) } # remove_reply_message_if_eap remove_reply_message_if_eap = noop (2148) update reply { (2148) Tunnel-Type := VLAN (2148) Tunnel-Medium-Type := IEEE-802 (2148) Tunnel-Private-Group-Id := 'eduroam' (2148) } # update reply = noop (2148) } # post-auth = noop (2148) Finished request example "No EAP session matching state" (3039) # Executing section authorize from file /etc/freeradius/sites-enabled/default (3039) authorize { (3039) filter_username filter_username { (3039) if (!User-Name) (3039) if (!User-Name) -> FALSE (3039) if (User-Name =~ / /) (3039) if (User-Name =~ / /) -> FALSE (3039) if (User-Name =~ /@.*@/ ) (3039) if (User-Name =~ /@.*@/ ) -> FALSE (3039) if (User-Name =~ /\\.\\./ ) Waking up in 0.3 seconds. (3039) if (User-Name =~ /\\.\\./ ) -> FALSE (3039) if ((User-Name =~ /@/) && (User-Name !~ /@(.+)\\.(.+)$/)) (3039) if ((User-Name =~ /@/) && (User-Name !~ /@(.+)\\.(.+)$/)) -> FALSE (3039) if (User-Name =~ /\\.$/) (3039) if (User-Name =~ /\\.$/) -> FALSE (3039) if (User-Name =~ /@\\./) (3039) if (User-Name =~ /@\\./) -> FALSE (3039) } # filter_username filter_username = notfound (3039) if ( User-Name && ( User-Name !~ /^([a-z0-9._-]+)@([a-z0-9._-]+)[.]([a-z]{2,4})$/i ) || ( User-Name =~ /@wlan\\.[[:alnum:]]+\\.[[:alnum:]]+\\.3gppnetwork\\.org$/i ) ) (3039) if ( User-Name && ( User-Name !~ /^([a-z0-9._-]+)@([a-z0-9._-]+)[.]([a-z]{2,4})$/i ) || ( User-Name =~ /@wlan\\.[[:alnum:]]+\\.[[:alnum:]]+\\.3gppnetwork\\.org$/i ) ) -> FALSE (3039) [preprocess] = ok (3039) suffix : Looking up realm "uni-wuppertal.de" for User-Name = "user294@uni-wuppertal.de" (3039) suffix : Found realm "uni-wuppertal.de" (3039) suffix : Adding Stripped-User-Name = "user294" (3039) suffix : Adding Realm = "uni-wuppertal.de" (3039) suffix : Authentication realm is LOCAL (3039) [suffix] = ok (3039) eap : EAP packet type response id 9 length 6 (3039) eap : Continuing tunnel setup (3039) [eap] = ok (3039) } # authorize = ok (3039) Found Auth-Type = EAP (3039) # Executing group from file /etc/freeradius/sites-enabled/default (3039) authenticate { (3039) eap : Expiring EAP session with state 0x048451e3058748ec rlm_eap (EAP): No EAP session matching state 0x893a58798e334141 (3039) eap : Either EAP-request timed out OR EAP-response to an unknown EAP-request (3039) eap : Failed in handler (3039) [eap] = invalid (3039) } # authenticate = invalid (3039) Failed to authenticate the user (3039) Login incorrect: [user294@uni-wuppertal.de] (from client radius2.eduroam.xy port 21118 cli 80-EA-96-AD-CA-E3) (3039) Using Post-Auth-Type Reject (3039) # Executing group from file /etc/freeradius/sites-enabled/default (3039) Post-Auth-Type REJECT { (3039) attr_filter.access_reject : EXPAND %{User-Name} (3039) attr_filter.access_reject : --> user294@uni-wuppertal.de (3039) attr_filter.access_reject : Matched entry DEFAULT at line 11 (3039) [attr_filter.access_reject] = updated (3039) eap : Expiring EAP session with state 0x048451e3058748ec rlm_eap (EAP): No EAP session matching state 0x893a58798e334141 (3039) eap : Either EAP-request timed out OR EAP-response to an unknown EAP-request (3039) eap : Failed to get handler, probably already removed, not inserting EAP-Failure (3039) [eap] = noop (3039) remove_reply_message_if_eap remove_reply_message_if_eap { (3039) if (reply:EAP-Message && reply:Reply-Message) (3039) if (reply:EAP-Message && reply:Reply-Message) -> FALSE (3039) else else { (3039) [noop] = noop (3039) } # else else = noop (3039) } # remove_reply_message_if_eap remove_reply_message_if_eap = noop (3039) } # Post-Auth-Type REJECT = updated (3039) Delaying response for 1 seconds Thread 5 waiting to be assigned a request Waking up in 0.6 seconds. (3039) Sending delayed response Waking up in 3.9 seconds. (3039) Cleaning up request packet ID 4 with timestamp +3458 another user with "No EAP session matching state" (2925) # Executing section authorize from file /etc/freeradius/sites-enabled/default (2925) authorize { (2925) filter_username filter_username { (2925) if (!User-Name) (2925) if (!User-Name) -> FALSE (2925) if (User-Name =~ / /) (2925) if (User-Name =~ / /) -> FALSE (2925) if (User-Name =~ /@.*@/ ) (2925) if (User-Name =~ /@.*@/ ) -> FALSE (2925) if (User-Name =~ /\\.\\./ ) (2925) if (User-Name =~ /\\.\\./ ) -> FALSE (2925) if ((User-Name =~ /@/) && (User-Name !~ /@(.+)\\.(.+)$/)) (2925) if ((User-Name =~ /@/) && (User-Name !~ /@(.+)\\.(.+)$/)) -> FALSE (2925) if (User-Name =~ /\\.$/) (2925) if (User-Name =~ /\\.$/) -> FALSE (2925) if (User-Name =~ /@\\./) (2925) if (User-Name =~ /@\\./) -> FALSE (2925) } # filter_username filter_username = notfound (2925) if ( User-Name && ( User-Name !~ /^([a-z0-9._-]+)@([a-z0-9._-]+)[.]([a-z]{2,4})$/i ) || ( User-Name =~ /@wlan\\.[[:alnum:]]+\\.[[:alnum:]]+\\.3gppnetwork\\.org$/i ) ) (2925) if ( User-Name && ( User-Name !~ /^([a-z0-9._-]+)@([a-z0-9._-]+)[.]([a-z]{2,4})$/i ) || ( User-Name =~ /@wlan\\.[[:alnum:]]+\\.[[:alnum:]]+\\.3gppnetwork\\.org$/i ) ) -> FALSE (2925) [preprocess] = ok (2925) suffix : Looking up realm "uni-wuppertal.de" for User-Name = "user940@uni-wuppertal.de" (2925) suffix : Found realm "uni-wuppertal.de" (2925) suffix : Adding Stripped-User-Name = "user940" (2925) suffix : Adding Realm = "uni-wuppertal.de" (2925) suffix : Authentication realm is LOCAL (2925) [suffix] = ok (2925) eap : EAP packet type response id 6 length 6 (2925) eap : Continuing tunnel setup (2925) [eap] = ok (2925) } # authorize = ok (2925) Found Auth-Type = EAP (2925) # Executing group from file /etc/freeradius/sites-enabled/default (2925) authenticate { (2925) eap : Expiring EAP session with state 0xc2b31edcc2b10778 rlm_eap (EAP): No EAP session matching state 0xea2b54dbee2d4d20 (2925) eap : Either EAP-request timed out OR EAP-response to an unknown EAP-request (2925) eap : Failed in handler (2925) [eap] = invalid (2925) } # authenticate = invalid (2925) Failed to authenticate the user (2925) Login incorrect: [user940@uni-wuppertal.de] (from client radius1.eduroam.xy port 13 cli 58:1f:aa:a5:7f:1a) (2925) Using Post-Auth-Type Reject (2925) # Executing group from file /etc/freeradius/sites-enabled/default (2925) Post-Auth-Type REJECT { (2925) attr_filter.access_reject : EXPAND %{User-Name} (2925) attr_filter.access_reject : --> user940@uni-wuppertal.de (2925) attr_filter.access_reject : Matched entry DEFAULT at line 11 (2925) [attr_filter.access_reject] = updated (2925) eap : Expiring EAP session with state 0xc2b31edcc2b10778 rlm_eap (EAP): No EAP session matching state 0xea2b54dbee2d4d20 (2925) eap : Either EAP-request timed out OR EAP-response to an unknown EAP-request (2925) eap : Failed to get handler, probably already removed, not inserting EAP-Failure (2925) [eap] = noop (2925) remove_reply_message_if_eap remove_reply_message_if_eap { (2925) if (reply:EAP-Message && reply:Reply-Message) (2925) if (reply:EAP-Message && reply:Reply-Message) -> FALSE (2925) else else { (2925) [noop] = noop (2925) } # else else = noop (2925) } # remove_reply_message_if_eap remove_reply_message_if_eap = noop (2925) } # Post-Auth-Type REJECT = updated (2925) Delaying response for 1 seconds Thread 3 waiting to be assigned a request Waking up in 0.7 seconds. (2925) Sending delayed response