freeRadius 2.1.10 PEAP/MSCHAPv2 w/ Active Directory

trevor_marquis at selinc.com trevor_marquis at selinc.com
Thu Apr 11 19:55:20 CEST 2013


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.





-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freeradius.org/pipermail/freeradius-users/attachments/20130411/37d07a66/attachment-0001.html>


More information about the Freeradius-Users mailing list