At 08:33 PM 1/14/2010, freerad...@corwyn.net wrote:
The Windows environment works, with one quirk, if no one has logged
in for a while (~15-30 min), the next user gets:
Here's the full log of one of those events (redacted): Two
interesting points are noted with "***". The reconnect takes only
moments when watching it flow by.
rad_recv: Access-Request packet from host 10.4.1.2 port 4734, id=116,
length=121
User-Name = "testuser"
MS-CHAP-Challenge = 0xe23b19133fb8d89eeaddcea89d9917ee
MS-CHAP2-Response =
0x01008875de342e3a72b85b591ede3516972e00000000000000008709a70df8e4f28d3f5d880e9558e580d723bc5d98c4a717
NAS-IP-Address = 10.4.1.2
NAS-Port = 0
server server_vpn {
+- entering group authorize {...}
++[preprocess] returns ok
[mschap] Found MS-CHAP attributes. Setting 'Auth-Type = mschap'
++[mschap] returns ok
rlm_ldap: Entering ldap_groupcmp()
[files] expand: OU=Enterprise,DC=int,DC=example,DC=com ->
OU=Enterprise,DC=int,DC=example,DC=com
[files] WARNING: Deprecated conditional expansion ":-". See "man
unlang" for details
[files] expand:
(&(sAMAccountname=%{Stripped-User-Name:-%{User-Name}})(objectClass=person))
-> (&(sAMAccountname=testuser)(objectClass=person))
rlm_ldap: ldap_get_conn: Checking Id: 0
rlm_ldap: ldap_get_conn: Got Id: 0
rlm_ldap: performing search in
OU=Enterprise,DC=int,DC=example,DC=com, with filter
(&(sAMAccountname=testuser)(objectClass=person))
****
****
rlm_ldap: ldap_search() failed: LDAP connection lost.
rlm_ldap: Attempting reconnect
rlm_ldap: attempting LDAP reconnection
rlm_ldap: closing existing LDAP connection
rlm_ldap: (re)connect to int.example.com:389, authentication 0
****
****
rlm_ldap: bind as CN=Admin_account,OU=Service Accounts,OU=Special
User
Accounts,OU=Enterprise,DC=int,DC=example,DC=com/wvyjCHCd2LJHcNrmpr0I
to int.example.com:389
rlm_ldap: waiting for bind result ...
rlm_ldap: Bind was successful
rlm_ldap: performing search in
OU=Enterprise,DC=int,DC=example,DC=com, with filter
(&(sAMAccountname=testuser)(objectClass=person))
rlm_ldap: ldap_release_conn: Release Id: 0
[files] expand:
(|(&(objectClass=GroupOfNames)(member=%{control:Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{control:Ldap-UserDn})))
-> (|(&(objectClass=GroupOfNames)(member=CN\3dJoe
Bob\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dJoe
Bob\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom)))
rlm_ldap: ldap_get_conn: Checking Id: 0
rlm_ldap: ldap_get_conn: Got Id: 0
rlm_ldap: performing search in
OU=Enterprise,DC=int,DC=example,DC=com, with filter
(&(cn=VPN_Users)(|(&(objectClass=GroupOfNames)(member=CN\3dJoe
Bob\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dJoe
Bob\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom))))
rlm_ldap: object not found
rlm_ldap: ldap_release_conn: Release Id: 0
rlm_ldap: ldap_get_conn: Checking Id: 0
rlm_ldap: ldap_get_conn: Got Id: 0
rlm_ldap: performing search in CN=Joe
Bob,OU=Users,OU=Enterprise,DC=int,DC=example,DC=com, with filter
(objectclass=*)
rlm_ldap: performing search in CN=VPN_Users,OU=Security
Groups,OU=Enterprise,DC=int,DC=example,DC=com, with filter (cn=VPN_Users)
rlm_ldap::ldap_groupcmp: User found in group VPN_Users
rlm_ldap: ldap_release_conn: Release Id: 0
[files] users: Matched entry DEFAULT at line 11
++[files] returns ok
[ldap] performing user authorization for testuser
[ldap] WARNING: Deprecated conditional expansion ":-". See "man
unlang" for details
[ldap] expand:
(&(sAMAccountname=%{Stripped-User-Name:-%{User-Name}})(objectClass=person))
-> (&(sAMAccountname=testuser)(objectClass=person))
[ldap] expand: OU=Enterprise,DC=int,DC=example,DC=com ->
OU=Enterprise,DC=int,DC=example,DC=com
rlm_ldap: ldap_get_conn: Checking Id: 0
rlm_ldap: ldap_get_conn: Got Id: 0
rlm_ldap: performing search in
OU=Enterprise,DC=int,DC=example,DC=com, with filter
(&(sAMAccountname=testuser)(objectClass=person))
[ldap] looking for check items in directory...
[ldap] looking for reply items in directory...
*****
*****
WARNING: No "known good" password was found in LDAP. Are you sure
that the user is configured correctly?
[ldap] user testuser authorized to use remote access
rlm_ldap: ldap_release_conn: Release Id: 0
++[ldap] returns ok
*** also odd.
++? if (Huntgroup-Name == "VPN_Huntgroup")
? Evaluating (Huntgroup-Name == "VPN_Huntgroup") -> TRUE
++? if (Huntgroup-Name == "VPN_Huntgroup") -> TRUE
++- entering if (Huntgroup-Name == "VPN_Huntgroup") {...}
+++? if (Ldap-Group == "VPN_Users")
rlm_ldap: Entering ldap_groupcmp()
expand: OU=Enterprise,DC=int,DC=example,DC=com ->
OU=Enterprise,DC=int,DC=example,DC=com
expand:
(|(&(objectClass=GroupOfNames)(member=%{control:Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{control:Ldap-UserDn})))
-> (|(&(objectClass=GroupOfNames)(member=CN\3dJoe
Bob\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dJoe
Bob\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom)))
rlm_ldap: ldap_get_conn: Checking Id: 0
rlm_ldap: ldap_get_conn: Got Id: 0
rlm_ldap: performing search in
OU=Enterprise,DC=int,DC=example,DC=com, with filter
(&(cn=VPN_Users)(|(&(objectClass=GroupOfNames)(member=CN\3dJoe
Bob\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom))(&(objectClass=GroupOfUniqueNames)(uniquemember=CN\3dJoe
Bob\2cOU\3dUsers\2cOU\3dEnterprise\2cDC\3dint\2cDC\3dexample\2cDC\3dcom))))
rlm_ldap: object not found
rlm_ldap: ldap_release_conn: Release Id: 0
rlm_ldap: ldap_get_conn: Checking Id: 0
rlm_ldap: ldap_get_conn: Got Id: 0
rlm_ldap: performing search in CN=Joe
Bob,OU=Users,OU=Enterprise,DC=int,DC=example,DC=com, with filter
(objectclass=*)
rlm_ldap: performing search in CN=VPN_Users,OU=Security
Groups,OU=Enterprise,DC=int,DC=example,DC=com, with filter (cn=VPN_Users)
rlm_ldap::ldap_groupcmp: User found in group VPN_Users
rlm_ldap: ldap_release_conn: Release Id: 0
? Evaluating (Ldap-Group == "VPN_Users") -> TRUE
+++? if (Ldap-Group == "VPN_Users") -> TRUE
+++- entering if (Ldap-Group == "VPN_Users") {...}
++++[ok] returns ok
+++- if (Ldap-Group == "VPN_Users") returns ok
+++ ... skipping else for request 6: Preceding "if" was taken
++- if (Huntgroup-Name == "VPN_Huntgroup") returns ok
Found Auth-Type = MSCHAP
+- entering group MS-CHAP {...}
[mschap] Told to do MS-CHAPv2 for testuser with NT-Password
[mschap] expand: --username=%{mschap:User-Name} -> --username=testuser
[mschap] No NT-Domain was found in the User-Name.
[mschap] expand: --domain=%{mschap:NT-Domain:-int.example.com}
-> --domain=int.example.com
[mschap] mschap2: e2
[mschap] expand: --challenge=%{mschap:Challenge:-00} ->
--challenge=b80b4d4cbe4d692c
[mschap] expand: --nt-response=%{mschap:NT-Response:-00} ->
--nt-response=8709a70df8e4f28d3f5d880e9558e580d723bc5d98c4a717
Exec-Program output: NT_KEY: ABB81B23774917AE41C16F92C19D6965
Exec-Program-Wait: plaintext: NT_KEY: ABB81B23774917AE41C16F92C19D6965
Exec-Program: returned: 0
[mschap] adding MS-CHAPv2 MPPE keys
++[mschap] returns ok
Login OK: [testuser] (from client VPN port 0)
+- entering group post-auth {...}
++[exec] returns noop
} # server server_vpn
Sending Access-Accept of id 116 to 10.4.1.2 port 4734
Reply-Message := "Authorized Users Only"
MS-CHAP2-Success =
0x01533d39363842343441374535383843394336413942443632343933444336304343444145313645394238
MS-MPPE-Recv-Key = 0x05ea5717340f74f2af887bf51c3712c6
MS-MPPE-Send-Key = 0x4443176296e087b447a514a7db4b6255
MS-MPPE-Encryption-Policy = 0x00000001
MS-MPPE-Encryption-Types = 0x00000006
Finished request 6.
Going to the next request
Waking up in 4.9 seconds.
Cleaning up request 6 ID 116 with timestamp +9831
Ready to process requests.
-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
