LDAP VPN Auth yet not in group?

freeradius at corwyn.net freeradius at corwyn.net
Tue Aug 24 22:48:22 CEST 2010 



I authenticate VPN users where the VPN Server authenticates against a 
LDAP server and FreeRadius 2.1.8 on CentOS. That generally, works 
fine. I'm using a user account to authenticate the radius server 
against AD for the queries.

What's odd is tho the other user accounts work, I can't authenticate 
with that actual user account (even though it's in the same Security 
group). Multiple other users in the security group VPN_Users work.

What seems (to me) to be odd in particular is I see
ue Aug 24 16:41:57 2010 : Info: ++? if (Huntgroup-Name == "VPN_Huntgroup")
Tue Aug 24 16:41:57 2010 : Info: ? Evaluating (Huntgroup-Name == 
"VPN_Huntgroup") -> TRUE
Tue Aug 24 16:41:57 2010 : Info: ++? if (Huntgroup-Name == 
"VPN_Huntgroup") -> TRUE
Tue Aug 24 16:41:57 2010 : Info: ++- entering if (Huntgroup-Name == 
"VPN_Huntgroup") {...}
Tue Aug 24 16:41:57 2010 : Info: +++? if (Ldap-Group == "VPN_Users")
Tue Aug 24 16:41:57 2010 : Debug:   [ldap] Entering ldap_groupcmp()


which makes me think it sees the user _sonicwall in the VPN_Users 
group, but then I get:

Tue Aug 24 16:41:57 2010 : Debug: rlm_ldap::ldap_groupcmp: 
ldap_get_values() failed
Tue Aug 24 16:41:57 2010 : Debug:   [ldap] ldap_release_conn: Release Id: 0
Tue Aug 24 16:41:57 2010 : Info: ? Evaluating (Ldap-Group == 
"VPN_Users") -> FALSE
Tue Aug 24 16:41:57 2010 : Info: +++? if (Ldap-Group == "VPN_Users") -> FALSE


Any insights appreciated.

Thanks

Rick

Full output below.

rad_recv: Access-Request packet from host 10.4.1.241 port 1196, 
id=26, length=126
         User-Name = "_sonicwall"
         MS-CHAP-Challenge = 0x780006c8503fee2cdf1d2505fe99f322
         MS-CHAP2-Response = 
0x01002f06ff27350f7121396d65349fc61ca90000000000000000675d0094d1b342dc5f172dc60bd9fd258fb94fc68aac5ff6
         NAS-IP-Address = 10.4.1.241
         NAS-Port = 0
