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