Freeradius2 and Samba3x

freeradius at corwyn.net freeradius at corwyn.net
Wed Jul 14 19:56:57 CEST 2010


At 11:46 AM 7/14/2010, you wrote:
>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


Why use it as a proxy then? Why not just use NPS?

RIck



>-----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
>
>-
>List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html






More information about the Freeradius-Users mailing list