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 =
0x0100f3dd5207d539bd0d7e1f7be50178d3820000000000000000a3492c6411f5548251a
05606aa028964d34b69c58e61c7d5
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=per
son)) -> (&(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}))(&(objectCl
ass=GroupOfUniqueNames)(uniquemember=%{control:Ldap-UserDn}))) ->
(|(&(objectClass=GroupOfNames)(member=CN\3dUser
Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexampl
e\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dUser
Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexampl
e\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\3dexampl
e\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dUser
Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexampl
e\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=per
son)) -> (&(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}))(&(objectCl
ass=GroupOfUniqueNames)(uniquemember=%{control:Ldap-UserDn}))) ->
(|(&(objectClass=GroupOfNames)(member=CN\3dUser
Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexampl
e\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dUser
Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexampl
e\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\3dexampl
e\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dUser
Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexampl
e\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 =
0x01000bd21f7a41e97a616ca8dd0634f4e5230000000000000000d4c66c9dd3cabae77ed
fe564c745de287968a0441d0df3a5
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=per
son)) -> (&(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}))(&(objectCl
ass=GroupOfUniqueNames)(uniquemember=%{control:Ldap-UserDn}))) ->
(|(&(objectClass=GroupOfNames)(member=CN\3dUser
Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexampl
e\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dUser
Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexampl
e\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\3dexampl
e\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dUser
Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexampl
e\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=per
son)) -> (&(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}))(&(objectCl
ass=GroupOfUniqueNames)(uniquemember=%{control:Ldap-UserDn}))) ->
(|(&(objectClass=GroupOfNames)(member=CN\3dUser
Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexampl
e\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dUser
Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexampl
e\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\3dexampl
e\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dUser
Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexampl
e\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 =
0x01000c60a44ccac150a8d8961f218cfd07b5000000000000000000be3e466ff82a106ee
9e3144e442c6caa1bcb71636031b6
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=per
son)) -> (&(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}))(&(objectCl
ass=GroupOfUniqueNames)(uniquemember=%{control:Ldap-UserDn}))) ->
(|(&(objectClass=GroupOfNames)(member=CN\3dUser
Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexampl
e\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dUser
Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexampl
e\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\3dexampl
e\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dUser
Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexampl
e\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=per
son)) -> (&(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}))(&(objectCl
ass=GroupOfUniqueNames)(uniquemember=%{control:Ldap-UserDn}))) ->
(|(&(objectClass=GroupOfNames)(member=CN\3dUser
Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexampl
e\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dUser
Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexampl
e\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\3dexampl
e\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dUser
Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexampl
e\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 =
0x01533d45453444463034303730304331303545384245463834323743454544353433303
841303643454530
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 =
0x0100af58b67bf00cc423c52b0a65b1f491000000000000000000d59dccc1f4e99c19be1
ded3a3a771e49bfbb14ec62424311
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=per
son)) -> (&(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}))(&(objectCl
ass=GroupOfUniqueNames)(uniquemember=%{control:Ldap-UserDn}))) ->
(|(&(objectClass=GroupOfNames)(member=CN\3dUser
Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexampl
e\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dUser
Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexampl
e\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\3dexampl
e\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dUser
Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexampl
e\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=per
son)) -> (&(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}))(&(objectCl
ass=GroupOfUniqueNames)(uniquemember=%{control:Ldap-UserDn}))) ->
(|(&(objectClass=GroupOfNames)(member=CN\3dUser
Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexampl
e\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dUser
Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexampl
e\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\3dexampl
e\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dUser
Account\2cOU\3dIS\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexampl
e\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 =
0x01533d33333944463630393339414534313746383533333841434436324439374137343
844413541313936
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=per
son)) 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}))(&(objectC
lass=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}"
}
-
List info/subscribe/unsubscribe? See
http://www.freeradius.org/list/users.html