Tue Aug 24 16:41:57 2010 : Info: server server_vpn {
Tue Aug 24 16:41:57 2010 : Info: +- entering group authorize {...}
Tue Aug 24 16:41:57 2010 : Info: ++[preprocess] returns ok
Tue Aug 24 16:41:57 2010 : Info: [mschap] Found MS-CHAP 
attributes.  Setting 'Auth-Type  = mschap'
Tue Aug 24 16:41:57 2010 : Info: ++[mschap] returns ok
Tue Aug 24 16:41:57 2010 : Debug:   [ldap] Entering ldap_groupcmp()
Tue Aug 24 16:41:57 2010 : Info: [files]        expand: 
OU=Enterprise,DC=int,DC=invtitle,DC=com -> 
OU=Enterprise,DC=int,DC=invtitle,DC=com
Tue Aug 24 16:41:57 2010 : Info: [files]        expand: 
%{Stripped-User-Name} ->
Tue Aug 24 16:41:57 2010 : Info: [files]        ... expanding second 
conditional
Tue Aug 24 16:41:57 2010 : Info: [files]        expand: %{User-Name} 
-> _sonicwall
Tue Aug 24 16:41:57 2010 : Info: [files]        expand: 
(&(sAMAccountname=%{%{Stripped-User-Name}:-%{User-Name}})(objectClass=person)) 
-> (&(sAMAccountname=_sonicwall)(objectClass=person))
Tue Aug 24 16:41:57 2010 : Debug:   [ldap] ldap_get_conn: Checking Id: 0
Tue Aug 24 16:41:57 2010 : Debug:   [ldap] ldap_get_conn: Got Id: 0
Tue Aug 24 16:41:57 2010 : Debug:   [ldap] performing search in 
OU=Enterprise,DC=int,DC=invtitle,DC=com, with filter 
(&(sAMAccountname=_sonicwall)(objectClass=person))
Tue Aug 24 16:41:57 2010 : Debug:   [ldap] ldap_release_conn: Release Id: 0
Tue Aug 24 16:41:57 2010 : Info: [files]        expand: 
(|(&(objectClass=GroupOfNames)(member=%{control:Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{control:Ldap-UserDn}))) 
-> 
(|(&(objectClass=GroupOfNames)(member=CN\3d_sonicwall\2cOU\3dService 
Accounts\2cOU\3dSpecial User 
Accounts\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dinvtitle\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3d_sonicwall\2cOU\3dService 
Accounts\2cOU\3dSpecial User 
Accounts\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dinvtitle\2cDC\3dcom)))
Tue Aug 24 16:41:57 2010 : Debug:   [ldap] ldap_get_conn: Checking Id: 0
Tue Aug 24 16:41:57 2010 : Debug:   [ldap] ldap_get_conn: Got Id: 0
Tue Aug 24 16:41:57 2010 : Debug:   [ldap] performing search in 
OU=Enterprise,DC=int,DC=invtitle,DC=com, with filter 
(&(cn=VPN_Users)(|(&(objectClass=GroupOfNames)(member=CN\3d_sonicwall\2cOU\3dService 
Accounts\2cOU\3dSpecial User 
Accounts\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dinvtitle\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3d_sonicwall\2cOU\3dService 
Accounts\2cOU\3dSpecial User 
Accounts\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dinvtitle\2cDC\3dcom))))
Tue Aug 24 16:41:57 2010 : Debug:   [ldap] object not found
Tue Aug 24 16:41:57 2010 : Debug:   [ldap] ldap_release_conn: Release Id: 0
Tue Aug 24 16:41:57 2010 : Debug:   [ldap] ldap_get_conn: Checking Id: 0
Tue Aug 24 16:41:57 2010 : Debug:   [ldap] ldap_get_conn: Got Id: 0
Tue Aug 24 16:41:57 2010 : Debug:   [ldap] performing search in 
CN=_sonicwall,OU=Service Accounts,OU=Special User 
Accounts,OU=Enterprise,DC=int,DC=invtitle,DC=com, with filter (objectclass=*)
Tue Aug 24 16:41:57 2010 : Debug: rlm_ldap::ldap_groupcmp: 
ldap_get_values() failed
Tue Aug 24 16:41:57 2010 : Debug:   [ldap] ldap_release_conn: Release Id: 0
Tue Aug 24 16:41:57 2010 : Info: ++[files] returns noop
Tue Aug 24 16:41:57 2010 : Info: [ldap] performing user authorization 
for _sonicwall
Tue Aug 24 16:41:57 2010 : Info: [ldap]         expand: 
%{Stripped-User-Name} ->
Tue Aug 24 16:41:57 2010 : Info: [ldap]         ... expanding second 
conditional
Tue Aug 24 16:41:57 2010 : Info: [ldap]         expand: %{User-Name} 
-> _sonicwall
Tue Aug 24 16:41:57 2010 : Info: [ldap]         expand: 
(&(sAMAccountname=%{%{Stripped-User-Name}:-%{User-Name}})(objectClass=person)) 
-> (&(sAMAccountname=_sonicwall)(objectClass=person))
Tue Aug 24 16:41:57 2010 : Info: [ldap]         expand: 
OU=Enterprise,DC=int,DC=invtitle,DC=com -> 
OU=Enterprise,DC=int,DC=invtitle,DC=com
Tue Aug 24 16:41:57 2010 : Debug:   [ldap] ldap_get_conn: Checking Id: 0
Tue Aug 24 16:41:57 2010 : Debug:   [ldap] ldap_get_conn: Got Id: 0
Tue Aug 24 16:41:57 2010 : Debug:   [ldap] performing search in 
OU=Enterprise,DC=int,DC=invtitle,DC=com, with filter 
(&(sAMAccountname=_sonicwall)(objectClass=person))
Tue Aug 24 16:41:57 2010 : Info: [ldap] looking for check items in directory...
Tue Aug 24 16:41:57 2010 : Info: [ldap] looking for reply items in directory...
Tue Aug 24 16:41:57 2010 : Debug: WARNING: No "known good" password 
was found in LDAP.  Are you sure that the user is configured correctly?
Tue Aug 24 16:41:57 2010 : Info: [ldap] user _sonicwall authorized to 
use remote access
Tue Aug 24 16:41:57 2010 : Debug:   [ldap] ldap_release_conn: Release Id: 0
Tue Aug 24 16:41:57 2010 : Info: ++[ldap] returns ok
Tue Aug 24 16:41:57 2010 : Info: ++? if (Huntgroup-Name == "VPN_Huntgroup")
Tue Aug 24 16:41:57 2010 : Info: ? Evaluating (Huntgroup-Name == 
"VPN_Huntgroup") -> TRUE
Tue Aug 24 16:41:57 2010 : Info: ++? if (Huntgroup-Name == 
"VPN_Huntgroup") -> TRUE
Tue Aug 24 16:41:57 2010 : Info: ++- entering if (Huntgroup-Name == 
"VPN_Huntgroup") {...}
Tue Aug 24 16:41:57 2010 : Info: +++? if (Ldap-Group == "VPN_Users")
Tue Aug 24 16:41:57 2010 : Debug:   [ldap] Entering ldap_groupcmp()
Tue Aug 24 16:41:57 2010 : Info:        expand: 
OU=Enterprise,DC=int,DC=invtitle,DC=com -> 
OU=Enterprise,DC=int,DC=invtitle,DC=com
Tue Aug 24 16:41:57 2010 : Info:        expand: 
(|(&(objectClass=GroupOfNames)(member=%{control:Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{control:Ldap-UserDn}))) 
-> 
(|(&(objectClass=GroupOfNames)(member=CN\3d_sonicwall\2cOU\3dService 
Accounts\2cOU\3dSpecial User 
Accounts\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dinvtitle\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3d_sonicwall\2cOU\3dService 
Accounts\2cOU\3dSpecial User 
Accounts\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dinvtitle\2cDC\3dcom)))
Tue Aug 24 16:41:57 2010 : Debug:   [ldap] ldap_get_conn: Checking Id: 0
Tue Aug 24 16:41:57 2010 : Debug:   [ldap] ldap_get_conn: Got Id: 0
Tue Aug 24 16:41:57 2010 : Debug:   [ldap] performing search in 
OU=Enterprise,DC=int,DC=invtitle,DC=com, with filter 
(&(cn=VPN_Users)(|(&(objectClass=GroupOfNames)(member=CN\3d_sonicwall\2cOU\3dService 
Accounts\2cOU\3dSpecial User 
Accounts\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dinvtitle\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3d_sonicwall\2cOU\3dService 
Accounts\2cOU\3dSpecial User 
Accounts\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dinvtitle\2cDC\3dcom))))
Tue Aug 24 16:41:57 2010 : Debug:   [ldap] object not found
Tue Aug 24 16:41:57 2010 : Debug:   [ldap] ldap_release_conn: Release Id: 0
Tue Aug 24 16:41:57 2010 : Debug:   [ldap] ldap_get_conn: Checking Id: 0
Tue Aug 24 16:41:57 2010 : Debug:   [ldap] ldap_get_conn: Got Id: 0
Tue Aug 24 16:41:57 2010 : Debug:   [ldap] performing search in 
CN=_sonicwall,OU=Service Accounts,OU=Special User 
Accounts,OU=Enterprise,DC=int,DC=invtitle,DC=com, with filter (objectclass=*)
Tue Aug 24 16:41:57 2010 : Debug: rlm_ldap::ldap_groupcmp: 
ldap_get_values() failed
Tue Aug 24 16:41:57 2010 : Debug:   [ldap] ldap_release_conn: Release Id: 0
Tue Aug 24 16:41:57 2010 : Info: ? Evaluating (Ldap-Group == 
"VPN_Users") -> FALSE
Tue Aug 24 16:41:57 2010 : Info: +++? if (Ldap-Group == "VPN_Users") -> FALSE
Tue Aug 24 16:41:57 2010 : Info: +++- entering else else {...}
Tue Aug 24 16:41:57 2010 : Info: ++++[reject] returns reject
Tue Aug 24 16:41:57 2010 : Info: +++- else else returns reject
Tue Aug 24 16:41:57 2010 : Info: ++- if (Huntgroup-Name == 
"VPN_Huntgroup") returns reject
Tue Aug 24 16:41:57 2010 : Auth: Invalid user: [_sonicwall] (from 
client VPN_SOHO port 0)
Tue Aug 24 16:41:57 2010 : Info: } # server server_vpn
Tue Aug 24 16:41:57 2010 : Info: Using Post-Auth-Type Reject
Tue Aug 24 16:41:57 2010 : Info: +- entering group REJECT {...}
Tue Aug 24 16:41:57 2010 : Info: 
[attr_filter.access_reject]    expand: %{User-Name} -> _sonicwall
Tue Aug 24 16:41:57 2010 : Debug:  attr_filter: Matched entry DEFAULT 
at line 11
Tue Aug 24 16:41:57 2010 : Info: ++[attr_filter.access_reject] returns updated
Tue Aug 24 16:41:57 2010 : Info: Delaying reject of request 17 for 1 seconds
Tue Aug 24 16:41:57 2010 : Debug: Going to the next request
Tue Aug 24 16:41:57 2010 : Debug: Waking up in 0.9 seconds.
Tue Aug 24 16:41:58 2010 : Info: Sending delayed reject for request 17
Sending Access-Reject of id 26 to 10.4.1.241 port 1196
Tue Aug 24 16:41:58 2010 : Debug: Waking up in 4.9 seconds.



Rick Steeves
http://www.sinister.net

In reality nothing is more damaging to the adventurous spirit within 
a man than a secure future -  Alexander Supertramp

More information about the Freeradius-Users mailing list