July 2010 - Freeradius-Users - lists.freeradius.org

Freeradius2 and Samba3x
by freeradius＠corwyn.net 14 Jul '10

14 Jul '10

We're in the process of upgrading from Windows 2003 to 2008 R2. Our Linux systems are CentOS 5.5. Looks like samba won't auth against 2008 r2. So we upgraded to samba 3x, but that appears to break freeradius. Hrm. We're using freeradius to auth VPN users that are connecting from a sonicwall firewall, using the windows l2tp client. freeradius2-2.1.8-2.el5 Here's the output from radiusd -xX rad_recv: Access-Request packet from host 10.4.1.2 port 2452, id=213, length=124 User-Name = "useraccount" MS-CHAP-Challenge = 0xc527897da16351a24f3a92d91b066df1 MS-CHAP2-Response = 0x0100f3dd5207d539bd0d7e1f7be50178d3820000000000000000a3492c6411f5548251a05606aa028964d34b69c58e61c7d5 NAS-IP-Address = 10.4.1.2 NAS-Port = 0 Wed Jul 14 10:51:16 2010 : Info: server server_vpn { Wed Jul 14 10:51:16 2010 : Info: +- entering group authorize {...} Wed Jul 14 10:51:16 2010 : Info: ++[preprocess] returns ok Wed Jul 14 10:51:16 2010 : Info: [mschap] Found MS-CHAP attributes. Setting 'Auth-Type = mschap' Wed Jul 14 10:51:16 2010 : Info: ++[mschap] returns ok Wed Jul 14 10:51:16 2010 : Debug: [ldap] Entering ldap_groupcmp() Wed Jul 14 10:51:16 2010 : Info: [files] expand: OU=Enterprise,DC=int,DC=example,DC=com -> OU=Enterprise,DC=int,DC=example,DC=com Wed Jul 14 10:51:16 2010 : Info: [files] expand: %{Stripped-User-Name} -> Wed Jul 14 10:51:16 2010 : Info: [files] ... expanding second conditional Wed Jul 14 10:51:16 2010 : Info: [files] expand: %{User-Name} -> useraccount Wed Jul 14 10:51:16 2010 : Info: [files] expand: (&(sAMAccountname=%{%{Stripped-User-Name}:-%{User-Name}})(objectClass=person)) -> (&(sAMAccountname=useraccount)(objectClass=person)) Wed Jul 14 10:51:16 2010 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Wed Jul 14 10:51:16 2010 : Debug: [ldap] ldap_get_conn: Got Id: 0 Wed Jul 14 10:51:16 2010 : Debug: [ldap] attempting LDAP reconnection Wed Jul 14 10:51:16 2010 : Debug: [ldap] (re)connect to int.example.com:389, authentication 0 Wed Jul 14 10:51:16 2010 : Debug: [ldap] bind as CN=_sonicwall,OU=Service Accounts,OU=Special User Accounts,OU=Enterprise,DC=int,DC=example,DC=com/wvyjCHCd2LJHcNrmpr0I to int.example.com:389 Wed Jul 14 10:51:16 2010 : Debug: [ldap] waiting for bind result ... Wed Jul 14 10:51:16 2010 : Debug: [ldap] Bind was successful Wed Jul 14 10:51:16 2010 : Debug: [ldap] performing search in OU=Enterprise,DC=int,DC=example,DC=com, with filter (&(sAMAccountname=useraccount)(objectClass=person)) Wed Jul 14 10:51:16 2010 : Debug: [ldap] ldap_release_conn: Release Id: 0 Wed Jul 14 10:51:16 2010 : Info: [files] expand: (|(&(objectClass=GroupOfNames)(member=%{control:Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{control:Ldap-UserDn}))) -> (|(&(objectClass=GroupOfNames)(member=CN\3dUser Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dUser Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom))) Wed Jul 14 10:51:16 2010 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Wed Jul 14 10:51:16 2010 : Debug: [ldap] ldap_get_conn: Got Id: 0 Wed Jul 14 10:51:16 2010 : Debug: [ldap] performing search in OU=Enterprise,DC=int,DC=example,DC=com, with filter (&(cn=VPN_Users)(|(&(objectClass=GroupOfNames)(member=CN\3dUser Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dUser Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom)))) Wed Jul 14 10:51:16 2010 : Debug: [ldap] object not found Wed Jul 14 10:51:16 2010 : Debug: [ldap] ldap_release_conn: Release Id: 0 Wed Jul 14 10:51:16 2010 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Wed Jul 14 10:51:16 2010 : Debug: [ldap] ldap_get_conn: Got Id: 0 Wed Jul 14 10:51:16 2010 : Debug: [ldap] performing search in CN=User Account,OU=IS,OU=Users,OU=Enterprise,DC=int,DC=example,DC=com, with filter (objectclass=*) Wed Jul 14 10:51:16 2010 : Debug: [ldap] performing search in CN=VPN_Users,OU=Security Groups,OU=Enterprise,DC=int,DC=example,DC=com, with filter (cn=VPN_Users) Wed Jul 14 10:51:16 2010 : Debug: rlm_ldap::ldap_groupcmp: User found in group VPN_Users Wed Jul 14 10:51:16 2010 : Debug: [ldap] ldap_release_conn: Release Id: 0 Wed Jul 14 10:51:16 2010 : Info: [files] users: Matched entry DEFAULT at line 11 Wed Jul 14 10:51:16 2010 : Info: ++[files] returns ok Wed Jul 14 10:51:16 2010 : Info: [ldap] performing user authorization for useraccount Wed Jul 14 10:51:16 2010 : Info: [ldap] expand: %{Stripped-User-Name} -> Wed Jul 14 10:51:16 2010 : Info: [ldap] ... expanding second conditional Wed Jul 14 10:51:16 2010 : Info: [ldap] expand: %{User-Name} -> useraccount Wed Jul 14 10:51:16 2010 : Info: [ldap] expand: (&(sAMAccountname=%{%{Stripped-User-Name}:-%{User-Name}})(objectClass=person)) -> (&(sAMAccountname=useraccount)(objectClass=person)) Wed Jul 14 10:51:16 2010 : Info: [ldap] expand: OU=Enterprise,DC=int,DC=example,DC=com -> OU=Enterprise,DC=int,DC=example,DC=com Wed Jul 14 10:51:16 2010 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Wed Jul 14 10:51:16 2010 : Debug: [ldap] ldap_get_conn: Got Id: 0 Wed Jul 14 10:51:16 2010 : Debug: [ldap] performing search in OU=Enterprise,DC=int,DC=example,DC=com, with filter (&(sAMAccountname=useraccount)(objectClass=person)) Wed Jul 14 10:51:16 2010 : Info: [ldap] looking for check items in directory... Wed Jul 14 10:51:16 2010 : Info: [ldap] looking for reply items in directory... Wed Jul 14 10:51:16 2010 : Debug: WARNING: No "known good" password was found in LDAP. Are you sure that the user is configured correctly? Wed Jul 14 10:51:16 2010 : Info: [ldap] user useraccount authorized to use remote access Wed Jul 14 10:51:16 2010 : Debug: [ldap] ldap_release_conn: Release Id: 0 Wed Jul 14 10:51:16 2010 : Info: ++[ldap] returns ok Wed Jul 14 10:51:16 2010 : Info: ++? if (Huntgroup-Name == "VPN_Huntgroup") Wed Jul 14 10:51:16 2010 : Info: ? Evaluating (Huntgroup-Name == "VPN_Huntgroup") -> TRUE Wed Jul 14 10:51:16 2010 : Info: ++? if (Huntgroup-Name == "VPN_Huntgroup") -> TRUE Wed Jul 14 10:51:16 2010 : Info: ++- entering if (Huntgroup-Name == "VPN_Huntgroup") {...} Wed Jul 14 10:51:16 2010 : Info: +++? if (Ldap-Group == "VPN_Users") Wed Jul 14 10:51:16 2010 : Debug: [ldap] Entering ldap_groupcmp() Wed Jul 14 10:51:16 2010 : Info: expand: OU=Enterprise,DC=int,DC=example,DC=com -> OU=Enterprise,DC=int,DC=example,DC=com Wed Jul 14 10:51:16 2010 : Info: expand: (|(&(objectClass=GroupOfNames)(member=%{control:Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{control:Ldap-UserDn}))) -> (|(&(objectClass=GroupOfNames)(member=CN\3dUser Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dUser Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom))) Wed Jul 14 10:51:16 2010 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Wed Jul 14 10:51:16 2010 : Debug: [ldap] ldap_get_conn: Got Id: 0 Wed Jul 14 10:51:16 2010 : Debug: [ldap] performing search in OU=Enterprise,DC=int,DC=example,DC=com, with filter (&(cn=VPN_Users)(|(&(objectClass=GroupOfNames)(member=CN\3dUser Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dUser Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom)))) Wed Jul 14 10:51:16 2010 : Debug: [ldap] object not found Wed Jul 14 10:51:16 2010 : Debug: [ldap] ldap_release_conn: Release Id: 0 Wed Jul 14 10:51:16 2010 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Wed Jul 14 10:51:16 2010 : Debug: [ldap] ldap_get_conn: Got Id: 0 Wed Jul 14 10:51:16 2010 : Debug: [ldap] performing search in CN=User Account,OU=IS,OU=Users,OU=Enterprise,DC=int,DC=example,DC=com, with filter (objectclass=*) Wed Jul 14 10:51:16 2010 : Debug: [ldap] performing search in CN=VPN_Users,OU=Security Groups,OU=Enterprise,DC=int,DC=example,DC=com, with filter (cn=VPN_Users) Wed Jul 14 10:51:16 2010 : Debug: rlm_ldap::ldap_groupcmp: User found in group VPN_Users Wed Jul 14 10:51:16 2010 : Debug: [ldap] ldap_release_conn: Release Id: 0 Wed Jul 14 10:51:16 2010 : Info: ? Evaluating (Ldap-Group == "VPN_Users") -> TRUE Wed Jul 14 10:51:16 2010 : Info: +++? if (Ldap-Group == "VPN_Users") -> TRUE Wed Jul 14 10:51:16 2010 : Info: +++- entering if (Ldap-Group == "VPN_Users") {...} Wed Jul 14 10:51:16 2010 : Info: ++++[ok] returns ok Wed Jul 14 10:51:16 2010 : Info: +++- if (Ldap-Group == "VPN_Users") returns ok Wed Jul 14 10:51:16 2010 : Info: +++ ... skipping else for request 0: Preceding "if" was taken Wed Jul 14 10:51:16 2010 : Info: ++- if (Huntgroup-Name == "VPN_Huntgroup") returns ok Wed Jul 14 10:51:16 2010 : Info: Found Auth-Type = MSCHAP Wed Jul 14 10:51:16 2010 : Info: +- entering group MS-CHAP {...} Wed Jul 14 10:51:16 2010 : Info: [mschap] Told to do MS-CHAPv2 for useraccount with NT-Password Wed Jul 14 10:51:16 2010 : Info: [mschap] expand: --username=%{mschap:User-Name} -> --username=useraccount Wed Jul 14 10:51:16 2010 : Info: [mschap] No NT-Domain was found in the User-Name. Wed Jul 14 10:51:16 2010 : Info: [mschap] expand: --domain=%{mschap:NT-Domain:-int.example.com} -> --domain= Wed Jul 14 10:51:16 2010 : Info: [mschap] mschap2: c5 Wed Jul 14 10:51:16 2010 : Info: [mschap] expand: --challenge=%{mschap:Challenge:-00} -> --challenge=a7b7f9db587b6d58 Wed Jul 14 10:51:16 2010 : Info: [mschap] expand: --nt-response=%{mschap:NT-Response:-00} -> --nt-response=a3492c6411f5548251a05606aa028964d34b69c58e61c7d5 Wed Jul 14 10:51:16 2010 : Debug: Exec-Program output: winbind client not authorized to use winbindd_pam_auth_crap. Ensure permissions on /var/lib/samba/winbindd_privileged are set correctly. (0xc0000022) Wed Jul 14 10:51:16 2010 : Debug: Exec-Program-Wait: plaintext: winbind client not authorized to use winbindd_pam_auth_crap. Ensure permissions on /var/lib/samba/winbindd_privileged are set correctly. (0xc0000022) Wed Jul 14 10:51:16 2010 : Debug: Exec-Program: returned: 1 Wed Jul 14 10:51:16 2010 : Info: [mschap] External script failed. Wed Jul 14 10:51:16 2010 : Info: [mschap] FAILED: MS-CHAP2-Response is incorrect Wed Jul 14 10:51:16 2010 : Info: ++[mschap] returns reject Wed Jul 14 10:51:16 2010 : Info: Failed to authenticate the user. Wed Jul 14 10:51:16 2010 : Auth: Login incorrect: [useraccount] (from client VPN port 0) Wed Jul 14 10:51:16 2010 : Info: } # server server_vpn Wed Jul 14 10:51:16 2010 : Info: Using Post-Auth-Type Reject Wed Jul 14 10:51:16 2010 : Info: +- entering group REJECT {...} Wed Jul 14 10:51:16 2010 : Info: [attr_filter.access_reject] expand: %{User-Name} -> useraccount Wed Jul 14 10:51:16 2010 : Debug: attr_filter: Matched entry DEFAULT at line 11 Wed Jul 14 10:51:16 2010 : Info: ++[attr_filter.access_reject] returns updated Wed Jul 14 10:51:16 2010 : Info: Delaying reject of request 0 for 1 seconds Wed Jul 14 10:51:16 2010 : Debug: Going to the next request Wed Jul 14 10:51:16 2010 : Debug: Waking up in 0.9 seconds. Wed Jul 14 10:51:17 2010 : Info: Sending delayed reject for request 0 Sending Access-Reject of id 213 to 10.4.1.2 port 2452 Reply-Message := "Authorized Users Only" Wed Jul 14 10:51:17 2010 : Debug: Waking up in 4.9 seconds. Wed Jul 14 10:51:22 2010 : Info: Cleaning up request 0 ID 213 with timestamp +52 Wed Jul 14 10:51:22 2010 : Info: Ready to process requests. rad_recv: Access-Request packet from host 10.4.1.2 port 2452, id=214, length=124 User-Name = "useraccount" MS-CHAP-Challenge = 0x74b06b183b08ce9d41907535cafb1ed3 MS-CHAP2-Response = 0x01000bd21f7a41e97a616ca8dd0634f4e5230000000000000000d4c66c9dd3cabae77edfe564c745de287968a0441d0df3a5 NAS-IP-Address = 10.4.1.2 NAS-Port = 0 Wed Jul 14 10:51:45 2010 : Info: server server_vpn { Wed Jul 14 10:51:45 2010 : Info: +- entering group authorize {...} Wed Jul 14 10:51:45 2010 : Info: ++[preprocess] returns ok Wed Jul 14 10:51:45 2010 : Info: [mschap] Found MS-CHAP attributes. Setting 'Auth-Type = mschap' Wed Jul 14 10:51:45 2010 : Info: ++[mschap] returns ok Wed Jul 14 10:51:45 2010 : Debug: [ldap] Entering ldap_groupcmp() Wed Jul 14 10:51:45 2010 : Info: [files] expand: OU=Enterprise,DC=int,DC=example,DC=com -> OU=Enterprise,DC=int,DC=example,DC=com Wed Jul 14 10:51:45 2010 : Info: [files] expand: %{Stripped-User-Name} -> Wed Jul 14 10:51:45 2010 : Info: [files] ... expanding second conditional Wed Jul 14 10:51:45 2010 : Info: [files] expand: %{User-Name} -> useraccount Wed Jul 14 10:51:45 2010 : Info: [files] expand: (&(sAMAccountname=%{%{Stripped-User-Name}:-%{User-Name}})(objectClass=person)) -> (&(sAMAccountname=useraccount)(objectClass=person)) Wed Jul 14 10:51:45 2010 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Wed Jul 14 10:51:45 2010 : Debug: [ldap] ldap_get_conn: Got Id: 0 Wed Jul 14 10:51:45 2010 : Debug: [ldap] performing search in OU=Enterprise,DC=int,DC=example,DC=com, with filter (&(sAMAccountname=useraccount)(objectClass=person)) Wed Jul 14 10:51:45 2010 : Debug: [ldap] ldap_release_conn: Release Id: 0 Wed Jul 14 10:51:45 2010 : Info: [files] expand: (|(&(objectClass=GroupOfNames)(member=%{control:Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{control:Ldap-UserDn}))) -> (|(&(objectClass=GroupOfNames)(member=CN\3dUser Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dUser Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom))) Wed Jul 14 10:51:45 2010 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Wed Jul 14 10:51:45 2010 : Debug: [ldap] ldap_get_conn: Got Id: 0 Wed Jul 14 10:51:45 2010 : Debug: [ldap] performing search in OU=Enterprise,DC=int,DC=example,DC=com, with filter (&(cn=VPN_Users)(|(&(objectClass=GroupOfNames)(member=CN\3dUser Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dUser Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom)))) Wed Jul 14 10:51:45 2010 : Debug: [ldap] object not found Wed Jul 14 10:51:45 2010 : Debug: [ldap] ldap_release_conn: Release Id: 0 Wed Jul 14 10:51:45 2010 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Wed Jul 14 10:51:45 2010 : Debug: [ldap] ldap_get_conn: Got Id: 0 Wed Jul 14 10:51:45 2010 : Debug: [ldap] performing search in CN=User Account,OU=IS,OU=Users,OU=Enterprise,DC=int,DC=example,DC=com, with filter (objectclass=*) Wed Jul 14 10:51:45 2010 : Debug: [ldap] performing search in CN=VPN_Users,OU=Security Groups,OU=Enterprise,DC=int,DC=example,DC=com, with filter (cn=VPN_Users) Wed Jul 14 10:51:45 2010 : Debug: rlm_ldap::ldap_groupcmp: User found in group VPN_Users Wed Jul 14 10:51:45 2010 : Debug: [ldap] ldap_release_conn: Release Id: 0 Wed Jul 14 10:51:45 2010 : Info: [files] users: Matched entry DEFAULT at line 11 Wed Jul 14 10:51:45 2010 : Info: ++[files] returns ok Wed Jul 14 10:51:45 2010 : Info: [ldap] performing user authorization for useraccount Wed Jul 14 10:51:45 2010 : Info: [ldap] expand: %{Stripped-User-Name} -> Wed Jul 14 10:51:45 2010 : Info: [ldap] ... expanding second conditional Wed Jul 14 10:51:45 2010 : Info: [ldap] expand: %{User-Name} -> useraccount Wed Jul 14 10:51:45 2010 : Info: [ldap] expand: (&(sAMAccountname=%{%{Stripped-User-Name}:-%{User-Name}})(objectClass=person)) -> (&(sAMAccountname=useraccount)(objectClass=person)) Wed Jul 14 10:51:45 2010 : Info: [ldap] expand: OU=Enterprise,DC=int,DC=example,DC=com -> OU=Enterprise,DC=int,DC=example,DC=com Wed Jul 14 10:51:45 2010 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Wed Jul 14 10:51:45 2010 : Debug: [ldap] ldap_get_conn: Got Id: 0 Wed Jul 14 10:51:45 2010 : Debug: [ldap] performing search in OU=Enterprise,DC=int,DC=example,DC=com, with filter (&(sAMAccountname=useraccount)(objectClass=person)) Wed Jul 14 10:51:45 2010 : Info: [ldap] looking for check items in directory... Wed Jul 14 10:51:45 2010 : Info: [ldap] looking for reply items in directory... Wed Jul 14 10:51:45 2010 : Debug: WARNING: No "known good" password was found in LDAP. Are you sure that the user is configured correctly? Wed Jul 14 10:51:45 2010 : Info: [ldap] user useraccount authorized to use remote access Wed Jul 14 10:51:45 2010 : Debug: [ldap] ldap_release_conn: Release Id: 0 Wed Jul 14 10:51:45 2010 : Info: ++[ldap] returns ok Wed Jul 14 10:51:45 2010 : Info: ++? if (Huntgroup-Name == "VPN_Huntgroup") Wed Jul 14 10:51:45 2010 : Info: ? Evaluating (Huntgroup-Name == "VPN_Huntgroup") -> TRUE Wed Jul 14 10:51:45 2010 : Info: ++? if (Huntgroup-Name == "VPN_Huntgroup") -> TRUE Wed Jul 14 10:51:45 2010 : Info: ++- entering if (Huntgroup-Name == "VPN_Huntgroup") {...} Wed Jul 14 10:51:45 2010 : Info: +++? if (Ldap-Group == "VPN_Users") Wed Jul 14 10:51:45 2010 : Debug: [ldap] Entering ldap_groupcmp() Wed Jul 14 10:51:45 2010 : Info: expand: OU=Enterprise,DC=int,DC=example,DC=com -> OU=Enterprise,DC=int,DC=example,DC=com Wed Jul 14 10:51:45 2010 : Info: expand: (|(&(objectClass=GroupOfNames)(member=%{control:Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{control:Ldap-UserDn}))) -> (|(&(objectClass=GroupOfNames)(member=CN\3dUser Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dUser Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom))) Wed Jul 14 10:51:45 2010 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Wed Jul 14 10:51:45 2010 : Debug: [ldap] ldap_get_conn: Got Id: 0 Wed Jul 14 10:51:45 2010 : Debug: [ldap] performing search in OU=Enterprise,DC=int,DC=example,DC=com, with filter (&(cn=VPN_Users)(|(&(objectClass=GroupOfNames)(member=CN\3dUser Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dUser Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom)))) Wed Jul 14 10:51:45 2010 : Debug: [ldap] object not found Wed Jul 14 10:51:45 2010 : Debug: [ldap] ldap_release_conn: Release Id: 0 Wed Jul 14 10:51:45 2010 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Wed Jul 14 10:51:45 2010 : Debug: [ldap] ldap_get_conn: Got Id: 0 Wed Jul 14 10:51:45 2010 : Debug: [ldap] performing search in CN=User Account,OU=IS,OU=Users,OU=Enterprise,DC=int,DC=example,DC=com, with filter (objectclass=*) Wed Jul 14 10:51:45 2010 : Debug: [ldap] performing search in CN=VPN_Users,OU=Security Groups,OU=Enterprise,DC=int,DC=example,DC=com, with filter (cn=VPN_Users) Wed Jul 14 10:51:45 2010 : Debug: rlm_ldap::ldap_groupcmp: User found in group VPN_Users Wed Jul 14 10:51:45 2010 : Debug: [ldap] ldap_release_conn: Release Id: 0 Wed Jul 14 10:51:45 2010 : Info: ? Evaluating (Ldap-Group == "VPN_Users") -> TRUE Wed Jul 14 10:51:45 2010 : Info: +++? if (Ldap-Group == "VPN_Users") -> TRUE Wed Jul 14 10:51:45 2010 : Info: +++- entering if (Ldap-Group == "VPN_Users") {...} Wed Jul 14 10:51:45 2010 : Info: ++++[ok] returns ok Wed Jul 14 10:51:45 2010 : Info: +++- if (Ldap-Group == "VPN_Users") returns ok Wed Jul 14 10:51:45 2010 : Info: +++ ... skipping else for request 1: Preceding "if" was taken Wed Jul 14 10:51:45 2010 : Info: ++- if (Huntgroup-Name == "VPN_Huntgroup") returns ok Wed Jul 14 10:51:45 2010 : Info: Found Auth-Type = MSCHAP Wed Jul 14 10:51:45 2010 : Info: +- entering group MS-CHAP {...} Wed Jul 14 10:51:45 2010 : Info: [mschap] Told to do MS-CHAPv2 for useraccount with NT-Password Wed Jul 14 10:51:45 2010 : Info: [mschap] expand: --username=%{mschap:User-Name} -> --username=useraccount Wed Jul 14 10:51:45 2010 : Info: [mschap] No NT-Domain was found in the User-Name. Wed Jul 14 10:51:45 2010 : Info: [mschap] expand: --domain=%{mschap:NT-Domain:-int.example.com} -> --domain= Wed Jul 14 10:51:45 2010 : Info: [mschap] mschap2: 74 Wed Jul 14 10:51:45 2010 : Info: [mschap] expand: --challenge=%{mschap:Challenge:-00} -> --challenge=03128051e813c832 Wed Jul 14 10:51:45 2010 : Info: [mschap] expand: --nt-response=%{mschap:NT-Response:-00} -> --nt-response=d4c66c9dd3cabae77edfe564c745de287968a0441d0df3a5 Wed Jul 14 10:51:45 2010 : Debug: Exec-Program output: winbind client not authorized to use winbindd_pam_auth_crap. Ensure permissions on /var/lib/samba/winbindd_privileged are set correctly. (0xc0000022) Wed Jul 14 10:51:45 2010 : Debug: Exec-Program-Wait: plaintext: winbind client not authorized to use winbindd_pam_auth_crap. Ensure permissions on /var/lib/samba/winbindd_privileged are set correctly. (0xc0000022) Wed Jul 14 10:51:45 2010 : Debug: Exec-Program: returned: 1 Wed Jul 14 10:51:45 2010 : Info: [mschap] External script failed. Wed Jul 14 10:51:45 2010 : Info: [mschap] FAILED: MS-CHAP2-Response is incorrect Wed Jul 14 10:51:45 2010 : Info: ++[mschap] returns reject Wed Jul 14 10:51:45 2010 : Info: Failed to authenticate the user. Wed Jul 14 10:51:45 2010 : Auth: Login incorrect: [useraccount] (from client VPN port 0) Wed Jul 14 10:51:45 2010 : Info: } # server server_vpn Wed Jul 14 10:51:45 2010 : Info: Using Post-Auth-Type Reject Wed Jul 14 10:51:45 2010 : Info: +- entering group REJECT {...} Wed Jul 14 10:51:45 2010 : Info: [attr_filter.access_reject] expand: %{User-Name} -> useraccount Wed Jul 14 10:51:45 2010 : Debug: attr_filter: Matched entry DEFAULT at line 11 Wed Jul 14 10:51:45 2010 : Info: ++[attr_filter.access_reject] returns updated Wed Jul 14 10:51:45 2010 : Info: Delaying reject of request 1 for 1 seconds Wed Jul 14 10:51:45 2010 : Debug: Going to the next request Wed Jul 14 10:51:45 2010 : Debug: Waking up in 0.9 seconds. Wed Jul 14 10:51:46 2010 : Info: Sending delayed reject for request 1 Sending Access-Reject of id 214 to 10.4.1.2 port 2452 Reply-Message := "Authorized Users Only" Wed Jul 14 10:51:46 2010 : Debug: Waking up in 4.9 seconds. Wed Jul 14 10:51:51 2010 : Info: Cleaning up request 1 ID 214 with timestamp +81 Wed Jul 14 10:51:51 2010 : Info: Ready to process requests. Now, I've seen that problem before of : Wed Jul 14 10:51:45 2010 : Debug: Exec-Program-Wait: plaintext: winbind client not authorized to use winbindd_pam_auth_crap. Ensure permissions on /var/lib/samba/winbindd_privileged are set correctly. (0xc0000022) whenever I patch samba. And I usually fix it with: chgrp radiusd /var/cache/samba/winbindd_privileged but with the upgrade to samba3x that doesn't work, because the group is now wbpriv. So instead I added the radiusd user to the wbpriv group: usermod -a -G wbpriv radiusd But it still fails, tho noting leaps out oat me from the output: rad_recv: Access-Request packet from host 10.4.1.2 port 2452, id=224, length=124 User-Name = "useraccount" MS-CHAP-Challenge = 0x36ad83e8c48bd67061d4059cd1a5e3a1 MS-CHAP2-Response = 0x01000c60a44ccac150a8d8961f218cfd07b5000000000000000000be3e466ff82a106ee9e3144e442c6caa1bcb71636031b6 NAS-IP-Address = 10.4.1.2 NAS-Port = 0 Wed Jul 14 11:18:08 2010 : Info: server server_vpn { Wed Jul 14 11:18:08 2010 : Info: +- entering group authorize {...} Wed Jul 14 11:18:08 2010 : Info: ++[preprocess] returns ok Wed Jul 14 11:18:08 2010 : Info: [mschap] Found MS-CHAP attributes. Setting 'Auth-Type = mschap' Wed Jul 14 11:18:08 2010 : Info: ++[mschap] returns ok Wed Jul 14 11:18:08 2010 : Debug: [ldap] Entering ldap_groupcmp() Wed Jul 14 11:18:08 2010 : Info: [files] expand: OU=Enterprise,DC=int,DC=example,DC=com -> OU=Enterprise,DC=int,DC=example,DC=com Wed Jul 14 11:18:08 2010 : Info: [files] expand: %{Stripped-User-Name} -> Wed Jul 14 11:18:08 2010 : Info: [files] ... expanding second conditional Wed Jul 14 11:18:08 2010 : Info: [files] expand: %{User-Name} -> useraccount Wed Jul 14 11:18:08 2010 : Info: [files] expand: (&(sAMAccountname=%{%{Stripped-User-Name}:-%{User-Name}})(objectClass=person)) -> (&(sAMAccountname=useraccount)(objectClass=person)) Wed Jul 14 11:18:08 2010 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Wed Jul 14 11:18:08 2010 : Debug: [ldap] ldap_get_conn: Got Id: 0 Wed Jul 14 11:18:08 2010 : Debug: [ldap] performing search in OU=Enterprise,DC=int,DC=example,DC=com, with filter (&(sAMAccountname=useraccount)(objectClass=person)) Wed Jul 14 11:18:08 2010 : Debug: [ldap] ldap_release_conn: Release Id: 0 Wed Jul 14 11:18:08 2010 : Info: [files] expand: (|(&(objectClass=GroupOfNames)(member=%{control:Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{control:Ldap-UserDn}))) -> (|(&(objectClass=GroupOfNames)(member=CN\3dUser Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dUser Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom))) Wed Jul 14 11:18:08 2010 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Wed Jul 14 11:18:08 2010 : Debug: [ldap] ldap_get_conn: Got Id: 0 Wed Jul 14 11:18:08 2010 : Debug: [ldap] performing search in OU=Enterprise,DC=int,DC=example,DC=com, with filter (&(cn=VPN_Users)(|(&(objectClass=GroupOfNames)(member=CN\3dUser Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dUser Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom)))) Wed Jul 14 11:18:08 2010 : Debug: [ldap] object not found Wed Jul 14 11:18:08 2010 : Debug: [ldap] ldap_release_conn: Release Id: 0 Wed Jul 14 11:18:08 2010 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Wed Jul 14 11:18:08 2010 : Debug: [ldap] ldap_get_conn: Got Id: 0 Wed Jul 14 11:18:08 2010 : Debug: [ldap] performing search in CN=User Account,OU=IS,OU=Users,OU=Enterprise,DC=int,DC=example,DC=com, with filter (objectclass=*) Wed Jul 14 11:18:08 2010 : Debug: [ldap] performing search in CN=VPN_Users,OU=Security Groups,OU=Enterprise,DC=int,DC=example,DC=com, with filter (cn=VPN_Users) Wed Jul 14 11:18:08 2010 : Debug: rlm_ldap::ldap_groupcmp: User found in group VPN_Users Wed Jul 14 11:18:08 2010 : Debug: [ldap] ldap_release_conn: Release Id: 0 Wed Jul 14 11:18:08 2010 : Info: [files] users: Matched entry DEFAULT at line 11 Wed Jul 14 11:18:08 2010 : Info: ++[files] returns ok Wed Jul 14 11:18:08 2010 : Info: [ldap] performing user authorization for useraccount Wed Jul 14 11:18:08 2010 : Info: [ldap] expand: %{Stripped-User-Name} -> Wed Jul 14 11:18:08 2010 : Info: [ldap] ... expanding second conditional Wed Jul 14 11:18:08 2010 : Info: [ldap] expand: %{User-Name} -> useraccount Wed Jul 14 11:18:08 2010 : Info: [ldap] expand: (&(sAMAccountname=%{%{Stripped-User-Name}:-%{User-Name}})(objectClass=person)) -> (&(sAMAccountname=useraccount)(objectClass=person)) Wed Jul 14 11:18:08 2010 : Info: [ldap] expand: OU=Enterprise,DC=int,DC=example,DC=com -> OU=Enterprise,DC=int,DC=example,DC=com Wed Jul 14 11:18:08 2010 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Wed Jul 14 11:18:08 2010 : Debug: [ldap] ldap_get_conn: Got Id: 0 Wed Jul 14 11:18:08 2010 : Debug: [ldap] performing search in OU=Enterprise,DC=int,DC=example,DC=com, with filter (&(sAMAccountname=useraccount)(objectClass=person)) Wed Jul 14 11:18:08 2010 : Info: [ldap] looking for check items in directory... Wed Jul 14 11:18:08 2010 : Info: [ldap] looking for reply items in directory... Wed Jul 14 11:18:08 2010 : Debug: WARNING: No "known good" password was found in LDAP. Are you sure that the user is configured correctly? Wed Jul 14 11:18:08 2010 : Info: [ldap] user useraccount authorized to use remote access Wed Jul 14 11:18:08 2010 : Debug: [ldap] ldap_release_conn: Release Id: 0 Wed Jul 14 11:18:08 2010 : Info: ++[ldap] returns ok Wed Jul 14 11:18:08 2010 : Info: ++? if (Huntgroup-Name == "VPN_Huntgroup") Wed Jul 14 11:18:08 2010 : Info: ? Evaluating (Huntgroup-Name == "VPN_Huntgroup") -> TRUE Wed Jul 14 11:18:08 2010 : Info: ++? if (Huntgroup-Name == "VPN_Huntgroup") -> TRUE Wed Jul 14 11:18:08 2010 : Info: ++- entering if (Huntgroup-Name == "VPN_Huntgroup") {...} Wed Jul 14 11:18:08 2010 : Info: +++? if (Ldap-Group == "VPN_Users") Wed Jul 14 11:18:08 2010 : Debug: [ldap] Entering ldap_groupcmp() Wed Jul 14 11:18:08 2010 : Info: expand: OU=Enterprise,DC=int,DC=example,DC=com -> OU=Enterprise,DC=int,DC=example,DC=com Wed Jul 14 11:18:08 2010 : Info: expand: (|(&(objectClass=GroupOfNames)(member=%{control:Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{control:Ldap-UserDn}))) -> (|(&(objectClass=GroupOfNames)(member=CN\3dUser Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dUser Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom))) Wed Jul 14 11:18:08 2010 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Wed Jul 14 11:18:08 2010 : Debug: [ldap] ldap_get_conn: Got Id: 0 Wed Jul 14 11:18:08 2010 : Debug: [ldap] performing search in OU=Enterprise,DC=int,DC=example,DC=com, with filter (&(cn=VPN_Users)(|(&(objectClass=GroupOfNames)(member=CN\3dUser Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dUser Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom)))) Wed Jul 14 11:18:08 2010 : Debug: [ldap] object not found Wed Jul 14 11:18:08 2010 : Debug: [ldap] ldap_release_conn: Release Id: 0 Wed Jul 14 11:18:08 2010 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Wed Jul 14 11:18:08 2010 : Debug: [ldap] ldap_get_conn: Got Id: 0 Wed Jul 14 11:18:08 2010 : Debug: [ldap] performing search in CN=User Account,OU=IS,OU=Users,OU=Enterprise,DC=int,DC=example,DC=com, with filter (objectclass=*) Wed Jul 14 11:18:08 2010 : Debug: [ldap] performing search in CN=VPN_Users,OU=Security Groups,OU=Enterprise,DC=int,DC=example,DC=com, with filter (cn=VPN_Users) Wed Jul 14 11:18:08 2010 : Debug: rlm_ldap::ldap_groupcmp: User found in group VPN_Users Wed Jul 14 11:18:08 2010 : Debug: [ldap] ldap_release_conn: Release Id: 0 Wed Jul 14 11:18:08 2010 : Info: ? Evaluating (Ldap-Group == "VPN_Users") -> TRUE Wed Jul 14 11:18:08 2010 : Info: +++? if (Ldap-Group == "VPN_Users") -> TRUE Wed Jul 14 11:18:08 2010 : Info: +++- entering if (Ldap-Group == "VPN_Users") {...} Wed Jul 14 11:18:08 2010 : Info: ++++[ok] returns ok Wed Jul 14 11:18:08 2010 : Info: +++- if (Ldap-Group == "VPN_Users") returns ok Wed Jul 14 11:18:08 2010 : Info: +++ ... skipping else for request 7: Preceding "if" was taken Wed Jul 14 11:18:08 2010 : Info: ++- if (Huntgroup-Name == "VPN_Huntgroup") returns ok Wed Jul 14 11:18:08 2010 : Info: Found Auth-Type = MSCHAP Wed Jul 14 11:18:08 2010 : Info: +- entering group MS-CHAP {...} Wed Jul 14 11:18:08 2010 : Info: [mschap] Told to do MS-CHAPv2 for useraccount with NT-Password Wed Jul 14 11:18:08 2010 : Info: [mschap] expand: --username=%{mschap:User-Name} -> --username=useraccount Wed Jul 14 11:18:08 2010 : Info: [mschap] No NT-Domain was found in the User-Name. Wed Jul 14 11:18:08 2010 : Info: [mschap] expand: --domain=%{mschap:NT-Domain:-int.example.com} -> --domain= Wed Jul 14 11:18:08 2010 : Info: [mschap] mschap2: 36 Wed Jul 14 11:18:08 2010 : Info: [mschap] expand: --challenge=%{mschap:Challenge:-00} -> --challenge=5826d0d6b7d4ed8f Wed Jul 14 11:18:08 2010 : Info: [mschap] expand: --nt-response=%{mschap:NT-Response:-00} -> --nt-response=00be3e466ff82a106ee9e3144e442c6caa1bcb71636031b6 Wed Jul 14 11:18:08 2010 : Debug: Exec-Program output: NT_KEY: 580B07A2801E5E9B5CDD55BC23C38D1F Wed Jul 14 11:18:08 2010 : Debug: Exec-Program-Wait: plaintext: NT_KEY: 580B07A2801E5E9B5CDD55BC23C38D1F Wed Jul 14 11:18:08 2010 : Debug: Exec-Program: returned: 0 Wed Jul 14 11:18:08 2010 : Info: [mschap] adding MS-CHAPv2 MPPE keys Wed Jul 14 11:18:08 2010 : Info: ++[mschap] returns ok Wed Jul 14 11:18:08 2010 : Auth: Login OK: [useraccount] (from client VPN port 0) Wed Jul 14 11:18:08 2010 : Info: +- entering group post-auth {...} Wed Jul 14 11:18:08 2010 : Info: ++[exec] returns noop Wed Jul 14 11:18:08 2010 : Info: } # server server_vpn Sending Access-Accept of id 224 to 10.4.1.2 port 2452 Reply-Message := "Authorized Users Only" MS-CHAP2-Success = 0x01533d45453444463034303730304331303545384245463834323743454544353433303841303643454530 MS-MPPE-Recv-Key = 0x908aea21b6fbe22426feafd473d29657 MS-MPPE-Send-Key = 0xe2cddf5bd3f2aaa193fbce0410b840e8 MS-MPPE-Encryption-Policy = 0x00000001 MS-MPPE-Encryption-Types = 0x00000006 Wed Jul 14 11:18:08 2010 : Info: Finished request 7. Wed Jul 14 11:18:08 2010 : Debug: Going to the next request Wed Jul 14 11:18:08 2010 : Debug: Waking up in 4.9 seconds. Wed Jul 14 11:18:13 2010 : Info: Cleaning up request 7 ID 224 with timestamp +635 Wed Jul 14 11:18:13 2010 : Info: Ready to process requests. rad_recv: Access-Request packet from host 10.4.1.2 port 2452, id=225, length=124 User-Name = "useraccount" MS-CHAP-Challenge = 0x2693887b8edc90b7c766c9108f14d937 MS-CHAP2-Response = 0x0100af58b67bf00cc423c52b0a65b1f491000000000000000000d59dccc1f4e99c19be1ded3a3a771e49bfbb14ec62424311 NAS-IP-Address = 10.4.1.2 NAS-Port = 0 Wed Jul 14 11:18:38 2010 : Info: server server_vpn { Wed Jul 14 11:18:38 2010 : Info: +- entering group authorize {...} Wed Jul 14 11:18:38 2010 : Info: ++[preprocess] returns ok Wed Jul 14 11:18:38 2010 : Info: [mschap] Found MS-CHAP attributes. Setting 'Auth-Type = mschap' Wed Jul 14 11:18:38 2010 : Info: ++[mschap] returns ok Wed Jul 14 11:18:38 2010 : Debug: [ldap] Entering ldap_groupcmp() Wed Jul 14 11:18:38 2010 : Info: [files] expand: OU=Enterprise,DC=int,DC=example,DC=com -> OU=Enterprise,DC=int,DC=example,DC=com Wed Jul 14 11:18:38 2010 : Info: [files] expand: %{Stripped-User-Name} -> Wed Jul 14 11:18:38 2010 : Info: [files] ... expanding second conditional Wed Jul 14 11:18:38 2010 : Info: [files] expand: %{User-Name} -> useraccount Wed Jul 14 11:18:38 2010 : Info: [files] expand: (&(sAMAccountname=%{%{Stripped-User-Name}:-%{User-Name}})(objectClass=person)) -> (&(sAMAccountname=useraccount)(objectClass=person)) Wed Jul 14 11:18:38 2010 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Wed Jul 14 11:18:38 2010 : Debug: [ldap] ldap_get_conn: Got Id: 0 Wed Jul 14 11:18:38 2010 : Debug: [ldap] performing search in OU=Enterprise,DC=int,DC=example,DC=com, with filter (&(sAMAccountname=useraccount)(objectClass=person)) Wed Jul 14 11:18:38 2010 : Debug: [ldap] ldap_release_conn: Release Id: 0 Wed Jul 14 11:18:38 2010 : Info: [files] expand: (|(&(objectClass=GroupOfNames)(member=%{control:Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{control:Ldap-UserDn}))) -> (|(&(objectClass=GroupOfNames)(member=CN\3dUser Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dUser Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom))) Wed Jul 14 11:18:38 2010 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Wed Jul 14 11:18:38 2010 : Debug: [ldap] ldap_get_conn: Got Id: 0 Wed Jul 14 11:18:38 2010 : Debug: [ldap] performing search in OU=Enterprise,DC=int,DC=example,DC=com, with filter (&(cn=VPN_Users)(|(&(objectClass=GroupOfNames)(member=CN\3dUser Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dUser Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom)))) Wed Jul 14 11:18:38 2010 : Debug: [ldap] object not found Wed Jul 14 11:18:38 2010 : Debug: [ldap] ldap_release_conn: Release Id: 0 Wed Jul 14 11:18:38 2010 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Wed Jul 14 11:18:38 2010 : Debug: [ldap] ldap_get_conn: Got Id: 0 Wed Jul 14 11:18:38 2010 : Debug: [ldap] performing search in CN=User Account,OU=IS,OU=Users,OU=Enterprise,DC=int,DC=example,DC=com, with filter (objectclass=*) Wed Jul 14 11:18:38 2010 : Debug: [ldap] performing search in CN=VPN_Users,OU=Security Groups,OU=Enterprise,DC=int,DC=example,DC=com, with filter (cn=VPN_Users) Wed Jul 14 11:18:38 2010 : Debug: rlm_ldap::ldap_groupcmp: User found in group VPN_Users Wed Jul 14 11:18:38 2010 : Debug: [ldap] ldap_release_conn: Release Id: 0 Wed Jul 14 11:18:38 2010 : Info: [files] users: Matched entry DEFAULT at line 11 Wed Jul 14 11:18:38 2010 : Info: ++[files] returns ok Wed Jul 14 11:18:38 2010 : Info: [ldap] performing user authorization for useraccount Wed Jul 14 11:18:38 2010 : Info: [ldap] expand: %{Stripped-User-Name} -> Wed Jul 14 11:18:38 2010 : Info: [ldap] ... expanding second conditional Wed Jul 14 11:18:38 2010 : Info: [ldap] expand: %{User-Name} -> useraccount Wed Jul 14 11:18:38 2010 : Info: [ldap] expand: (&(sAMAccountname=%{%{Stripped-User-Name}:-%{User-Name}})(objectClass=person)) -> (&(sAMAccountname=useraccount)(objectClass=person)) Wed Jul 14 11:18:38 2010 : Info: [ldap] expand: OU=Enterprise,DC=int,DC=example,DC=com -> OU=Enterprise,DC=int,DC=example,DC=com Wed Jul 14 11:18:38 2010 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Wed Jul 14 11:18:38 2010 : Debug: [ldap] ldap_get_conn: Got Id: 0 Wed Jul 14 11:18:38 2010 : Debug: [ldap] performing search in OU=Enterprise,DC=int,DC=example,DC=com, with filter (&(sAMAccountname=useraccount)(objectClass=person)) Wed Jul 14 11:18:38 2010 : Info: [ldap] looking for check items in directory... Wed Jul 14 11:18:38 2010 : Info: [ldap] looking for reply items in directory... Wed Jul 14 11:18:38 2010 : Debug: WARNING: No "known good" password was found in LDAP. Are you sure that the user is configured correctly? Wed Jul 14 11:18:38 2010 : Info: [ldap] user useraccount authorized to use remote access Wed Jul 14 11:18:38 2010 : Debug: [ldap] ldap_release_conn: Release Id: 0 Wed Jul 14 11:18:38 2010 : Info: ++[ldap] returns ok Wed Jul 14 11:18:38 2010 : Info: ++? if (Huntgroup-Name == "VPN_Huntgroup") Wed Jul 14 11:18:38 2010 : Info: ? Evaluating (Huntgroup-Name == "VPN_Huntgroup") -> TRUE Wed Jul 14 11:18:38 2010 : Info: ++? if (Huntgroup-Name == "VPN_Huntgroup") -> TRUE Wed Jul 14 11:18:38 2010 : Info: ++- entering if (Huntgroup-Name == "VPN_Huntgroup") {...} Wed Jul 14 11:18:38 2010 : Info: +++? if (Ldap-Group == "VPN_Users") Wed Jul 14 11:18:38 2010 : Debug: [ldap] Entering ldap_groupcmp() Wed Jul 14 11:18:38 2010 : Info: expand: OU=Enterprise,DC=int,DC=example,DC=com -> OU=Enterprise,DC=int,DC=example,DC=com Wed Jul 14 11:18:38 2010 : Info: expand: (|(&(objectClass=GroupOfNames)(member=%{control:Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{control:Ldap-UserDn}))) -> (|(&(objectClass=GroupOfNames)(member=CN\3dUser Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dUser Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom))) Wed Jul 14 11:18:38 2010 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Wed Jul 14 11:18:38 2010 : Debug: [ldap] ldap_get_conn: Got Id: 0 Wed Jul 14 11:18:38 2010 : Debug: [ldap] performing search in OU=Enterprise,DC=int,DC=example,DC=com, with filter (&(cn=VPN_Users)(|(&(objectClass=GroupOfNames)(member=CN\3dUser Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dUser Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom)))) Wed Jul 14 11:18:38 2010 : Debug: [ldap] object not found Wed Jul 14 11:18:38 2010 : Debug: [ldap] ldap_release_conn: Release Id: 0 Wed Jul 14 11:18:38 2010 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Wed Jul 14 11:18:38 2010 : Debug: [ldap] ldap_get_conn: Got Id: 0 Wed Jul 14 11:18:38 2010 : Debug: [ldap] performing search in CN=User Account,OU=IS,OU=Users,OU=Enterprise,DC=int,DC=example,DC=com, with filter (objectclass=*) Wed Jul 14 11:18:38 2010 : Debug: [ldap] performing search in CN=VPN_Users,OU=Security Groups,OU=Enterprise,DC=int,DC=example,DC=com, with filter (cn=VPN_Users) Wed Jul 14 11:18:38 2010 : Debug: rlm_ldap::ldap_groupcmp: User found in group VPN_Users Wed Jul 14 11:18:38 2010 : Debug: [ldap] ldap_release_conn: Release Id: 0 Wed Jul 14 11:18:38 2010 : Info: ? Evaluating (Ldap-Group == "VPN_Users") -> TRUE Wed Jul 14 11:18:38 2010 : Info: +++? if (Ldap-Group == "VPN_Users") -> TRUE Wed Jul 14 11:18:38 2010 : Info: +++- entering if (Ldap-Group == "VPN_Users") {...} Wed Jul 14 11:18:38 2010 : Info: ++++[ok] returns ok Wed Jul 14 11:18:38 2010 : Info: +++- if (Ldap-Group == "VPN_Users") returns ok Wed Jul 14 11:18:38 2010 : Info: +++ ... skipping else for request 8: Preceding "if" was taken Wed Jul 14 11:18:38 2010 : Info: ++- if (Huntgroup-Name == "VPN_Huntgroup") returns ok Wed Jul 14 11:18:38 2010 : Info: Found Auth-Type = MSCHAP Wed Jul 14 11:18:38 2010 : Info: +- entering group MS-CHAP {...} Wed Jul 14 11:18:38 2010 : Info: [mschap] Told to do MS-CHAPv2 for useraccount with NT-Password Wed Jul 14 11:18:38 2010 : Info: [mschap] expand: --username=%{mschap:User-Name} -> --username=useraccount Wed Jul 14 11:18:38 2010 : Info: [mschap] No NT-Domain was found in the User-Name. Wed Jul 14 11:18:38 2010 : Info: [mschap] expand: --domain=%{mschap:NT-Domain:-int.example.com} -> --domain= Wed Jul 14 11:18:38 2010 : Info: [mschap] mschap2: 26 Wed Jul 14 11:18:38 2010 : Info: [mschap] expand: --challenge=%{mschap:Challenge:-00} -> --challenge=6349848fd05003ee Wed Jul 14 11:18:38 2010 : Info: [mschap] expand: --nt-response=%{mschap:NT-Response:-00} -> --nt-response=d59dccc1f4e99c19be1ded3a3a771e49bfbb14ec62424311 Wed Jul 14 11:18:38 2010 : Debug: Exec-Program output: NT_KEY: 580B07A2801E5E9B5CDD55BC23C38D1F Wed Jul 14 11:18:38 2010 : Debug: Exec-Program-Wait: plaintext: NT_KEY: 580B07A2801E5E9B5CDD55BC23C38D1F Wed Jul 14 11:18:38 2010 : Debug: Exec-Program: returned: 0 Wed Jul 14 11:18:38 2010 : Info: [mschap] adding MS-CHAPv2 MPPE keys Wed Jul 14 11:18:38 2010 : Info: ++[mschap] returns ok Wed Jul 14 11:18:38 2010 : Auth: Login OK: [useraccount] (from client VPN port 0) Wed Jul 14 11:18:38 2010 : Info: +- entering group post-auth {...} Wed Jul 14 11:18:38 2010 : Info: ++[exec] returns noop Wed Jul 14 11:18:38 2010 : Info: } # server server_vpn Sending Access-Accept of id 225 to 10.4.1.2 port 2452 Reply-Message := "Authorized Users Only" MS-CHAP2-Success = 0x01533d33333944463630393339414534313746383533333841434436324439374137343844413541313936 MS-MPPE-Recv-Key = 0xd81d386eb6bd95dcd85badccd21036b4 MS-MPPE-Send-Key = 0x1415b0a4e0f2d9063a9b0d0e92e2869b MS-MPPE-Encryption-Policy = 0x00000001 MS-MPPE-Encryption-Types = 0x00000006 Wed Jul 14 11:18:38 2010 : Info: Finished request 8. Wed Jul 14 11:18:38 2010 : Debug: Going to the next request Wed Jul 14 11:18:38 2010 : Debug: Waking up in 4.9 seconds. Wed Jul 14 11:18:43 2010 : Info: Cleaning up request 8 ID 225 with timestamp +665 Wed Jul 14 11:18:43 2010 : Info: Ready to process requests. Any ideas? Here are the complete details of our config: FreeRadius 2.1.8 Setup, configuration, troubleshooting instructions, on CentOS 5.x Goals: o Authentication telnet sessions for Cisco switches against AD for a specific security group (Infrastructure) o Authentication for VPN users using MSCHAP on a sonicwall firewall using a Windows VPN client with L2TP against AD for a specific security group (VPN_Users) Assumptions: SELinux is disabled Access is required on (the default of) 1812/udp and 1813/tcp Install The linux site for the rpm download of freeradius2 is: Create /etc/yum.repos.d/freeradius2.repo: [freeradius2] name=Freeradius2 baseurl=http://people.redhat.com/jdennis/freeradius-rhel-centos enabled=1 gpgcheck=0 Install freeradius2: yum clean all yum install freeradius2 freeradius2-utils freeradius2-ldap Enable FreeRadius to start on boot: chkconfig radiusd on To start the freeRadius service service radiusd start To run the service in debug mode (which you should be doing until everything works): service radiusd stop radiusd X Quirks If you get an error from the output of radiusd X along the lines of: Exec-Program output: winbind client not authorized to use winbindd_pam_auth_crap. Ensure permissions on /var/cache/samba/winbindd_privileged are set correctly. (0xc0000022) then the issue is that radiusd doesn't have access to the winbindd_privileged folder. You can fix with: chgrp radiusd /var/cache/samba/winbindd_privileged usermod -a -G wbpriv radiusd ### not this I don't think chmod g+rw /var/cache/samba/winbindd_privileged Configuration See Note that the configuring of SAMBA, kerberos, and adding to the domain should already be done as part of the default Linux install, see h:\is\operating system\Linux\Guide_linux.doc Verify that a user in the domain can be authenticated: wbinfo -a user%password Try the same login with the program, which is what FreeRADIUS will be using: ntlm_auth --request-nt-key --domain=MYDOMAIN --username=user --password=password /etc/raddb/radiusd.conf (see Appendix C) Update max_requests to # users * 256 Add to the end of the auth listen {..} (to permit groups of clients) clients = disambiguate Add to the end of the acct listen {..} (to permit groups of clients) clients = disambiguate In log{..} auth = yes (to log authentication requests) /etc/raddb/huntgroups huntgroups let you restrict which clients are associated with which user. You will need to add each IP of each device that will be using the RADIUS server, and associate it with the correct huntgroup. This will let the /etc/raddb/users file associate the user with the appropriate device: /etc/radbb/huntgroups: Cisco_Huntgroup NAS-IP-Address == 10.100.0.1 Cisco_Huntgroup NAS-IP-Address == 10.100.0.2 Cisco_Huntgroup NAS-IP-Address == 10.100.0.3 VPN_Huntgroup NAS-IP-Address == 10.4.1.2 /etc/raddb/modules/ntlm_auth Update the /modules/ntlm_auth module: (to enable ntlm_auth as an authentication method) exec ntlm_auth { wait = yes program = "/usr/bin/ntlm_auth ntlm_auth --request-nt-key --domain=example.com -username=%{mschap:User-Name} --password=%{User-Password}" } /etc/raddb/modules/ldap If this file is missing, you need to install the RPM for freeradius2-ldap. This section is one of the biggest pains to configure, as all of your LDAP strings need to be 100% correct, and they will be very specific to the environment. Of course, update server, identify, password, basedn for your own environment. You will need a user account in AD to permit the bind to LDAP. In this example, that account is in: CN=_useraccount,OU=Service Accounts,OU=Special User Accounts,OU=Enterprise,DC=example,DC=com In this example, the Security groups are located in (or below): OU=Enterprise,DC=example,DC=com ldap { server = "example.com" identity = "CN=_useraccount,OU=Service Accounts,OU=Special User Accounts,OU=Enterprise,DC=example,DC=com" password = secretpassword basedn = "OU=Enterprise,DC=example,DC=com" filter = (&(sAMAccountname=%{%{Stripped-User-Name}:-%{User-Name}})(objectClass=person)) groupmembership_attribute = "memberOf" ldap_connections_number = 5 timeout = 4 timelimit = 3 net_timeout = 1 tls { start_tls = no } dictionary_mapping = ${confdir}/ldap.attrmap edir_account_policy_check = no groupname_attribute = cn groupmembership_filter = "(|(&(objectClass=GroupOfNames)(member=%{control:Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{control:Ldap-UserDn})))" } Configuration of different virtual sites For this you'll have 3 general sites, default (used mostly for testing on 127.0.0.1), server_cisco (used to AAA the Cisco users), and server_vpn (used to AAA the VPN users). These live in /etc/raddb/sites-available/ inner-tunnel Add: ntlm_auth to the end of the authenticate{..} section default Add: ntlm_auth to the end of the authenticate{..} section server_cisco (see Appendix B) We're going to duplicate the default config, and modify it for that particular virtual server: cp /etc/raddb/sites-available/default /etc/raddb/sites-available/server_cisco Edit server_cisco and change it from server{..} to server server_cisco{..} Since we're not using any of these methods for the Ciscos, in authenticate{..} disable: chap, mschap, suffix, ntdomain, unix, pap Add to the end of the authenticate{..} section: ntlm_auth server_vpn (see Appendix A) cp /etc/raddb/sites-available/server_cisco /etc/raddb/sites-available/server_vpn Edit server_vpn and change it from server server_cisco {..} to server server_vpn {..} To get it to restrict who gets authorized based on the LDAP group, add to authorize {..}: if(Huntgroup-Name == "VPN_Huntgroup") { if(Ldap-Group == "VPN_Users") { ok } else { reject } } Link sites-enabled to sites-available: chown root:radiusd /etc/raddb/sites-available/server_cisco chown root:radiusd /etc/raddb/sites-available/server_vpn cd /etc/raddb/sites-enabled ln s ../sites-available/server_cisco server_cisco ln s ../sites-available/server_vpn server_vpn /etc/raddb/clients.conf This defines which individual clients connect to which virtual server, letting you differentiate the server config (including the secret) by client Note: The secret needs to match the secret set on the respective client. Change the secret to an actual secret clients disambiguate { client localhost { ipaddr = 127.0.0.1 secret = testing123 require_message_authenticator = no } client VPN { ipaddr = 10.4.1.2 secret = secret virtual_server = server_vpn } client Cisco { ipaddr = 10.100.0.0 netmask = 16 secret = secret virtual_server = server_cisco nastype = cisco }} /etc/raddb/users This file determines which AAA is done against which device and associates the defined huntgroups with the type of AAA #testuser Huntgroup-Name == Cisco_Huntgroup, Cleartext-Password:="testpass" # Service-Type:=NAS-Prompt-User,cisco-avpair:="shell:priv-lvl=15" DEFAULT Huntgroup-Name == Cisco_Huntgroup, Auth-Type:=ntlm_auth, Ldap-Group == "Infrastructure" Service-Type:=NAS-Prompt-User,cisco-avpair:="shell:priv-lvl=15" DEFAULT Huntgroup-Name == VPN_Huntgroup, Ldap-Group == "VPN_Users" /etc/raddb/modules/mschap mschap { ntlm_auth = "/usr/bin/ntlm_auth --request-nt-key --username=%{mschap:User-Name} --domain=%{mschap:NT-Domain:-example.com} --challenge=%{mschap:Challenge:-00} --nt-response=%{mschap:NT-Response:-00}" }

6 10

Re: Freeradius-Users Digest, Vol 63, Issue 29
by Chillifire 14 Jul '10

14 Jul '10

Hi Alan, Thank you for this response. I accept of course that garbage in garbage out, bad data is nothing the Radius can fix. However, I thought this through and when I make the following assumptions: - Freeradius has different SQL statements stored in its configuration for radacct update and insert; - It is Freeradius ' responsibility to decide whether to peform an insert or update; and - AcctSessionId and AcctUniqueId are unique identifiers for one session; there should be only exactly one record for each AcctSessionId and AcctUniqueId; Then there is still something amiss with the Freeradius updates of radacct. Even if erroneously session updates are sent in duplicate or with same or differing information, Freeradius should not insert a new record for an existing AcctSessionId and AcctUniqueId. Based on the above assumptions double entries for AcctSessionId and AcctUniqueId should never occur in radacct. Freeradius' insert/update logic should prevent that. However, multiple entries (anything between 2 and 17 in about 1% of all cases) is what we see in my extracts. Any thoughts? Hanno > > Hanno Schupp wrote: > > I am having trouble with my radacct table. Which creates some 80k entries > > per annum. For about 1% of users it contains doubled up entries (entries > > with same AcctSessionId and same AcctUniqueId) and also lots of entries > with > > the Username being empty (as opposed to either filled or Null). > > Blame the NAS. FreeRADIUS logs whatever the NAS sends. If the NAS > sends two packets that have *different* information for the same user > session... then the NAS is broken. > > > What could cause the doubled up radacct entries and what might cause the > > empty UserName radacct updates? > > The NAS is sending bad data. > > Alan DeKok. > > > >

2 1

expiration linked to both huntgroup and user
by Chris Tong 13 Jul '10

13 Jul '10

Hi, So here's my hurdle. I have multiple groups and use hunt-groups plus expiration time on the users for authentication. Assuming I have groups 1 & 2 how is it possible to link the expiration time to a group and the user and not just for the user. The expiration time is set on a per user level (not per group) which means a given user will either have access or not have access. A user can not have access to hunt-group 1 with an expiration in 10 days as well as an access expiring in 2 hours on hunt-group B. I only want to have one user over the whole domain so do not want to create multiple users and then append to the name on the incoming request and authenticate against multiple users who are in fact the same. Is there any other way round this problem? Many thanks, Chris

1 0

Freeradius+mysql+chillispot
by jorge88 13 Jul '10

13 Jul '10

Good morning, I have a serious problem, see if you can help. It just can not authenticate any user. The throwing error is: WARNING: Please update your configuration, and remove 'Auth-Type = Local' WARNING: Use the PAP or CHAP modules instead. User-Password in the request does NOT match "known good" password. Failed to authenticate the user. WARNING: unprintable characters in the password. Double-check the shared secret on the server and the NAS! Working with a database mysql + freeradius + chillispot. I show the output of freeradius-X Module: Linked to rlm_files module Module: instantiating files (files usersfile = "/ etc / freeradius / users" acctusersfile = "/ etc / freeradius / acct_users" preproxy_usersfile = "/ etc / freeradius / preproxy_users" compat = "no" ) Module: Checking session {...} for more modules to load Module: Linked to module rlm_radutmp Module: instantiating radutmp (radutmp filename = "/ var / log / freeradius / radutmp" username = "% (User-Name)" case_sensitive = yes check_with_nas = yes perm = 384 callerid = yes ) Module: Checking post-proxy {...} for more modules to load Module: Checking post-auth {...} for more modules to load Module: Linked to module rlm_attr_filter Module: instantiating attr_filter.access_reject (attr_filter.access_reject attr_filter attrsfile = "/ etc / freeradius / attrs.access_reject" key = "% (User-Name)" ) ) # Modules # Server) server ( (modules Module: Checking authenticate {...} for more modules to load Module: Checking Authorize {...} for more modules to load Module: Linked to module rlm_preprocess Module: instantiating Preprocess (Preprocess huntgroups = "/ etc / freeradius / huntgroups" hints = "/ etc / freeradius / hints" with_ascend_hack = no ascend_channels_per_line = 23 with_ntdomain_hack = no with_specialix_jetstream_hack = no with_cisco_vsa_hack = no with_alvarion_vsa_hack = no ) Module: Linked to module rlm_sql Module: sql instantiating (sql driver = "rlm_sql_mysql" server = "localhost" port = "" login = "radius" password = "radpass" radius_db = "radius" read_groups = yes sqltrace = no sqltracefile = "/ var / log / freeradius / sqltrace.sql" readclients = no deletestalesessions = yes num_sql_socks = 5 lifetime = 0 max_queries = 0 sql_user_name = "% (User-Name)" default_user_profile = "" nas_query = "SELECT id, nasname, shortname, type, secret FROM nas" authorize_check_query = "SELECT id, username, attribute, value, op FROM radcheck WHERE username = '% (SQL-User-Name)' ORDER BY id" authorize_reply_query = "SELECT id, username, attribute, value, op FROM radreply WHERE username = '% (SQL-User-Name)' ORDER BY id" authorize_group_check_query = "SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '% (Sql-Group)' ORDER BY id" authorize_group_reply_query = "SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '% (Sql-Group)' ORDER BY id" accounting_onoff_query = "UPDATE SET radacct acctstoptime = '% S', acctsessiontime = UNIX_TIMESTAMP ('% S') - UNIX_TIMESTAMP (acctstarttime) acctterminatecause = '% (Acct-Terminate-Cause)', acctstopdelay =% (% (Acct-Delay -Time): -0) WHERE IS NULL AND acctstoptime nasipaddress = '% (NAS-IP-Address)' AND acctstarttime <= '% S' " accounting_update_query = "UPDATE SET radacct framedipaddress = '% (Framed-IP-Address)', acctsessiontime = '% (Acct-Session-Time)', acctinputoctets ='%{%{ Acct-Input-Gigawords): -0) ' <<32 |'%{%{ Acct-Input-Octets): -0) ', acctoutputoctets ='%{%{ Acct-Output-Gigawords): -0)' <<32 | Acct-'%{%{ Output-Octets): -0) 'WHERE acctsessionid ='% (Acct-Session-Id) 'AND username = "% (SQL-User-Name)' AND nasipaddress = '% (NAS-IP-address)'" accounting_update_query_alt = "INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctsessiontime, acctauthentic, connectinfo_start, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, ServiceType, framedprotocol, framedipaddress, acctstartdelay, xascendsessionsvrkey) VALUES (' % (Acct-Session-Id) ','% (Acct-Unique-Session-Id) ','% (SQL-User-Name) ','% (Realm) ','% (NAS-IP-Address) ','% (NAS-Port) ','% (NAS-Port-Type) ', DATE_SUB ('% S ', INTERVAL (%{%{ Acct-Session-Time): -0) +% (% ( Acct-Delay-Time): -0)) SECOND), '% (Acct-Session-Time)', '% (Acct-Authentic)','','%{%{ Acct-Input-Gigawords): - 0) '<<32 |'%{%{ Acct-Input-Octets): -0)', Acct-Output-'%{%{ Gigawords): -0) '<<32 |'%{%{ Acct -Output-Octets): -0) ','% (Called-Station-Id) ','% (Calling-Station-Id) ','% (Service-Type) ','% (Framed-Protocol) ' , '% (Framed-IP-Address)', '0 ','% (X-Ascend-Session-Svr-Key) ') " accounting_start_query = "INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, ServiceType, framedprotocol, framedipaddress, acctstartdelay , acctstopdelay, xascendsessionsvrkey) VALUES ('% (Acct-Session-Id)', '% (Acct-Unique-Session-Id)', '% (SQL-User-Name)', '% (Realm)', ' % (the NAS-IP-Address) ', the NAS-Port% ()', (% Nas-Port-Type) ', "% S', NULL, '0 'for'% (Acct-Authentic) ', '% (Connect-Info) ",'', '0', '0 ','% (Called-Station-Id) ','% (Calling" Station-Id) ','','% (Service- Type) ','% (Framed-Protocol) ','% (Framed-IP-Address) ','%{%{ Acct-Delay-Time): -0)', '0 ','% (X- Ascend-Session-Svr-Key) ') " accounting_start_query_alt = "UPDATE SET radacct acctstarttime = '% S', acctstartdelay ='%{%{ Acct-Delay-Time): -0) ', connectinfo_start ='% (Connect-Info) 'WHERE acctsessionid ='% (Acct- Session-Id) 'AND username ='% (SQL-User-Name) 'AND nasipaddress ='% (NAS-IP-Address) '" accounting_stop_query = "UPDATE SET radacct acctstoptime = '% S', acctsessiontime = '% (Acct-Session-Time)', acctinputoctets ='%{%{ Acct-Input-Gigawords): -0) '<<32 |'% (% (Acct-Input-Octets): -0) ', acctoutputoctets ='%{%{ Acct-Output-Gigawords): -0)' <<32 |'%{%{ Acct-Output-Octets): - 0) ', acctterminatecause ='% (Acct-Terminate-Cause) ', acctstopdelay ='%{%{ Acct-Delay-Time): -0)', connectinfo_stop = '% (Connect-Info)' WHERE acctsessionid = ' % (Acct-Session-Id) 'AND username ='% (SQL-User-Name) 'AND nasipaddress ='% (NAS-IP-Address) '" accounting_stop_query_alt = "INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, ServiceType, framedprotocol, framedipaddress, acctstartdelay , acctstopdelay) VALUES ('% (Acct-Session-Id)', '% (Acct-Unique-Session-Id)', '% (SQL-User-Name)', '% (Realm)', '% ( NAS-IP-Address) ','% (NAS-Port) ','% (NAS-Port-Type) ', DATE_SUB ('% S ', INTERVAL (%{%{ Acct-Session-Time): -0 (%) +% (Acct-Delay-Time): -0)) SECOND), '% S', '% (Acct-Session-Time)', '% (Acct-Authentic)','', '% (Connect-Info) ','%{%{ Acct-Input-Gigawords): -0)' <<32 |'%{%{ Acct-Input-Octets): -0) ', Acct'%{%{ -Output-Gigawords): -0) '<<32 |'%{%{ Acct-Output-Octets): -0)', '% (Called-Station-Id)', '% (Calling-Station-Id ) ','% (Acct-Terminate-Cause) ','% (Service-Type) ','% (Framed-Protocol) ','% (Framed-IP-Address) ', '0', '% ( % (Acct-Delay-Time): -0) ') " group_membership_query = "SELECT groupname FROM radusergroup WHERE username = '% (SQL-User-Name)' ORDER BY priority" connect_failure_retry_delay = 60 simul_count_query = "" simul_verify_query = "SELECT radacctid, acctsessionid, username, nasipaddress, nasportid, framedipaddress, callingstationid, framedprotocol radacct FROM WHERE username = '% (SQL-User-Name)' AND acctstoptime IS NULL" postauth_query = "INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ('% (User-Name)', User-Password'%{%{ }:-%{ Chap-Password)) ','% (reply :) Packet-Type ','% S ') " safe-characters = "@ abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" ) rlm_sql (sql): Driver rlm_sql_mysql (rlm_sql_mysql module) loaded and linked rlm_sql (sql): Attempting to connect to radius @ localhost: / radius rlm_sql (sql): starting 0 rlm_sql (sql): Attempting to connect rlm_sql_mysql # 0 rlm_sql_mysql: Starting connect to MySQL server for # 0 rlm_sql (sql): Connected new DB handle, # 0 rlm_sql (sql): starting 1 rlm_sql (sql): Attempting to connect rlm_sql_mysql # 1 rlm_sql_mysql: Starting connect to MySQL server for # 1 rlm_sql (sql): Connected new DB handle, # 1 rlm_sql (sql): starting 2 rlm_sql (sql): Attempting to connect rlm_sql_mysql # 2 rlm_sql_mysql: Starting connect to MySQL server for # 2 rlm_sql (sql): Connected new DB handle, # 2 rlm_sql (sql): starting 3 rlm_sql (sql): Attempting to connect rlm_sql_mysql # 3 rlm_sql_mysql: Starting connect to MySQL server for # 3 rlm_sql (sql): Connected new DB handle, # 3 rlm_sql (sql): starting 4 rlm_sql (sql): Attempting to connect rlm_sql_mysql # 4 rlm_sql_mysql: Starting connect to MySQL server for # 4 rlm_sql (sql): Connected new DB handle, # 4 Module: Checking preacct {...} for more modules to load Module: Linked to module rlm_acct_unique Module: instantiating acct_unique (acct_unique key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port" ) Module: Checking accounting {...} for more modules to load Module: Linked to module rlm_detail Module: instantiating detail (detail detailfile = "/ var / log / freeradius / radacct /% (Client-IP-Address) / detail-% Y% m% d" header = "% t" detailperm = 384 dirperm = 493 locking = no log_packet_header = no ) Module: instantiating attr_filter.accounting_response (attr_filter.accounting_response attr_filter attrsfile = "/ etc / freeradius / attrs.accounting_response" key = "% (User-Name)" ) Module: Checking session {...} for more modules to load Module: Checking post-proxy {...} for more modules file to load Module: Checking post-auth {...} for more modules to load ) # Modules # Server) radiusd: # # # # Opening IP addresses and Ports # # # # list ( type = "auth" ipaddr = * port = 0 ) listen ( type = "acct" ipaddr = * port = 0 ) Listening on authentication address * port 1812 Listening on accounting address * port 1813 Listening on proxy address * port 1814 Ready to process requests. rad_recv: Access-Request packet from host 81.39.156.140 port 56 066, id = 0, length = 193 User-Name = "george" User-Password = "L] \ 357DK \ 027 \ 304 \ 033 \ 376Hx. \ 342Ö \ 336" NAS-IP-Address = 0.0.0.0 Service-Type = Login-User Framed-IP-Address = 172.30.0.2 Calling-Station-Id = "00-26-B6-21-00-B6" Called-Station-Id = "00-15-6D-EA-2A-64" NAS-Identifier = "nas01" Acct-Session-Id = "4a22752700000000" NAS-Port-Type = Wireless-802.11 NAS-Port = 0 Message-Authenticator = 0xcb69aaaeb72f21b84a10ffcda684fc8d WISPr-Logoff-URL = "http://172.30.0.1:3990/logoff" + - Authorize Entering group {...} + + [Preprocess] returns ok + + [Chap] returns noop + + [MSCHAP] returns noop [Suffix] No '@' in User-Name = "george", looking up realm NULL [Suffix] No such realm "NULL" + + [Suffix] returns noop [Eap] No EAP-Message, Not doing EAP + + [Eap] returns noop + + [Unix] returns notfound [Sql] expand:% (User-Name) -> jorge [Sql] sql_set_user escaped user -> 'jorge' rlm_sql (sql): Reserving sql socket id: 4 [Sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '% (SQL-User-Name)' ORDER BY id -> SELECT id, username, attribute, value, op FROM WHERE username = radcheck 'jorge' ORDER BY id [Sql] User radcheck found in table [Sql] expand: SELECT id, username, attribute, value, op FROM radreply WHERE username = '% (SQL-User-Name)' ORDER BY id -> SELECT id, username, attribute, value, op FROM WHERE username = radreply 'jorge' ORDER BY id [Sql] expand: SELECT groupname FROM radusergroup WHERE username = '% (SQL-User-Name)' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = 'jorge' ORDER BY priority rlm_sql (sql): Released sql socket id: 4 + + [Sql] returns ok + + [Expiration] returns noop + + [Logintime] returns noop WARNING: Please update your configuration, and remove 'Auth-Type = Local' WARNING: Use the PAP or CHAP modules instead. User-Password in the request does NOT match "known good" password. Failed to authenticate the user. WARNING: unprintable characters in the password. Double-check the shared secret on the server and the NAS! Using Post-Auth-Type Reject + - Entering group REJECT {...} [Attr_filter.access_reject] expand:% (User-Name) -> jorge attr_filter: Matched entry DEFAULT at line 11 + + [Attr_filter.access_reject] returns updated Delaying reject of request 0 for 1 seconds Going to the next request Waking up in 0.9 seconds. Sending delayed reject for request 0 Sending Access-Reject of id 0 to 81.39.156.140 port 56 066 Waking up in 4.9 seconds. Cleaning up request 0 ID 0 with timestamp +10 Ready to process requests. When I try to authenticate displays the following output: rad_recv: Access-Request packet from host 81.39.156.140 port 56 607, id = 0, length = 193 User-Name = "steve" User-Password = "\ 227 \ 260 \ 342 \ 242R $, \ 274 \ 204 \ 270 \ 265 \ 035 <\ 217X \ 313" NAS-IP-Address = 0.0.0.0 Service-Type = Login-User Framed-IP-Address = 172.30.0.2 Calling-Station-Id = "00-26-B6-21-00-B6" Called-Station-Id = "00-15-6D-EA-2A-64" NAS-Identifier = "nas01" Acct-Session-Id = "4a22752700000000" NAS-Port-Type = Wireless-802.11 NAS-Port = 0 Message-Authenticator = 0x5024856015aed1488bc5a5ab81f96a7e WISPr-Logoff-URL = "http://172.30.0.1:3990/logoff" + - Authorize Entering group {...} & + [Preprocess] returns ok + + [Chap] returns noop & + [MSCHAP] returns noop [Suffix] No '@' in User-Name = "steve", looking up realm NULL [Suffix] No such realm "NULL" + + [Suffix] returns noop [Eap] No EAP-Message, Not doing EAP + + [Eap] returns noop + + [Unix] returns notfound [Sql] expand:% (User-Name) -> steve [Sql] sql_set_user escaped user -> 'steve' rlm_sql (sql): Reserving sql socket id: 3 [Sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '% (SQL-User-Name)' ORDER BY id -> SELECT id, username, attribute, value, op FROM WHERE username = radcheck 'steve' ORDER BY id [Sql] expand: SELECT groupname FROM radusergroup WHERE username = '% (SQL-User-Name)' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = 'steve' ORDER BY priority rlm_sql (sql): Released sql socket id: 3 [Sql] User not found steve + + [Sql] returns notfound + + [Expiration] returns noop + + [Logintime] returns noop No authenticate method (Auth-Type) configuration found for the request: Rejecting the user Failed to authenticate the user. WARNING: unprintable characters in the password. Double-check the shared secret on the server and the NAS! Using Post-Auth-Type Reject + - Entering group REJECT {...} [Attr_filter.access_reject] expand:% (User-Name) - steve attr_filter: Matched entry DEFAULT at line 11 & & [Attr_filter.access_reject] returns updated Delaying reject of request 1 for 1 seconds Going to the next request Waking up in 0.9 seconds. Sending delayed reject for request 1 Sending Access-Reject of id 0 to 81.39.156.140 port 56 607 Waking up in 4.9 seconds. Cleaning up request 1 ID 0 with timestamp +515 Ready to process requests. Thank you very much ;) -- View this message in context: http://old.nabble.com/Freeradius%2Bmysql%2Bchillispot-tp29149021p29149021.h… Sent from the FreeRadius - User mailing list archive at Nabble.com.

5 4

freeRadius Disconnect-Message
by jean466＠sympatico.ca 13 Jul '10

13 Jul '10

Hi, Quote from another post: "2.1.9 supports disconnect. It's for disconnecting users. Alan DeKok." and another one: "The Freeradius server will not do this for you You have to write maybe 10 lines of configuration to get this done. Alan DeKok." Here are my questions: 1 - Is freeRadius server able to send a disconnect-request? 2 - If so, where can I get information on how to do this? 3 - Do we still have to use radclient to send the message? Thank you. Jean

3 2

Help
by Jawad Khawaja 13 Jul '10

13 Jul '10

Hi, I am using CentOS with Radius 1.1.3..... it automatically stops working..... and i do restart its services to restore its original state.. As if we do restart system's services 2 or three times, system starts working.... it has a very strange to us... what should i share to trouble shoot. Any suggestion will be appreciated. ... Regards James

4 3

Novell E-Directory
by John McDonnell 13 Jul '10

13 Jul '10

I've noticed in all the old documentation that it says to configure FreeRADIUS with --with-edir to enable support for Novell. All of the documentation for this that I've found is generally old and referencing FR v1.x and not 2.x. On FreeBSD, in the ports system, the with-edir toggle has been removed from the config options when building FR v2.x though it is still something available in the older FR v1.x. My question is, do I need to do anything special when building FR v2.x to get support for the couple of e-directory options (edir_account_policy_check come to mind) or if this just works out of the box. If I do still need to configure --with-edir when compiling, does anyone happen to know the syntax for FreeBSD to include it since it is no longer a toggle option. (If it is required, I'll drop an e-mail on the maintainer to see if it can be added again to make things simpler in the future.) Thanks. :) -- John McDonnell Penn Cambria School District mcdonnjd(a)pcam.org O< ASCII Ribbon Campaign - www.asciiribbon.org

2 1

Is there a definitive config guide for installing 1.1.7 on Solaris 10
by Avery, Larry EIS-ERDC-ITL-MS Contractor 13 Jul '10

13 Jul '10

I'm running a Solaris 10 U6 (10/08) whole-root zone where I'm trying to install freeRadius 1.1.7 from packages (Sunfreeware). I've loaded what is listed (on Sunfreeware) as dependencies (and dependencies of those packages), but I still get a segmentation fault on startup. No changes have been made to any of the radius config files. Is there a complete list of packages required for freeRADIUS on my version of Solaris 10? The attempted startup of radius, with the "-X" option is shown below: # ./S99rad* start -n Starting FreeRADIUS: Starting - reading configuration files ... reread_config: reading radiusd.conf Config: including file: /usr/local/etc/raddb/proxy.conf Config: including file: /usr/local/etc/raddb/clients.conf Config: including file: /usr/local/etc/raddb/snmp.conf Config: including file: /usr/local/etc/raddb/eap.conf Config: including file: /usr/local/etc/raddb/sql.conf main: prefix = "/usr/local" main: localstatedir = "/usr/local/var" main: logdir = "/usr/local/var/log/radius" main: libdir = "/usr/local/lib" main: radacctdir = "/usr/local/var/log/radius/radacct" main: hostname_lookups = no main: snmp = no main: max_request_time = 30 main: cleanup_delay = 5 main: max_requests = 1024 main: delete_blocked_requests = 0 main: port = 0 main: allow_core_dumps = no main: log_stripped_names = no main: log_file = "/usr/local/var/log/radius/radius.log" main: log_auth = no main: log_auth_badpass = no main: log_auth_goodpass = no main: pidfile = "/usr/local/var/run/radiusd/radiusd.pid" main: user = "(null)" main: group = "(null)" main: usercollide = no main: lower_user = "no" main: lower_pass = "no" main: nospace_user = "no" main: nospace_pass = "no" main: checkrad = "/usr/local/sbin/checkrad" main: proxy_requests = yes proxy: retry_delay = 5 proxy: retry_count = 3 proxy: synchronous = no proxy: default_fallback = yes proxy: dead_time = 120 proxy: post_proxy_authorize = no proxy: wake_all_if_all_dead = no security: max_attributes = 200 security: reject_delay = 1 security: status_server = no main: debug_level = 0 read_config_files: reading dictionary read_config_files: reading naslist Using deprecated naslist file. Support for this will go away soon. read_config_files: reading clients read_config_files: reading realms radiusd: entering modules setup Segmentation Fault - core dumped radiusd # I've seen queries from others with the same problem, but I can't find a resolution. Thanks for the help, Larry Avery

3 2

Log Client-NAS-IP insetad of shortname
by Matthias Cramer 13 Jul '10

13 Jul '10

Hi I have a bunch of Routers authentication agoinst a freeradius instance. All using the same secret, therefore I configured them as follows in the clients.conf client dynamicdsl { secret = XXXXXX shortname = dynamicdsl nastype = cisco ipaddr = xxx.xxx.xxx.0 netmask = 20 } Now it would be nice if it would be possible to log the NAS IP instead of the shortname in radius.log Is that possible. Would someone be willing to add such an option if not allready implemented ? Regards Matthias -- Matthias Cramer / mc322-ripe Senior Network & Security Engineer iway AG Phone +41 43 500 1111 Josefstrasse 225 Fax +41 44 271 3535 CH-8005 Zürich http://www.iway.ch/ GnuPG 1024D/2D208250 = DBC6 65B6 7083 1029 781E 3959 B62F DF1C 2D20 8250

1 0

David Suarez De Lis/UN24956/OPERACION Y MANTENIMIENTO/TSM está ausente de la oficina.
by david.suarezdelis＠telefonica.es 12 Jul '10

12 Jul '10

Estaré ausente de la oficina desde el 12/07/2010 y no volveré hasta el 28/07/2010. Responderé a su mensaje cuando regrese. Si tiene alguna emergencia, puede contactar con Accesos_SOR@telefonica (900 111 245 opción 3, 2)o Jose Manuel Gomez Perez (jmgomez(a)telefonica.es) ___________________________________________________________________________ Este mensaje se dirige exclusivamente a su destinatario y puede contener información privilegiada o confidencial. Si no es vd. el destinatario indicado, queda notificado de que la lectura, utilización, divulgación y/o copia sin autorización está prohibida en virtud de la legislación vigente. Si ha recibido este mensaje por error, le rogamos que nos lo comunique inmediatamente por esta misma vía y proceda a su destrucción. El correo electrónico vía Internet no permite asegurar la confidencialidad de los mensajes que se transmiten ni su integridad o correcta recepción. Telefónica no asume ninguna responsabilidad por estas circunstancias. This message is intended exclusively for its addressee and may contain information that is CONFIDENTIAL and protected by a professional privilege or whose disclosure is prohibited by law.If you are not the intended recipient you are hereby notified that any read, dissemination, copy or disclosure of this communication is strictly prohibited by law. If this message has been received in error, please immediately notify us via e-mail and delete it. Internet e-mail neither guarantees the confidentiality nor the integrity or proper receipt of the messages sent. Telefónica does not assume any liability for those circumstances. ___________________________________________________________________________

1 0