Hello all, I'm new to freeRadius and am using freeRadius version 2.1.10 for some lab testing. I've got freeradius extracting users and passwords from an Active Directory database. I'm using PEAP/MSCHAPv2. All configs have been working until about a week or so ago. All of a sudden, my mschapv2 challenge/response is not correct.
Not sure where exactly the problem is occurring so I've posted the debug output below. If other config files are necessary, I can post them too. Thank for any help. Trevor rad_recv: Access-Request packet from host 127.0.0.1 port 50066, id=2, length=81 User-Name = "TheAdmin" NAS-Port = 0 NAS-IP-Address = 127.0.0.1 EAP-Message = 0x0200001001747265766f7261646d696e Message-Authenticator = 0x1f8e3dc1fcbafac6481c9fe22c8449e5 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] No '@' in User-Name = "TheAdmin", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [eap] EAP packet type response id 0 length 16 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated [ldap] Entering ldap_groupcmp() [files] expand: dc=commslab,dc=local -> dc=commslab,dc=local [files] expand: %{Stripped-User-Name} -> [files] ... expanding second conditional [files] expand: %{User-Name} -> TheAdmin [files] expand: (&(objectclass=user)(sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}}*)) -> (&(objectclass=user)(sAMAccountName=TheAdmin*)) [ldap] ldap_get_conn: Checking Id: 0 [ldap] ldap_get_conn: Got Id: 0 [ldap] performing search in dc=commslab,dc=local, with filter (&(objectclass=user)(sAMAccountName=TheAdmin*)) [ldap] ldap_release_conn: Release Id: 0 [files] expand: (|(&(objectClass=GroupOfNames)(member=%{Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{Ldap-UserDn}))) -> (|(&(objectClass=GroupOfNames)(member=))(&(objectClass=GroupOfUniqueNames)(uniquemember=))) [ldap] ldap_get_conn: Checking Id: 0 [ldap] ldap_get_conn: Got Id: 0 [ldap] performing search in dc=commslab,dc=local, with filter (&(cn=Commslab_Domain_Users)(|(&(objectClass=GroupOfNames)(member=))(&(objectClass=GroupOfUniqueNames)(uniquemember=)))) [ldap] object not found [ldap] ldap_release_conn: Release Id: 0 [ldap] ldap_get_conn: Checking Id: 0 [ldap] ldap_get_conn: Got Id: 0 [ldap] performing search in CN=TheAdmin,OU=Users,OU=commslab,DC=commslab,DC=local, with filter (objectclass=*) [ldap] performing search in CN=Commslab_Enterprise_Admins,OU=Groups,OU=commslab,DC=commslab,DC=local, with filter (cn=Commslab_Domain_Users) [ldap] object not found [ldap] performing search in CN=Domain Admins,CN=Users,DC=commslab,DC=local, with filter (cn=Commslab_Domain_Users) [ldap] object not found rlm_ldap::groupcmp: Group Commslab_Domain_Users not found or user not a member [ldap] ldap_release_conn: Release Id: 0 [ldap] Entering ldap_groupcmp() [files] expand: dc=commslab,dc=local -> dc=commslab,dc=local [files] expand: (|(&(objectClass=GroupOfNames)(member=%{Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{Ldap-UserDn}))) -> (|(&(objectClass=GroupOfNames)(member=))(&(objectClass=GroupOfUniqueNames)(uniquemember=))) [ldap] ldap_get_conn: Checking Id: 0 [ldap] ldap_get_conn: Got Id: 0 [ldap] performing search in dc=commslab,dc=local, with filter (&(cn=Commslab_Enterprise_Admins)(|(&(objectClass=GroupOfNames)(member=))(&(objectClass=GroupOfUniqueNames)(uniquemember=)))) [ldap] object not found [ldap] ldap_release_conn: Release Id: 0 [ldap] ldap_get_conn: Checking Id: 0 [ldap] ldap_get_conn: Got Id: 0 [ldap] performing search in CN=TheAdmin,OU=Users,OU=commslab,DC=commslab,DC=local, with filter (objectclass=*) [ldap] performing search in CN=Commslab_Enterprise_Admins,OU=Groups,OU=commslab,DC=commslab,DC=local, with filter (cn=Commslab_Enterprise_Admins) rlm_ldap::ldap_groupcmp: User found in group Commslab_Enterprise_Admins [ldap] ldap_release_conn: Release Id: 0 ++[files] returns noop ++[expiration] returns noop ++[logintime] returns noop [pap] WARNING! No "known good" password found for the user. Authentication may fail because of this. ++[pap] returns noop ++? if (!control:Auth-Type) ? Evaluating !(control:Auth-Type) -> FALSE ++? if (!control:Auth-Type) -> FALSE Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] EAP Identity [eap] processing type tls [tls] Initiate --- Not sure why were trying TLS [tls] Start returned 1 ++[eap] returns handled Sending Access-Challenge of id 2 to 127.0.0.1 port 50066 EAP-Message = 0x010100061920 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xc823e63dc822ff81c661e84e3a0d59ca Finished request 11. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 127.0.0.1 port 50066, id=3, length=89 User-Name = "TheAdmin" NAS-Port = 0 NAS-IP-Address = 127.0.0.1 State = 0xc823e63dc822ff81c661e84e3a0d59ca EAP-Message = 0x02010006031a Message-Authenticator = 0x800227d2e97f5df201d1173187725335 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] No '@' in User-Name = "TheAdmin", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [eap] EAP packet type response id 1 length 6 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated [ldap] Entering ldap_groupcmp() [files] expand: dc=commslab,dc=local -> dc=commslab,dc=local [files] expand: %{Stripped-User-Name} -> [files] ... expanding second conditional [files] expand: %{User-Name} -> TheAdmin [files] expand: (&(objectclass=user)(sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}}*)) -> (&(objectclass=user)(sAMAccountName=TheAdmin*)) [ldap] ldap_get_conn: Checking Id: 0 [ldap] ldap_get_conn: Got Id: 0 [ldap] performing search in dc=commslab,dc=local, with filter (&(objectclass=user)(sAMAccountName=TheAdmin*)) [ldap] ldap_release_conn: Release Id: 0 [files] expand: (|(&(objectClass=GroupOfNames)(member=%{Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{Ldap-UserDn}))) -> (|(&(objectClass=GroupOfNames)(member=))(&(objectClass=GroupOfUniqueNames)(uniquemember=))) [ldap] ldap_get_conn: Checking Id: 0 [ldap] ldap_get_conn: Got Id: 0 [ldap] performing search in dc=commslab,dc=local, with filter (&(cn=Commslab_Domain_Users)(|(&(objectClass=GroupOfNames)(member=))(&(objectClass=GroupOfUniqueNames)(uniquemember=)))) [ldap] object not found [ldap] ldap_release_conn: Release Id: 0 [ldap] ldap_get_conn: Checking Id: 0 [ldap] ldap_get_conn: Got Id: 0 [ldap] performing search in CN=TheAdmin,OU=Users,OU=commslab,DC=commslab,DC=local, with filter (objectclass=*) [ldap] performing search in CN=Commslab_Enterprise_Admins,OU=Groups,OU=commslab,DC=commslab,DC=local, with filter (cn=Commslab_Domain_Users) [ldap] object not found [ldap] performing search in CN=Domain Admins,CN=Users,DC=commslab,DC=local, with filter (cn=Commslab_Domain_Users) [ldap] object not found rlm_ldap::groupcmp: Group Commslab_Domain_Users not found or user not a member [ldap] ldap_release_conn: Release Id: 0 [ldap] Entering ldap_groupcmp() [files] expand: dc=commslab,dc=local -> dc=commslab,dc=local [files] expand: (|(&(objectClass=GroupOfNames)(member=%{Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{Ldap-UserDn}))) -> (|(&(objectClass=GroupOfNames)(member=))(&(objectClass=GroupOfUniqueNames)(uniquemember=))) [ldap] ldap_get_conn: Checking Id: 0 [ldap] ldap_get_conn: Got Id: 0 [ldap] performing search in dc=commslab,dc=local, with filter (&(cn=Commslab_Enterprise_Admins)(|(&(objectClass=GroupOfNames)(member=))(&(objectClass=GroupOfUniqueNames)(uniquemember=)))) [ldap] object not found [ldap] ldap_release_conn: Release Id: 0 [ldap] ldap_get_conn: Checking Id: 0 [ldap] ldap_get_conn: Got Id: 0 [ldap] performing search in CN=TheAdmin,OU=Users,OU=commslab,DC=commslab,DC=local, with filter (objectclass=*) [ldap] performing search in CN=Commslab_Enterprise_Admins,OU=Groups,OU=commslab,DC=commslab,DC=local, with filter (cn=Commslab_Enterprise_Admins) rlm_ldap::ldap_groupcmp: User found in group Commslab_Enterprise_Admins [ldap] ldap_release_conn: Release Id: 0 ++[files] returns noop ++[expiration] returns noop ++[logintime] returns noop [pap] WARNING! No "known good" password found for the user. Authentication may fail because of this. ++[pap] returns noop ++? if (!control:Auth-Type) ? Evaluating !(control:Auth-Type) -> FALSE ++? if (!control:Auth-Type) -> FALSE Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP NAK [eap] EAP-NAK asked for EAP-Type/mschapv2 [eap] processing type mschapv2 rlm_eap_mschapv2: Issuing Challenge ++[eap] returns handled Sending Access-Challenge of id 3 to 127.0.0.1 port 50066 EAP-Message = 0x010200251a0102002010930f6110164723e95627e52001aff4d9747265766f7261646d696e Message-Authenticator = 0x00000000000000000000000000000000 State = 0xc823e63dc921fc81c661e84e3a0d59ca Finished request 12. Going to the next request Waking up in 4.7 seconds. rad_recv: Access-Request packet from host 127.0.0.1 port 50066, id=4, length=153 User-Name = "TheAdmin" NAS-Port = 0 NAS-IP-Address = 127.0.0.1 State = 0xc823e63dc921fc81c661e84e3a0d59ca EAP-Message = 0x020200461a0202004131b42117333d3bf549251d07a7319c724b0000000000000000cfca112520907fc06b8d9625adebf0f172890cf2a89f8c1f00747265766f7261646d696e Message-Authenticator = 0x3917cdcab9c4ee67b9b697ff2fad2fd0 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] No '@' in User-Name = "TheAdmin", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [eap] EAP packet type response id 2 length 70 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated [ldap] Entering ldap_groupcmp() [files] expand: dc=commslab,dc=local -> dc=commslab,dc=local [files] expand: %{Stripped-User-Name} -> [files] ... expanding second conditional [files] expand: %{User-Name} -> TheAdmin [files] expand: (&(objectclass=user)(sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}}*)) -> (&(objectclass=user)(sAMAccountName=TheAdmin*)) [ldap] ldap_get_conn: Checking Id: 0 [ldap] ldap_get_conn: Got Id: 0 [ldap] performing search in dc=commslab,dc=local, with filter (&(objectclass=user)(sAMAccountName=TheAdmin*)) [ldap] ldap_release_conn: Release Id: 0 [files] expand: (|(&(objectClass=GroupOfNames)(member=%{Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{Ldap-UserDn}))) -> (|(&(objectClass=GroupOfNames)(member=))(&(objectClass=GroupOfUniqueNames)(uniquemember=))) [ldap] ldap_get_conn: Checking Id: 0 [ldap] ldap_get_conn: Got Id: 0 [ldap] performing search in dc=commslab,dc=local, with filter (&(cn=Commslab_Domain_Users)(|(&(objectClass=GroupOfNames)(member=))(&(objectClass=GroupOfUniqueNames)(uniquemember=)))) [ldap] object not found [ldap] ldap_release_conn: Release Id: 0 [ldap] ldap_get_conn: Checking Id: 0 [ldap] ldap_get_conn: Got Id: 0 [ldap] performing search in CN=TheAdmin,OU=Users,OU=commslab,DC=commslab,DC=local, with filter (objectclass=*) [ldap] performing search in CN=Commslab_Enterprise_Admins,OU=Groups,OU=commslab,DC=commslab,DC=local, with filter (cn=Commslab_Domain_Users) [ldap] object not found [ldap] performing search in CN=Domain Admins,CN=Users,DC=commslab,DC=local, with filter (cn=Commslab_Domain_Users) [ldap] object not found rlm_ldap::groupcmp: Group Commslab_Domain_Users not found or user not a member [ldap] ldap_release_conn: Release Id: 0 [ldap] Entering ldap_groupcmp() [files] expand: dc=commslab,dc=local -> dc=commslab,dc=local [files] expand: (|(&(objectClass=GroupOfNames)(member=%{Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{Ldap-UserDn}))) -> (|(&(objectClass=GroupOfNames)(member=))(&(objectClass=GroupOfUniqueNames)(uniquemember=))) [ldap] ldap_get_conn: Checking Id: 0 [ldap] ldap_get_conn: Got Id: 0 [ldap] performing search in dc=commslab,dc=local, with filter (&(cn=Commslab_Enterprise_Admins)(|(&(objectClass=GroupOfNames)(member=))(&(objectClass=GroupOfUniqueNames)(uniquemember=)))) [ldap] object not found [ldap] ldap_release_conn: Release Id: 0 [ldap] ldap_get_conn: Checking Id: 0 [ldap] ldap_get_conn: Got Id: 0 [ldap] performing search in CN=TheAdmin,OU=Users,OU=commslab,DC=commslab,DC=local, with filter (objectclass=*) [ldap] performing search in CN=Commslab_Enterprise_Admins,OU=Groups,OU=commslab,DC=commslab,DC=local, with filter (cn=Commslab_Enterprise_Admins) rlm_ldap::ldap_groupcmp: User found in group Commslab_Enterprise_Admins [ldap] ldap_release_conn: Release Id: 0 ++[files] returns noop ++[expiration] returns noop ++[logintime] returns noop [pap] WARNING! No "known good" password found for the user. Authentication may fail because of this. ++[pap] returns noop ++? if (!control:Auth-Type) ? Evaluating !(control:Auth-Type) -> FALSE ++? if (!control:Auth-Type) -> FALSE Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/mschapv2 [eap] processing type mschapv2 [mschapv2] # Executing group from file /etc/freeradius/sites-enabled/default [mschapv2] +- entering group MS-CHAP {...} [mschap] Creating challenge hash with username: TheAdmin [mschap] Told to do MS-CHAPv2 for TheAdmin with NT-Password [mschap] expand: --username=%{mschap:User-Name:-None} -> --username=TheAdmin [mschap] No NT-Domain was found in the User-Name. [mschap] expand: %{mschap:NT-Domain} -> [mschap] ... expanding second conditional [mschap] expand: --domain=%{%{mschap:NT-Domain}:-commslab} -> --domain=commslab [mschap] mschap2: 93 [mschap] Creating challenge hash with username: TheAdmin [mschap] expand: --challenge=%{mschap:Challenge:-00} -> --challenge=d5bed64075a3500e [mschap] expand: --nt-response=%{mschap:NT-Response:-00} -> --nt-response=cfca112520907fc06b8d9625adebf0f172890cf2a89f8c1f WARNING: The "idmap uid" option is deprecated WARNING: The "idmap gid" option is deprecated Exec-Program output: Access denied (0xc0000022) Exec-Program-Wait: plaintext: Access denied (0xc0000022) Exec-Program: returned: 1 [mschap] External script failed. [mschap] FAILED: MS-CHAP2-Response is incorrect ++[mschap] returns reject [eap] Freeing handler ++[eap] returns reject Failed to authenticate the user. Login incorrect (mschap: External script says Access denied (0xc0000022)): [TheAdmin/<via Auth-Type = EAP>] (from client localhost port 0) Using Post-Auth-Type Reject # Executing group from file /etc/freeradius/sites-enabled/default +- entering group REJECT {...} [attr_filter.access_reject] expand: %{User-Name} -> TheAdmin attr_filter: Matched entry DEFAULT at line 11 ++[attr_filter.access_reject] returns updated Delaying reject of request 13 for 1 seconds Going to the next request Waking up in 0.8 seconds. Sending delayed reject for request 13 Sending Access-Reject of id 4 to 127.0.0.1 port 50066 EAP-Message = 0x04020004 Message-Authenticator = 0x00000000000000000000000000000000 Waking up in 3.6 seconds. Cleaning up request 11 ID 2 with timestamp +897 Waking up in 0.2 seconds. Cleaning up request 12 ID 3 with timestamp +897 Waking up in 1.0 seconds. Cleaning up request 13 ID 4 with timestamp +897 Ready to process requests.
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html