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