Freeradius2 and Samba3x
Lovaas,Steven
Steven.Lovaas at ColoState.EDU
Wed Jul 14 17:46:18 CEST 2010
Rather than deal with the never-ending tail-chasing between samba and Microsoft, I've decided to move toward using FreeRadius as a proxy for the Windows radius implementation (formerly IAS, now called NPS). I haven't completed the change, so I'm sorry that I can't tell you how easy it is... but it surely can't be as frustrating as trying to deal with samba always being behind, right?
Steve Lovaas
-----Original Message-----
From: freeradius-users-bounces+steven.lovaas=colostate.edu at lists.freeradius.org [mailto:freeradius-users-bounces+steven.lovaas=colostate.edu at lists.freeradius.org] On Behalf Of freeradius at corwyn.net
Sent: Wednesday, July 14, 2010 9:23 AM
To: FreeRadius users mailing list
Subject: Freeradius2 and Samba3x
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}"
}
-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
More information about the Freeradius-Users
mailing list