ERROR: Failed continuing EAP MD5 (4) session

Mohamed Lrhazi Mohamed.Lrhazi at georgetown.edu
Sat Feb 6 00:23:53 CET 2016


I have some users, apparently always the same, who get rejected with this
error message... I managed to get a session containing the failure captured
in debug mode. Not sure if I should post more, but this the end of one such
session....

How can I get to the root cause of their rejections?

This is running 3.0.11 but I saw the same errors in previous versions as
well.

Thanks a lot,
Mohamed.



Waking up in 0.4 seconds.
(267) Received Access-Request Id 50 from 64.57.22.74:59485 to
10.212.11.16:1812 length 322
(267)   User-Name = "usernamescrub at georgetown.edu"
(267)   NAS-IP-Address = 137.158.248.12
(267)   NAS-Identifier = "mc-wlan-3"
(267)   EAP-Message =
0x020d006019001703010020a656b177e50de453353cc5168dee3c22a1ed723cbb64f31aef3691fa701022dd17030100305b78b8ff2b863942c2334a32879eadff634098f4bfedef9becd8c6bdb487a756b1171bb2702c3646f84ecae10457efa4
(267)   State = 0x7f22f2a0752febe91327d6769b7e379b
(267)   Message-Authenticator = 0x33f00e391800047cf82dac79dae82745
(267)   Attr-26.9048.0 =
0x50726f786965642d42793d65746c72312e656475726f616d2e6f72672d31343534363537343033
(267)   Attr-26.9048.0 =
0x50726f786965642d42793d72616469756d2e737572666e65742e6e6c2d31343534363537343033
(267)   Attr-26.9048.0 =
0x50726f786965642d42793d544c5253312e656475726f616d2e7573
(267) session-state: No cached attributes
(267) # Executing section authorize from file
/etc/raddb/sites-enabled/default
(267)   authorize {
(267)     policy filter_username {
(267)       if (User-Name != "%{tolower:%{User-Name}}") {
(267)       EXPAND %{tolower:%{User-Name}}
(267)          --> usernamescrub at georgetown.edu
(267)       if (User-Name != "%{tolower:%{User-Name}}")  -> FALSE
(267)       if (User-Name =~ / /) {
(267)       if (User-Name =~ / /)  -> FALSE
(267)       if (User-Name =~ /@.*@/ ) {
(267)       if (User-Name =~ /@.*@/ )  -> FALSE
(267)       if (User-Name =~ /\\.\\./ ) {
(267)       if (User-Name =~ /\\.\\./ )  -> FALSE
(267)       if ((User-Name =~ /@/) && (User-Name !~ /@(.+)\\.(.+)$/))  {
(267)       if ((User-Name =~ /@/) && (User-Name !~ /@(.+)\\.(.+)$/))   ->
FALSE
(267)       if (User-Name =~ /\\.$/)  {
(267)       if (User-Name =~ /\\.$/)   -> FALSE
(267)       if (User-Name =~ /@\\./)  {
(267)       if (User-Name =~ /@\\./)   -> FALSE
(267)     } # policy filter_username = notfound
(267)     [preprocess] = ok
(267)     policy operator-name.authorize {
(267)       if ("%{client:Operator-Name}") {
(267)       EXPAND %{client:Operator-Name}
(267)          -->
(267)       if ("%{client:Operator-Name}")  -> FALSE
(267)     } # policy operator-name.authorize = ok
(267)     [chap] = noop
(267)     [mschap] = noop
(267)     [digest] = noop
(267) suffix: Checking for suffix after "@"
(267) suffix: Looking up realm "georgetown.edu" for User-Name = "
usernamescrub at georgetown.edu"
(267) suffix: Found realm "georgetown.edu"
(267) suffix: Adding Stripped-User-Name = "usernamescrub"
(267) suffix: Adding Realm = "georgetown.edu"
(267) suffix: Authentication realm is LOCAL
(267)     [suffix] = ok
(267)     if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/) {
(267)     EXPAND %{User-Name}
(267)        --> usernamescrub at georgetown.edu
(267)     if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/)
 -> TRUE
(267)     if ("%{User-Name}" =~ /\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/)  {
(267)       if ("%{2}" && ("%{2}" !~ /.*georgetown\.edu$/i && "%{2}" !~
/msb\.edu$/i) ) {
(267)       EXPAND %{2}
(267)          --> georgetown.edu
(267)       EXPAND %{2}
(267)          --> georgetown.edu
(267)       if ("%{2}" && ("%{2}" !~ /.*georgetown\.edu$/i && "%{2}" !~
/msb\.edu$/i) )  -> FALSE
(267)     } # if ("%{User-Name}" =~
/\\\\?([^@\\\\]+)@?([-[:alnum:]._]*)?$/)  = ok
(267)     if ("%{Realm}" != 'NULL' && "%{Realm}" != 'LOCAL' && "%{Realm}"
!= 'georgetown.edu' && "%{Realm}" != 'gu.edu' && "%{Realm}" != 'msb.edu' &&
"%{Realm}" != 'eduroam') {
(267)     if ("%{Realm}" != 'NULL' && "%{Realm}" != 'LOCAL' && "%{Realm}"
!= 'georgetown.edu' && "%{Realm}" != 'gu.edu' && "%{Realm}" != 'msb.edu' &&
"%{Realm}" != 'eduroam')  -> FALSE
(267) eap: Peer sent EAP Response (code 2) ID 13 length 96
(267) eap: Continuing tunnel setup
(267)     [eap] = ok
(267)   } # authorize = ok
(267) Found Auth-Type = eap
(267) # Executing group from file /etc/raddb/sites-enabled/default
(267)   authenticate {
(267) eap: Expiring EAP session with state 0x4cf0afb84dfdabc5
(267) eap: Finished EAP session with state 0x7f22f2a0752febe9
(267) eap: Previous EAP request found for state 0x7f22f2a0752febe9,
released from the list
(267) eap: Peer sent packet with method EAP PEAP (25)
(267) eap: Calling submodule eap_peap to process data
(267) eap_peap: Continuing EAP-TLS
(267) eap_peap: [eaptls verify] = ok
(267) eap_peap: Done initial handshake
(267) eap_peap: [eaptls process] = ok
(267) eap_peap: Session established.  Decoding tunneled attributes
(267) eap_peap: PEAP state phase2
(267) eap_peap: EAP method MD5 (4)
(267) eap_peap: Got tunneled request
(267) eap_peap:   EAP-Message =
0x020d001604104ed6fcaab16a1dcd4bc8ba2eded04e1b
(267) eap_peap: Setting User-Name to usernamescrub at georgetown.edu
(267) eap_peap: Sending tunneled request to inner-tunnel
(267) eap_peap:   EAP-Message =
0x020d001604104ed6fcaab16a1dcd4bc8ba2eded04e1b
(267) eap_peap:   FreeRADIUS-Proxied-To = 127.0.0.1
(267) eap_peap:   User-Name = "usernamescrub at georgetown.edu"
(267) eap_peap:   State = 0x4cf0afb84dfdabc5e4cbfa01e2805e60
(267) eap_peap:   NAS-IP-Address = 137.158.248.12
(267) eap_peap:   NAS-Identifier = "mc-wlan-3"
(267) eap_peap:   Attr-26.9048.0 =
0x50726f786965642d42793d65746c72312e656475726f616d2e6f72672d31343534363537343033
(267) eap_peap:   Attr-26.9048.0 =
0x50726f786965642d42793d72616469756d2e737572666e65742e6e6c2d31343534363537343033
(267) eap_peap:   Attr-26.9048.0 =
0x50726f786965642d42793d544c5253312e656475726f616d2e7573
(267) eap_peap:   Attr-26.9048.0 =
0x50726f786965642d42793d72616469756d2e737572666e65742e6e6c2d31343534363537343033
(267) eap_peap:   Attr-26.9048.0 =
0x50726f786965642d42793d544c5253312e656475726f616d2e7573
(267) eap_peap:   Attr-26.9048.0 =
0x50726f786965642d42793d544c5253312e656475726f616d2e7573
(267) eap_peap:   Event-Timestamp = "Feb  5 2016 14:09:55 EST"
(267) Virtual server inner-tunnel received request
(267)   EAP-Message = 0x020d001604104ed6fcaab16a1dcd4bc8ba2eded04e1b
(267)   FreeRADIUS-Proxied-To = 127.0.0.1
(267)   User-Name = "usernamescrub at georgetown.edu"
(267)   State = 0x4cf0afb84dfdabc5e4cbfa01e2805e60
(267)   NAS-IP-Address = 137.158.248.12
(267)   NAS-Identifier = "mc-wlan-3"
(267)   Attr-26.9048.0 =
0x50726f786965642d42793d65746c72312e656475726f616d2e6f72672d31343534363537343033
(267)   Attr-26.9048.0 =
0x50726f786965642d42793d72616469756d2e737572666e65742e6e6c2d31343534363537343033
(267)   Attr-26.9048.0 =
0x50726f786965642d42793d544c5253312e656475726f616d2e7573
(267)   Attr-26.9048.0 =
0x50726f786965642d42793d72616469756d2e737572666e65742e6e6c2d31343534363537343033
(267)   Attr-26.9048.0 =
0x50726f786965642d42793d544c5253312e656475726f616d2e7573
(267)   Attr-26.9048.0 =
0x50726f786965642d42793d544c5253312e656475726f616d2e7573
(267)   Event-Timestamp = "Feb  5 2016 14:09:55 EST"
(267) WARNING: Outer and inner identities are the same.  User privacy is
compromised.
(267) server inner-tunnel {
(267)   session-state: No cached attributes
(267)   # Executing section authorize from file
/etc/raddb/sites-enabled/inner-tunnel
(267)     authorize {
(267)       [chap] = noop
(267)       [mschap] = noop
(267) suffix: Checking for suffix after "@"
(267) suffix: Looking up realm "georgetown.edu" for User-Name = "
usernamescrub at georgetown.edu"
(267) suffix: Found realm "georgetown.edu"
(267) suffix: Adding Stripped-User-Name = "usernamescrub"
(267) suffix: Adding Realm = "georgetown.edu"
(267) suffix: Authentication realm is LOCAL
(267)       [suffix] = ok
(267)       update control {
(267)         Proxy-To-Realm := LOCAL
(267)       } # update control = noop
(267) eap: Peer sent EAP Response (code 2) ID 13 length 22
(267) eap: No EAP Start, assuming it's an on-going EAP conversation
(267)       [eap] = updated
(267)       [files] = noop
rlm_ldap (ldap): Reserved connection (12)
(267) ldap: EXPAND (uid=%{%{Stripped-User-Name}:-%{User-Name}})
(267) ldap:    --> (uid=usernamescrub)
(267) ldap: Performing search in "ou=people,dc=georgetown,dc=edu" with
filter "(uid=usernamescrub)", scope "sub"
(267) ldap: Waiting for search result...
(267) ldap: User object found at DN
"uid=usernamescrub,ou=people,dc=georgetown,dc=edu"
(267) ldap: Processing user attributes
(267) ldap: control:Password-With-Header +=
{MD4}1DD9FC26BF0FCD74413AF390A74F559B
rlm_ldap (ldap): Released connection (12)
(267)       [ldap] = updated
(267)       if (&control:Password-With-Header =~ /^.MD4.(.*)$/) {
(267)       if (&control:Password-With-Header =~ /^.MD4.(.*)$/)  -> TRUE
(267)       if (&control:Password-With-Header =~ /^.MD4.(.*)$/)  {
(267)         update control {
(267)           EXPAND {nt}%{1}
(267)              --> {nt}1DD9FC26BF0FCD74413AF390A74F559B
(267)           Password-With-Header := {nt}1DD9FC26BF0FCD74413AF390A74F559B
(267)         } # update control = noop
(267) pap: Converted: Password-With-Header -> NT-Password
(267) pap: Removing &control:Password-With-Header
(267) pap: Normalizing NT-Password from hex encoding, 32 bytes -> 16 bytes
(267) pap: WARNING: Auth-Type already set.  Not setting to PAP
(267)         [pap] = noop
(267)       } # if (&control:Password-With-Header =~ /^.MD4.(.*)$/)  = noop
(267)       if ((ok || updated) && User-Password) {
(267)       if ((ok || updated) && User-Password)  -> FALSE
(267)       [expiration] = noop
(267)       [logintime] = noop
(267) pap: WARNING: Auth-Type already set.  Not setting to PAP
(267)       [pap] = noop
(267)     } # authorize = updated
(267)   Found Auth-Type = eap
(267)   # Executing group from file /etc/raddb/sites-enabled/inner-tunnel
(267)     authenticate {
(267) eap: Expiring EAP session with state 0x4cf0afb84dfdabc5
(267) eap: Finished EAP session with state 0x4cf0afb84dfdabc5
(267) eap: Previous EAP request found for state 0x4cf0afb84dfdabc5,
released from the list
(267) eap: Peer sent packet with method EAP MD5 (4)
(267) eap: Calling submodule eap_md5 to process data
(267) eap_md5: Cleartext-Password is required for EAP-MD5 authentication
(267) eap: ERROR: Failed continuing EAP MD5 (4) session.  EAP sub-module
failed
(267) eap: Sending EAP Failure (code 4) ID 13 length 4
(267) eap: Failed in EAP select
(267)       [eap] = invalid
(267)     } # authenticate = invalid
(267)   Failed to authenticate the user
(267)   Using Post-Auth-Type Reject
(267)   # Executing group from file /etc/raddb/sites-enabled/inner-tunnel
(267)     Post-Auth-Type REJECT {


More information about the Freeradius-Users mailing list