LDAP timeouts

freeradius at corwyn.net freeradius at corwyn.net
Wed Jan 20 06:43:26 CET 2010 

At 08:33 PM 1/14/2010, freeradius at 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.

More information about the Freeradius-Users mailing list