Hi, I've got freeradius 3.1 up and running (taken from the git repo on the 25th Nov) on Ubuntu 14.04 and am having weird issues with LDAP. Hoping someone may be able to shed some light. I'm using freeradius for dot1x authentication, both wireless (peap/mschapv2) and wired via NTLM auth. The freeradius LDAP module is used to look up Active Directory group membership and based on membership returns the relevant Tunnel-Private-Group-Id. The issue I'm having is that the LDAP lookup will work most of the time, but will frequently stop working for 5-25 minutes. It will start working again without any changes being made. To isolate LDAP user/server issues I've tried using different user accounts and 2012 AD servers. My freeradius config is pretty stock and I have highlighted what I believe is the the relevent LDAP config below. Please let me know if you need any more configuration to assist. This same LDAP config is working in 3.0.10, but I'm experiencing other unrelated issues (I think) and that is why I am trying 3.1 (these issues seem to be resolved in 3.1 so far). Many thanks! mods-config/files/authorize: DEFAULT Ldap-Group == "CN=test,OU=VLAN-Access,DC=in,DC=testdomain" Tunnel-Medium-Type = 802, Tunnel-Type = VLAN, Tunnel-Private-Group-Id = 10 mods-enabled/ldap: ldap { server = 'dc1.in.testdomain' server = 'dc2.in.testdomain' identity = 'CN=ldapradiusauth,CN=users,DC=in,DC=testdomain' password = 'changeme' base_dn = 'dc=in,dc=testdomain' } user { *SNIP* filter = "(sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}})" *SNIP* } group { *SNIP* membership_filter = "(member:1.2.840.113556.1.4.1941:=%{control:Ldap-UserDn})" *SNIP* } debug output for when LDAP is not working: Debug: (7) Received Access-Request Id 155 from 192.168.6.253:41795 to 192.168.254.173:1812 via eth0 length 319 Debug: (7) User-Name = "DOMAIN\\testuser" Debug: (7) NAS-IP-Address = 192.168.6.253 Debug: (7) NAS-Port = 0 Debug: (7) NAS-Identifier = "192.168.6.253" Debug: (7) NAS-Port-Type = Wireless-802.11 Debug: (7) Calling-Station-Id = "240A64A07AA3" Debug: (7) Called-Station-Id = "000B869A9037" Debug: (7) Service-Type = Framed-User Debug: (7) Framed-MTU = 1100 Debug: (7) EAP-Message = 0x0208006b190017030100604d9137ede185960c664a078e8b48cc5082037cb862005ef9b5fcd5c382b38ec0169fe33226ba383903ad774f0d68d2570bb96ded52f75b9306047481284bea8329db0f25c65a2e3df1f0ee5e4e774ff8b1bd22e83e8c31e9525a60f8fa16ca2e Debug: (7) State = 0xee38dd6d6038ae2de9d2789435e4c640 Debug: (7) Aruba-Essid-Name = "bandit" Debug: (7) Aruba-Location-Id = "ap1" Debug: (7) Aruba-AP-Group = "grp1" Debug: (7) Aruba-Device-Type = "Win 7" Debug: (7) Message-Authenticator = 0xf0ea95380ec91f06d36168bc3de93a19 Debug: (7) No &session-state attributes to restore Debug: (7) # Executing section authorize from file /etc/freeradius/sites-enabled/default Debug: (7) authorize { Debug: (7) policy filter_username { Debug: (7) if (!&User-Name){ Debug: (7) if (!&User-Name) -> FALSE Debug: (7) if (&User-Name =~ / /){ Debug: No matches Debug: (7) if (&User-Name =~ / /) -> FALSE Debug: (7) if (&User-Name =~ /@.*@/ ){ Debug: No matches Debug: (7) if (&User-Name =~ /@.*@/ ) -> FALSE Debug: (7) if (&User-Name =~ /\.\./ ){ Debug: No matches Debug: (7) if (&User-Name =~ /\.\./ ) -> FALSE Debug: (7) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)){ Debug: No matches Debug: (7) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) -> FALSE Debug: (7) if (&User-Name =~ /\.$/){ Debug: No matches Debug: (7) if (&User-Name =~ /\.$/) -> FALSE Debug: (7) if (&User-Name =~ /@\./){ Debug: No matches Debug: (7) if (&User-Name =~ /@\./) -> FALSE Debug: (7) } # policy filter_username = notfound Debug: (7) modsingle[authorize]: calling preprocess (preprocess) for request 7 Debug: (7) preprocess: Comparing name "DOMAIN\testuser" and check value ".ppp" Debug: (7) preprocess: Comparing name "DOMAIN\testuser" and check value ".slip" Debug: (7) preprocess: Comparing name "DOMAIN\testuser" and check value ".cslip" Debug: (7) modsingle[authorize]: returned from preprocess (preprocess) for request 7 Debug: (7) [preprocess] = ok Debug: (7) modsingle[authorize]: calling chap (chap) for request 7 Debug: (7) modsingle[authorize]: returned from chap (chap) for request 7 Debug: (7) [chap] = noop Debug: (7) modsingle[authorize]: calling mschap (mschap) for request 7 Debug: (7) modsingle[authorize]: returned from mschap (mschap) for request 7 Debug: (7) [mschap] = noop Debug: (7) modsingle[authorize]: calling digest (digest) for request 7 Debug: (7) modsingle[authorize]: returned from digest (digest) for request 7 Debug: (7) [digest] = noop Debug: (7) modsingle[authorize]: calling suffix (realm) for request 7 Debug: (7) suffix: Checking for suffix after "@" Debug: (7) suffix: No '@' in User-Name = "DOMAIN\testuser", looking up realm NULL Debug: (7) suffix: No such realm "NULL" Debug: (7) modsingle[authorize]: returned from suffix (realm) for request 7 Debug: (7) [suffix] = noop Debug: (7) modsingle[authorize]: calling ntdomain (realm) for request 7 Debug: (7) ntdomain: Checking for prefix before "\" Debug: (7) ntdomain: Looking up realm "DOMAIN" for User-Name = "DOMAIN\testuser" Debug: (7) ntdomain: Found realm "DOMAIN" Debug: (7) ntdomain: Adding Stripped-User-Name = "testuser" Debug: (7) ntdomain: Adding Realm = "DOMAIN" Debug: (7) ntdomain: Authentication realm is LOCAL Debug: (7) modsingle[authorize]: returned from ntdomain (realm) for request 7 Debug: (7) [ntdomain] = ok Debug: (7) modsingle[authorize]: calling eap (eap) for request 7 Debug: (7) eap: Peer sent EAP Response (code 2) ID 8 length 107 Debug: (7) eap: Continuing tunnel setup Debug: (7) modsingle[authorize]: returned from eap (eap) for request 7 Debug: (7) [eap] = ok Debug: (7) } # authorize = ok Debug: (7) Found Auth-Type = EAP Debug: (7) # Executing group from file /etc/freeradius/sites-enabled/default Debug: (7) authenticate { Debug: (7) modsingle[authenticate]: calling eap (eap) for request 7 Debug: (7) eap: Got eap_session_t 0x1fd38a0 from request data Debug: (7) eap: Peer sent packet with method EAP PEAP (25) Debug: (7) eap: Calling submodule eap_peap to process data Debug: (7) eap_peap: Continuing EAP-TLS Debug: (7) eap_peap: Peer sent flags -------- Debug: (7) eap_peap: Got complete TLS record (101 bytes) Debug: (7) eap_peap: [eap-tls verify] = ok Debug: (7) eap_peap: [eap-tls process] = ok Debug: (7) eap_peap: Session established. Decoding tunneled attributes Debug: (7) eap_peap: PEAP state phase2 Debug: (7) eap_peap: EAP method MSCHAPv2 (26) Debug: (7) eap_peap: Got tunneled request Debug: (7) eap_peap: EAP-Message = 0x0208004e1a02080049317ef3bc67cb921089a4502f961e0e3e93000000000000000040fbef6cb5343fc997e0c4bee9af0168efc513c085e0344b004652455348564945575c74796e616e74657374 Debug: (7) eap_peap: Setting &request:User-Name from tunnel (protected) identity "DOMAIN\testuser" Debug: (7) eap_peap: Sending tunneled request to inner-tunnel Debug: (7) eap_peap: Adding eap_session_t 0x1fe9a90 to fake request Debug: (7) Added request data 0x1fe9a90 at (nil):1 Debug: (7) Virtual server inner-tunnel received request Debug: (7) EAP-Message = 0x0208004e1a02080049317ef3bc67cb921089a4502f961e0e3e93000000000000000040fbef6cb5343fc997e0c4bee9af0168efc513c085e0344b004652455348564945575c74796e616e74657374 Debug: (7) FreeRADIUS-Proxied-To = 127.0.0.1 Debug: (7) User-Name = "DOMAIN\\testuser" Debug: (7) server inner-tunnel { Debug: (7) No &request:State attribute, can't restore &session-state Debug: (7) # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel Debug: (7) authorize { Debug: (7) modsingle[authorize]: calling chap (chap) for request 7 Debug: (7) modsingle[authorize]: returned from chap (chap) for request 7 Debug: (7) [chap] = noop Debug: (7) modsingle[authorize]: calling mschap (mschap) for request 7 Debug: (7) modsingle[authorize]: returned from mschap (mschap) for request 7 Debug: (7) [mschap] = noop Debug: (7) modsingle[authorize]: calling suffix (realm) for request 7 Debug: (7) suffix: Checking for suffix after "@" Debug: (7) suffix: No '@' in User-Name = "DOMAIN\testuser", looking up realm NULL Debug: (7) suffix: No such realm "NULL" Debug: (7) modsingle[authorize]: returned from suffix (realm) for request 7 Debug: (7) [suffix] = noop Debug: (7) modsingle[authorize]: calling ntdomain (realm) for request 7 Debug: (7) ntdomain: Checking for prefix before "\" Debug: (7) ntdomain: Looking up realm "DOMAIN" for User-Name = "DOMAIN\testuser" Debug: (7) ntdomain: Found realm "DOMAIN" Debug: (7) ntdomain: Adding Stripped-User-Name = "testuser" Debug: (7) ntdomain: Adding Realm = "DOMAIN" Debug: (7) ntdomain: Authentication realm is LOCAL Debug: (7) modsingle[authorize]: returned from ntdomain (realm) for request 7 Debug: (7) [ntdomain] = ok Debug: (7) update control { Debug: (7) &Proxy-To-Realm := LOCAL Debug: (7) } # update control = noop Debug: (7) modsingle[authorize]: calling eap (eap) for request 7 Debug: (7) eap: Peer sent EAP Response (code 2) ID 8 length 78 Debug: (7) eap: Continuing on-going EAP conversation Debug: (7) modsingle[authorize]: returned from eap (eap) for request 7 Debug: (7) [eap] = updated Debug: (7) modsingle[authorize]: calling files (files) for request 7 Debug: (7) files: Searching for user in group "CN=test,OU=VLAN-Access,DC=in,DC=testdomain" Debug: rlm_ldap (ldap): Reserved connection (0) Debug: (7) files: EXPAND TMPL XLAT Debug: (sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}}) Debug: Parsed xlat tree: Debug: literal --> (sAMAccountName= Debug: if { Debug: attribute --> Stripped-User-Name Debug: } Debug: else { Debug: attribute --> User-Name Debug: } Debug: literal --> ) Debug: (7) files: EXPAND (sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}}) Debug: (7) files: --> (sAMAccountName=testuser) Debug: (7) files: EXPAND TMPL LITERAL Debug: (7) files: Performing search in "dc=in,dc=DOMAIN" with filter "(sAMAccountName=testuser)", scope "sub" Debug: (7) files: Waiting for search result... Debug: rlm_ldap (ldap): Rebinding to URL ldap://DomainDnsZones.in.testdomain/DC=DomainDnsZones,DC=in,DC=testdomain Debug: rlm_ldap (ldap): Waiting for bind result... Debug: rlm_ldap (ldap): Rebinding to URL ldap://ForestDnsZones.in.testdomain/DC=ForestDnsZones,DC=in,DC=testdomain Debug: rlm_ldap (ldap): Waiting for bind result... Debug: rlm_ldap (ldap): Rebinding to URL ldap://in.testdomain/CN=Configuration,DC=in,DC=testdomain Debug: rlm_ldap (ldap): Waiting for bind result... Debug: rlm_ldap (ldap): Bind successful Debug: rlm_ldap (ldap): Bind successful Debug: rlm_ldap (ldap): Bind successful Info: rlm_ldap (ldap): Deleting inviable connection (0) Debug: rlm_ldap: Closing libldap handle 0x1f60190 Info: rlm_ldap (ldap): Need 6 more connections to reach 10 spares Info: rlm_ldap (ldap): Opening additional connection (5), 1 of 28 pending slots used Debug: rlm_ldap (ldap): Connecting to ldap://dc1.in.testdomain:389 ldap://dc2.in.testdomain:389 Debug: rlm_ldap (ldap): New libldap handle 0x1f60190 Debug: rlm_ldap (ldap): Waiting for bind result... Debug: rlm_ldap (ldap): Bind successful Info: rlm_ldap (ldap): Closing connection (4): Hit idle_timeout, was idle for 135 seconds Debug: rlm_ldap: Closing libldap handle 0x1f9e9d0 Info: rlm_ldap (ldap): Closing connection (3): Hit idle_timeout, was idle for 135 seconds Debug: rlm_ldap: Closing libldap handle 0x1f9e180 Info: rlm_ldap (ldap): Closing connection (2): Hit idle_timeout, was idle for 135 seconds Debug: rlm_ldap (ldap): You probably need to lower "min" Debug: rlm_ldap: Closing libldap handle 0x1f8c9e0 Info: rlm_ldap (ldap): Closing connection (1): Hit idle_timeout, was idle for 135 seconds Debug: rlm_ldap (ldap): You probably need to lower "min" Debug: rlm_ldap: Closing libldap handle 0x1f8bee0 Debug: rlm_ldap (ldap): Reserved connection (5) WARNING: (7) files: Search failed: Timed out while waiting for server to respond. Got new socket, retrying... Debug: (7) files: Waiting for search result... Debug: rlm_ldap (ldap): Rebinding to URL ldap://DomainDnsZones.in.testdomain/DC=DomainDnsZones,DC=in,DC=testdomain Debug: rlm_ldap (ldap): Waiting for bind result... Debug: rlm_ldap (ldap): Rebinding to URL ldap://ForestDnsZones.in.testdomain/DC=ForestDnsZones,DC=in,DC=testdomain Debug: rlm_ldap (ldap): Waiting for bind result... Debug: rlm_ldap (ldap): Rebinding to URL ldap://in.testdomain/CN=Configuration,DC=in,DC=testdomain Debug: rlm_ldap (ldap): Waiting for bind result... Debug: rlm_ldap (ldap): Bind successful Debug: rlm_ldap (ldap): Bind successful Debug: rlm_ldap (ldap): Bind successful Info: rlm_ldap (ldap): Deleting inviable connection (5) Debug: rlm_ldap: Closing libldap handle 0x1f60190 Info: rlm_ldap (ldap): Need 3 more connections to reach 10 spares Info: rlm_ldap (ldap): Opening additional connection (6), 1 of 32 pending slots used Debug: rlm_ldap (ldap): Connecting to ldap://dc1.in.testdomain:389 ldap://dc2.in.testdomain:389 Debug: rlm_ldap (ldap): New libldap handle 0x1f60190 Debug: rlm_ldap (ldap): Waiting for bind result... Debug: rlm_ldap (ldap): Bind successful Debug: rlm_ldap (ldap): Reserved connection (6) WARNING: (7) files: Search failed: Timed out while waiting for server to respond. Got new socket, retrying... Debug: (7) files: Waiting for search result... Debug: rlm_ldap (ldap): Rebinding to URL ldap://DomainDnsZones.in.testdomain/DC=DomainDnsZones,DC=in,DC=testdomain Debug: rlm_ldap (ldap): Waiting for bind result... Debug: rlm_ldap (ldap): Rebinding to URL ldap://ForestDnsZones.in.testdomain/DC=ForestDnsZones,DC=in,DC=testdomain Debug: rlm_ldap (ldap): Waiting for bind result... Debug: rlm_ldap (ldap): Rebinding to URL ldap://in.testdomain/CN=Configuration,DC=in,DC=testdomain Debug: rlm_ldap (ldap): Waiting for bind result... Debug: rlm_ldap (ldap): Bind successful Debug: rlm_ldap (ldap): Bind successful Debug: rlm_ldap (ldap): Bind successful Info: rlm_ldap (ldap): Deleting inviable connection (6) Debug: rlm_ldap: Closing libldap handle 0x1f60190 Info: rlm_ldap (ldap): Need 3 more connections to reach 10 spares Info: rlm_ldap (ldap): Opening additional connection (7), 1 of 32 pending slots used Debug: rlm_ldap (ldap): Connecting to ldap://dc1.in.testdomain:389 ldap://dc2.in.testdomain:389 Debug: rlm_ldap (ldap): New libldap handle 0x1f60190 Debug: rlm_ldap (ldap): Waiting for bind result... Debug: rlm_ldap (ldap): Bind successful Debug: rlm_ldap (ldap): Reserved connection (7) WARNING: (7) files: Search failed: Timed out while waiting for server to respond. Got new socket, retrying... Debug: (7) files: Waiting for search result... Debug: rlm_ldap (ldap): Rebinding to URL ldap://DomainDnsZones.in.testdomain/DC=DomainDnsZones,DC=in,DC=testdomain Debug: rlm_ldap (ldap): Waiting for bind result... Debug: rlm_ldap (ldap): Rebinding to URL ldap://ForestDnsZones.in.testdomain/DC=ForestDnsZones,DC=in,DC=testdomain Debug: rlm_ldap (ldap): Waiting for bind result... Debug: rlm_ldap (ldap): Rebinding to URL ldap://in.testdomain/CN=Configuration,DC=in,DC=testdomain Debug: rlm_ldap (ldap): Waiting for bind result... Debug: rlm_ldap (ldap): Bind successful Debug: rlm_ldap (ldap): Bind successful Debug: rlm_ldap (ldap): Bind successful Info: rlm_ldap (ldap): Deleting inviable connection (7) Debug: rlm_ldap: Closing libldap handle 0x1f60190 Info: rlm_ldap (ldap): Need 3 more connections to reach 10 spares Info: rlm_ldap (ldap): Opening additional connection (8), 1 of 32 pending slots used Debug: rlm_ldap (ldap): Connecting to ldap://dc1.in.testdomain:389 ldap://dc2.in.testdomain:389 Debug: rlm_ldap (ldap): New libldap handle 0x1f60190 Debug: rlm_ldap (ldap): Waiting for bind result... Debug: rlm_ldap (ldap): Bind successful Debug: rlm_ldap (ldap): Reserved connection (8) WARNING: (7) files: Search failed: Timed out while waiting for server to respond. Got new socket, retrying... Debug: (7) files: Waiting for search result... Debug: rlm_ldap (ldap): Rebinding to URL ldap://DomainDnsZones.in.testdomain/DC=DomainDnsZones,DC=in,DC=testdomain Debug: rlm_ldap (ldap): Waiting for bind result... Debug: rlm_ldap (ldap): Rebinding to URL ldap://ForestDnsZones.in.testdomain/DC=ForestDnsZones,DC=in,DC=testdomain Debug: rlm_ldap (ldap): Waiting for bind result... Debug: rlm_ldap (ldap): Rebinding to URL ldap://in.testdomain/CN=Configuration,DC=in,DC=testdomain Debug: rlm_ldap (ldap): Waiting for bind result... Debug: rlm_ldap (ldap): Bind successful Debug: rlm_ldap (ldap): Bind successful Debug: rlm_ldap (ldap): Bind successful Info: rlm_ldap (ldap): Deleting inviable connection (8) Debug: rlm_ldap: Closing libldap handle 0x1f60190 Info: rlm_ldap (ldap): Need 3 more connections to reach 10 spares Info: rlm_ldap (ldap): Opening additional connection (9), 1 of 32 pending slots used Debug: rlm_ldap (ldap): Connecting to ldap://dc1.in.testdomain:389 ldap://dc2.in.testdomain:389 Debug: rlm_ldap (ldap): New libldap handle 0x1f60190 Debug: rlm_ldap (ldap): Waiting for bind result... Debug: rlm_ldap (ldap): Bind successful Debug: rlm_ldap (ldap): Reserved connection (9) WARNING: (7) files: Search failed: Timed out while waiting for server to respond. Got new socket, retrying... Debug: (7) files: Waiting for search result... Debug: rlm_ldap (ldap): Rebinding to URL ldap://DomainDnsZones.in.testdomain/DC=DomainDnsZones,DC=in,DC=testdomain Debug: rlm_ldap (ldap): Waiting for bind result... Debug: rlm_ldap (ldap): Rebinding to URL ldap://ForestDnsZones.in.testdomain/DC=ForestDnsZones,DC=in,DC=testdomain Debug: rlm_ldap (ldap): Waiting for bind result... Debug: rlm_ldap (ldap): Rebinding to URL ldap://in.testdomain/CN=Configuration,DC=in,DC=testdomain Debug: rlm_ldap (ldap): Waiting for bind result... Debug: rlm_ldap (ldap): Bind successful Debug: rlm_ldap (ldap): Bind successful Error: rlm_ldap (ldap): Bind with CN=ldapradiusauth,CN=users,DC=in,DC=testdomain to ldap://dc1.in.testdomain:389 ldap://dc2.in.testdomain:389 failed: Timed out while waiting for server to respond Unable to chase referral "ldap://DomainDnsZones.in.testdomain/DC=DomainDnsZones,DC=in,DC=testdomain" (-5: Timed out) Info: rlm_ldap (ldap): Deleting inviable connection (9) Debug: rlm_ldap: Closing libldap handle 0x1f60190 Info: rlm_ldap (ldap): Need 3 more connections to reach 10 spares Info: rlm_ldap (ldap): Opening additional connection (10), 1 of 32 pending slots used Debug: rlm_ldap (ldap): Connecting to ldap://dc1.in.testdomain:389 ldap://dc2.in.testdomain:389 Debug: rlm_ldap (ldap): New libldap handle 0x1f60190 Debug: rlm_ldap (ldap): Waiting for bind result... Debug: rlm_ldap (ldap): Bind successful Debug: rlm_ldap (ldap): Reserved connection (10) WARNING: (7) files: Search failed: Timed out while waiting for server to respond. Got new socket, retrying... ERROR: (7) files: Hit reconnection limit Debug output for when LDAP is working: Debug: (7) files: EXPAND (sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}}) Debug: (7) files: --> (sAMAccountName=testuser) Debug: (7) files: EXPAND TMPL LITERAL Debug: (7) files: Performing search in "dc=in,dc=DOMAIN" with filter "(sAMAccountName=testuser)", scope "sub" Debug: (7) files: Waiting for search result... Debug: rlm_ldap (ldap): Rebinding to URL ldap://DomainDnsZones.in.testdomain/DC=DomainDnsZones,DC=in,DC=testdomain Debug: rlm_ldap (ldap): Waiting for bind result... Debug: rlm_ldap (ldap): Rebinding to URL ldap://ForestDnsZones.in.testdomain/DC=ForestDnsZones,DC=in,DC=testdomain Debug: rlm_ldap (ldap): Waiting for bind result... Debug: rlm_ldap (ldap): Rebinding to URL ldap://in.testdomain/CN=Configuration,DC=in,DC=testdomain Debug: rlm_ldap (ldap): Waiting for bind result... Debug: rlm_ldap (ldap): Bind successful Debug: rlm_ldap (ldap): Bind successful Debug: rlm_ldap (ldap): Bind successful Debug: (7) files: User object found at DN "CN=testuser,OU=users,DC=in,DC=testdomain" Debug: (7) files: Checking for user in group objects Debug: (member:1.2.840.113556.1.4.1941:=%{control:Ldap-UserDn}) Debug: Parsed xlat tree: Debug: literal --> (member:1.2.840.113556.1.4.1941:= Debug: attribute --> LDAP-UserDN Debug: literal --> ) Debug: (7) files: EXPAND (member:1.2.840.113556.1.4.1941:=%{control:Ldap-UserDn}) Debug: (7) files: --> (member:1.2.840.113556.1.4.1941:=CN\3dtestuser\2cOU\3dUsers\2cDC\3din\2cDC\3dtestdomain) Debug: (7) files: Waiting for bind result... Debug: (7) files: Bind successful Debug: (7) files: Performing search in "CN=test,OU=VLAN-Access,DC=in,DC=testdomain" with filter "(member:1.2.840.113556.1.4.1941:=CN\3dtestuser\2cOU\3dUsers\2cDC\3din\2cDC\3dtestdomain", scope "sub" Debug: (7) files: Waiting for search result... Debug: (7) files: User found in group object "CN=test,OU=VLAN-Access,DC=in,DC=testdomain"
On 1 Dec 2015, at 03:34, Tynan Young <tynany@gmail.com> wrote:
Hi,
I've got freeradius 3.1 up and running (taken from the git repo on the 25th Nov) on Ubuntu 14.04 and am having weird issues with LDAP. Hoping someone may be able to shed some light.
I'm using freeradius for dot1x authentication, both wireless (peap/mschapv2) and wired via NTLM auth. The freeradius LDAP module is used to look up Active Directory group membership and based on membership returns the relevant Tunnel-Private-Group-Id.
The issue I'm having is that the LDAP lookup will work most of the time, but will frequently stop working for 5-25 minutes. It will start working again without any changes being made. To isolate LDAP user/server issues I've tried using different user accounts and 2012 AD servers.
CN=ldapradiusauth,CN=users,DC=in,DC=testdomain to ldap://dc1.in.testdomain:389 ldap://dc2.in.testdomain:389 failed: Timed out while waiting for server to respond Unable to chase referral "ldap://DomainDnsZones.in.testdomain/DC=DomainDnsZones,DC=in,DC=testdomain" (-5: Timed out) Interesting. So it looks like it follows the complete referral chain, but then the search operation times out. It may be that timeouts that were not being enforced correctly in v3.0.x are now enforced in v3.1.x, I did fix a fair few of those. To know for sure, it'd be good to get the debug output with timestampsand maybe a pcap showing what's actually going on. It really just seems like the LDAP server isn't responding quickly enough. -Arran Arran Cudbard-Bell <a.cudbardb@freeradius.org> FreeRADIUS development team FD31 3077 42EC 7FCD 32FE 5EE2 56CF 27F9 30A8 CAA2
On Wed, Dec 2, 2015 at 8:58 AM, Arran Cudbard-Bell <a.cudbardb@freeradius.org> wrote:
On 1 Dec 2015, at 03:34, Tynan Young <tynany@gmail.com> wrote:
Hi,
I've got freeradius 3.1 up and running (taken from the git repo on the 25th Nov) on Ubuntu 14.04 and am having weird issues with LDAP. Hoping someone may be able to shed some light.
I'm using freeradius for dot1x authentication, both wireless (peap/mschapv2) and wired via NTLM auth. The freeradius LDAP module is used to look up Active Directory group membership and based on membership returns the relevant Tunnel-Private-Group-Id.
The issue I'm having is that the LDAP lookup will work most of the time, but will frequently stop working for 5-25 minutes. It will start working again without any changes being made. To isolate LDAP user/server issues I've tried using different user accounts and 2012 AD servers.
CN=ldapradiusauth,CN=users,DC=in,DC=testdomain to ldap://dc1.in.testdomain:389 ldap://dc2.in.testdomain:389 failed: Timed out while waiting for server to respond Unable to chase referral "ldap://DomainDnsZones.in.testdomain/DC=DomainDnsZones,DC=in,DC=testdomain" (-5: Timed out)
Interesting.
So it looks like it follows the complete referral chain, but then the search operation times out. It may be that timeouts that were not being enforced correctly in v3.0.x are now enforced in v3.1.x, I did fix a fair few of those.
Interesting - this may explain some of the issues I've been experiencing with 3.0.X also.
To know for sure, it'd be good to get the debug output with timestampsand maybe a pcap showing what's actually going on.
See below. Let me know if you would like more information. -Timestamps when LDAP search is not working: Wed Dec 2 09:25:16 2015 : Debug: (7) files: Performing search in "dc=in,dc=testdomain" with filter "(sAMAccountName=testuser)", scope "sub" Wed Dec 2 09:25:16 2015 : Debug: (7) files: Waiting for search result... Wed Dec 2 09:27:23 2015 : Debug: rlm_ldap (ldap): Rebinding to URL ldap://DomainDnsZones.in.testdomain/DC=DomainDnsZones,DC=in,DC=testdomain Wed Dec 2 09:27:23 2015 : Debug: rlm_ldap (ldap): Waiting for bind result... Wed Dec 2 09:29:31 2015 : Debug: rlm_ldap (ldap): Rebinding to URL ldap://ForestDnsZones.in.testdomain/DC=ForestDnsZones,DC=in,DC=testdomain Wed Dec 2 09:29:31 2015 : Debug: rlm_ldap (ldap): Waiting for bind result... Wed Dec 2 09:29:31 2015 : Debug: rlm_ldap (ldap): Rebinding to URL ldap://in.testdomain/CN=Configuration,DC=in,DC=testdomain Wed Dec 2 09:29:31 2015 : Debug: rlm_ldap (ldap): Waiting for bind result... Wed Dec 2 09:29:31 2015 : Debug: rlm_ldap (ldap): Bind successful Wed Dec 2 09:29:31 2015 : Debug: rlm_ldap (ldap): Bind successful Wed Dec 2 09:29:31 2015 : Error: rlm_ldap (ldap): Bind with CN=ldapradiusauth,CN=users,DC=in,DC=testdomain to ldap://dc1.in.testdomain:389 ldap://dc2.in.testdomain:389 failed: Timed out while waiting for server to respond Unable to chase referral "ldap://DomainDnsZones.in.testdomain/DC=DomainDnsZones,DC=in,DC=testdomain" (-5: Timed out) Wed Dec 2 09:29:31 2015 : Info: rlm_ldap (ldap): Deleting inviable connection (0) Wed Dec 2 09:29:31 2015 : Debug: rlm_ldap: Closing libldap handle 0x2365990 Wed Dec 2 09:29:31 2015 : Info: rlm_ldap (ldap): Need 6 more connections to reach 10 spares Wed Dec 2 09:29:31 2015 : Info: rlm_ldap (ldap): Opening additional connection (5), 1 of 28 pending slots used Wed Dec 2 09:29:31 2015 : Debug: rlm_ldap (ldap): Connecting to ldap://dc1.in.testdomain:389 ldap://dc2.in.testdomain:389 Wed Dec 2 09:29:31 2015 : Debug: rlm_ldap (ldap): New libldap handle 0x2365990 Wed Dec 2 09:29:31 2015 : Debug: rlm_ldap (ldap): Waiting for bind result... Wed Dec 2 09:29:31 2015 : Debug: rlm_ldap (ldap): Bind successful Wed Dec 2 09:29:31 2015 : Info: rlm_ldap (ldap): Closing connection (4): Hit idle_timeout, was idle for 284 seconds Wed Dec 2 09:29:31 2015 : Debug: rlm_ldap: Closing libldap handle 0x23a41f0 Wed Dec 2 09:29:31 2015 : Info: rlm_ldap (ldap): Closing connection (3): Hit idle_timeout, was idle for 284 seconds Wed Dec 2 09:29:31 2015 : Debug: rlm_ldap: Closing libldap handle 0x23a39a0 Wed Dec 2 09:29:31 2015 : Info: rlm_ldap (ldap): Closing connection (2): Hit idle_timeout, was idle for 284 seconds Wed Dec 2 09:29:31 2015 : Debug: rlm_ldap (ldap): You probably need to lower "min" Wed Dec 2 09:29:31 2015 : Debug: rlm_ldap: Closing libldap handle 0x23922a0 Wed Dec 2 09:29:31 2015 : Info: rlm_ldap (ldap): Closing connection (1): Hit idle_timeout, was idle for 284 seconds Wed Dec 2 09:29:31 2015 : Debug: rlm_ldap (ldap): You probably need to lower "min" Wed Dec 2 09:29:31 2015 : Debug: rlm_ldap: Closing libldap handle 0x23917a0 Wed Dec 2 09:29:31 2015 : Debug: rlm_ldap (ldap): Reserved connection (5) Wed Dec 2 09:29:31 2015 : WARNING: (7) files: Search failed: Timed out while waiting for server to respond. Got new socket, retrying... Wed Dec 2 09:29:31 2015 : Debug: (7) files: Waiting for search result... -High level packet capture when LDAP search is not working: No. Time Source Destination Protocol Length Info 21 2.815005 radius.in.testdomain dc1.in.testdomain LDAP 106 bindRequest(1) "ldapradiusauth" simple 22 2.817726 dc1.in.testdomain radius.in.testdomain LDAP 88 bindResponse(1) success 27 2.822321 radius.in.testdomain dc1.in.testdomain LDAP 106 bindRequest(1) "ldapradiusauth" simple 28 2.825065 dc1.in.testdomain radius.in.testdomain LDAP 88 bindResponse(1) success 33 2.829556 radius.in.testdomain dc1.in.testdomain LDAP 106 bindRequest(1) "ldapradiusauth" simple 34 2.832579 dc1.in.testdomain radius.in.testdomain LDAP 88 bindResponse(1) success 39 2.837051 radius.in.testdomain dc1.in.testdomain LDAP 106 bindRequest(1) "ldapradiusauth" simple 40 2.839793 dc1.in.testdomain radius.in.testdomain LDAP 88 bindResponse(1) success 45 2.844133 radius.in.testdomain dc1.in.testdomain LDAP 106 bindRequest(1) "ldapradiusauth" simple 46 2.846510 dc1.in.testdomain radius.in.testdomain LDAP 88 bindResponse(1) success 53 31.857220 radius.in.testdomain dc1.in.testdomain LDAP 139 searchRequest(2) "dc=in,dc=testdomain" wholeSubtree 54 31.860144 dc1.in.testdomain radius.in.testdomain LDAP 1852 searchResEntry(2) "CN=testuser,OU=users,DC=in,DC=testdomain" | searchResRef(2) | searchResRef(2) | searchResRef(2) | searchResDone(2) success [1 result] 115 287.249001 radius.in.testdomain dc1.in.testdomain LDAP 73 unbindRequest(11) 122 287.253363 radius.in.testdomain dc1.in.testdomain LDAP 106 bindRequest(1) "ldapradiusauth" simple 123 287.256485 dc1.in.testdomain radius.in.testdomain LDAP 88 bindResponse(1) success 125 287.256691 radius.in.testdomain dc1.in.testdomain LDAP 73 unbindRequest(2) 127 287.256864 radius.in.testdomain dc1.in.testdomain LDAP 73 unbindRequest(2) 129 287.257010 radius.in.testdomain dc1.in.testdomain LDAP 73 unbindRequest(2) 131 287.257127 radius.in.testdomain dc1.in.testdomain LDAP 73 unbindRequest(2) 133 287.257266 radius.in.testdomain dc1.in.testdomain LDAP 139 searchRequest(2) "dc=in,dc=testdomain" wholeSubtree 142 287.259174 dc1.in.testdomain radius.in.testdomain LDAP 1852 searchResEntry(2) "CN=testuser,OU=users,DC=in,DC=testdomain" | searchResRef(2) | searchResRef(2) | searchResRef(2) | searchResDone(2) success [1 result] -High level packet capture when LDAP search is working: No. Time Source Destination Protocol Length Info 4 0.001709 radius.in.testdomain dc1.in.testdomain LDAP 106 bindRequest(1) "ldapradiusauth" simple 5 0.004474 dc1.in.testdomain radius.in.testdomain LDAP 88 bindResponse(1) success 10 0.008402 radius.in.testdomain dc1.in.testdomain LDAP 106 bindRequest(1) "ldapradiusauth" simple 11 0.011494 dc1.in.testdomain radius.in.testdomain LDAP 88 bindResponse(1) success 16 0.015274 radius.in.testdomain dc1.in.testdomain LDAP 106 bindRequest(1) "ldapradiusauth" simple 17 0.017818 dc1.in.testdomain radius.in.testdomain LDAP 88 bindResponse(1) success 22 0.022174 radius.in.testdomain dc1.in.testdomain LDAP 106 bindRequest(1) "ldapradiusauth" simple 23 0.024050 dc1.in.testdomain radius.in.testdomain LDAP 88 bindResponse(1) success 28 0.028135 radius.in.testdomain dc1.in.testdomain LDAP 106 bindRequest(1) "ldapradiusauth" simple 29 0.030606 dc1.in.testdomain radius.in.testdomain LDAP 88 bindResponse(1) success 31 7.718161 radius.in.testdomain dc1.in.testdomain LDAP 139 searchRequest(2) "dc=in,dc=testdomain" wholeSubtree 32 7.720647 dc1.in.testdomain radius.in.testdomain LDAP 1852 searchResEntry(2) "CN=testuser,OU=users,DC=in,DC=testdomain" | searchResRef(2) | searchResRef(2) | searchResRef(2) | searchResDone(2) success [1 result] 37 7.725337 radius.in.testdomain dc1.in.testdomain LDAP 106 bindRequest(4) "ldapradiusauth" simple 38 7.727794 dc1.in.testdomain radius.in.testdomain LDAP 88 bindResponse(4) success 43 7.945255 radius.in.testdomain dc2.in.testdomain LDAP 106 bindRequest(8) "ldapradiusauth" simple 44 7.948543 dc2.in.testdomain radius.in.testdomain LDAP 88 bindResponse(8) success 46 7.948856 radius.in.testdomain dc2.in.testdomain LDAP 156 searchRequest(7) "CN=Configuration,dc=in,dc=testdomain" wholeSubtree 47 7.949716 dc2.in.testdomain radius.in.testdomain LDAP 170 searchResRef(7) | searchResDone(7) success [0 results] 48 7.949817 radius.in.testdomain dc2.in.testdomain LDAP 166 searchRequest(9) "CN=Schema,CN=Configuration,dc=in,dc=testdomain" wholeSubtree 49 7.950501 dc2.in.testdomain radius.in.testdomain LDAP 88 searchResDone(9) success [0 results] 50 7.950590 radius.in.testdomain dc2.in.testdomain LDAP 73 unbindRequest(10) 54 8.151267 radius.in.testdomain dc1.in.testdomain LDAP 157 searchRequest(3) "DC=DomainDnsZones,dc=in,dc=testdomain" wholeSubtree 55 8.152470 dc1.in.testdomain radius.in.testdomain LDAP 88 searchResDone(3) success [0 results] 57 8.152626 radius.in.testdomain dc1.in.testdomain LDAP 73 unbindRequest(11) 61 8.364198 radius.in.testdomain dc1.in.testdomain LDAP 106 bindRequest(13) "ldapradiusauth" simple 62 8.367117 dc1.in.testdomain radius.in.testdomain LDAP 88 bindResponse(13) success 64 8.367626 radius.in.testdomain dc1.in.testdomain LDAP 272 searchRequest(14) "CN=test,OU=VLAN-Access,DC=in,DC=testdomain" wholeSubtree 65 8.369174 dc1.in.testdomain radius.in.testdomain LDAP 1038 searchResEntry(14) "CN=test,OU=VLAN-Access,DC=in,DC=testdomain" | searchResDone(14) success [1 result] 66 8.369731 radius.in.testdomain dc1.in.testdomain LDAP 73 unbindRequest(15) 73 8.375227 radius.in.testdomain dc1.in.testdomain LDAP 106 bindRequest(1) "ldapradiusauth" simple 74 8.377783 dc1.in.testdomain radius.in.testdomain LDAP 88 bindResponse(1) success 76 8.386249 radius.in.testdomain dc1.in.testdomain LDAP 225 searchRequest(2) "dc=in,dc=testdomain" wholeSubtree 77 8.388571 dc1.in.testdomain radius.in.testdomain LDAP 425 searchResEntry(2) "CN=testuser,OU=users,DC=in,DC=testdomain" | searchResRef(2) | searchResRef(2) | searchResRef(2) | searchResDone(2) success [1 result] 82 8.393105 radius.in.testdomain dc1.in.testdomain LDAP 106 bindRequest(4) "ldapradiusauth" simple 83 8.396002 dc1.in.testdomain radius.in.testdomain LDAP 88 bindResponse(4) success 88 8.612681 radius.in.testdomain dc2.in.testdomain LDAP 106 bindRequest(8) "ldapradiusauth" simple 89 8.615446 dc2.in.testdomain radius.in.testdomain LDAP 88 bindResponse(8) success 91 8.615772 radius.in.testdomain dc2.in.testdomain LDAP 242 searchRequest(7) "CN=Configuration,dc=in,dc=testdomain" wholeSubtree 92 8.616556 dc2.in.testdomain radius.in.testdomain LDAP 170 searchResRef(7) | searchResDone(7) success [0 results] 93 8.616637 radius.in.testdomain dc2.in.testdomain LDAP 252 searchRequest(9) "CN=Schema,CN=Configuration,dc=in,dc=testdomain" wholeSubtree 94 8.617563 dc2.in.testdomain radius.in.testdomain LDAP 88 searchResDone(9) success [0 results] 95 8.617650 radius.in.testdomain dc2.in.testdomain LDAP 73 unbindRequest(10) 99 8.819244 radius.in.testdomain dc1.in.testdomain LDAP 243 searchRequest(3) "DC=DomainDnsZones,dc=in,dc=testdomain" wholeSubtree 100 8.820485 dc1.in.testdomain radius.in.testdomain LDAP 88 searchResDone(3) success [0 results] 102 8.820635 radius.in.testdomain dc1.in.testdomain LDAP 73 unbindRequest(11) 106 9.032638 radius.in.testdomain dc1.in.testdomain LDAP 73 unbindRequest(13) 113 9.038806 radius.in.testdomain dc1.in.testdomain LDAP 106 bindRequest(1) "ldapradiusauth" simple 114 9.041627 dc1.in.testdomain radius.in.testdomain LDAP 88 bindResponse(1) success 119 9.101453 radius.in.testdomain dc1.in.testdomain LDAP 139 searchRequest(2) "dc=in,dc=testdomain" wholeSubtree 120 9.103941 dc1.in.testdomain radius.in.testdomain LDAP 1852 searchResEntry(2) "CN=testuser,OU=users,DC=in,DC=testdomain" | searchResRef(2) | searchResRef(2) | searchResRef(2) | searchResDone(2) success [1 result] 125 9.108084 radius.in.testdomain dc1.in.testdomain LDAP 106 bindRequest(4) "ldapradiusauth" simple 126 9.110923 dc1.in.testdomain radius.in.testdomain LDAP 88 bindResponse(4) success 131 9.329203 radius.in.testdomain dc2.in.testdomain LDAP 106 bindRequest(8) "ldapradiusauth" simple 132 9.332170 dc2.in.testdomain radius.in.testdomain LDAP 88 bindResponse(8) success 134 9.332361 radius.in.testdomain dc2.in.testdomain LDAP 156 searchRequest(7) "CN=Configuration,dc=in,dc=testdomain" wholeSubtree 135 9.333151 dc2.in.testdomain radius.in.testdomain LDAP 170 searchResRef(7) | searchResDone(7) success [0 results] 136 9.333294 radius.in.testdomain dc2.in.testdomain LDAP 166 searchRequest(9) "CN=Schema,CN=Configuration,dc=in,dc=testdomain" wholeSubtree 137 9.334050 dc2.in.testdomain radius.in.testdomain LDAP 88 searchResDone(9) success [0 results] 138 9.334179 radius.in.testdomain dc2.in.testdomain LDAP 73 unbindRequest(10) 142 9.534048 radius.in.testdomain dc1.in.testdomain LDAP 157 searchRequest(3) "DC=DomainDnsZones,dc=in,dc=testdomain" wholeSubtree 143 9.535179 dc1.in.testdomain radius.in.testdomain LDAP 88 searchResDone(3) success [0 results] 145 9.535365 radius.in.testdomain dc1.in.testdomain LDAP 73 unbindRequest(11) 149 9.746469 radius.in.testdomain dc1.in.testdomain LDAP 106 bindRequest(13) "ldapradiusauth" simple 150 9.749525 dc1.in.testdomain radius.in.testdomain LDAP 88 bindResponse(13) success 152 9.750101 radius.in.testdomain dc1.in.testdomain LDAP 272 searchRequest(14) "CN=test,OU=VLAN-Access,DC=in,DC=testdomain" wholeSubtree 153 9.751542 dc1.in.testdomain radius.in.testdomain LDAP 1038 searchResEntry(14) "CN=test,OU=VLAN-Access,DC=in,DC=testdomain" | searchResDone(14) success [1 result] 154 9.752103 radius.in.testdomain dc1.in.testdomain LDAP 73 unbindRequest(15) 161 9.757750 radius.in.testdomain dc1.in.testdomain LDAP 106 bindRequest(1) "ldapradiusauth" simple 162 9.760814 dc1.in.testdomain radius.in.testdomain LDAP 88 bindResponse(1) success 164 9.765768 radius.in.testdomain dc1.in.testdomain LDAP 225 searchRequest(2) "dc=in,dc=testdomain" wholeSubtree 165 9.767654 dc1.in.testdomain radius.in.testdomain LDAP 425 searchResEntry(2) "CN=testuser,OU=users,DC=in,DC=testdomain" | searchResRef(2) | searchResRef(2) | searchResRef(2) | searchResDone(2) success [1 result] 170 9.772173 radius.in.testdomain dc1.in.testdomain LDAP 106 bindRequest(4) "ldapradiusauth" simple 171 9.774400 dc1.in.testdomain radius.in.testdomain LDAP 88 bindResponse(4) success 176 9.991406 radius.in.testdomain dc2.in.testdomain LDAP 106 bindRequest(8) "ldapradiusauth" simple 177 9.993905 dc2.in.testdomain radius.in.testdomain LDAP 88 bindResponse(8) success 179 9.994235 radius.in.testdomain dc2.in.testdomain LDAP 242 searchRequest(7) "CN=Configuration,dc=in,dc=testdomain" wholeSubtree 180 9.995032 dc2.in.testdomain radius.in.testdomain LDAP 170 searchResRef(7) | searchResDone(7) success [0 results] 181 9.995132 radius.in.testdomain dc2.in.testdomain LDAP 252 searchRequest(9) "CN=Schema,CN=Configuration,dc=in,dc=testdomain" wholeSubtree 182 9.995820 dc2.in.testdomain radius.in.testdomain LDAP 88 searchResDone(9) success [0 results] 183 9.995894 radius.in.testdomain dc2.in.testdomain LDAP 73 unbindRequest(10) 187 10.198411 radius.in.testdomain dc1.in.testdomain LDAP 243 searchRequest(3) "DC=DomainDnsZones,dc=in,dc=testdomain" wholeSubtree 188 10.199514 dc1.in.testdomain radius.in.testdomain LDAP 88 searchResDone(3) success [0 results] 190 10.199652 radius.in.testdomain dc1.in.testdomain LDAP 73 unbindRequest(11) 194 10.410664 radius.in.testdomain dc1.in.testdomain LDAP 73 unbindRequest(13) 201 10.416576 radius.in.testdomain dc1.in.testdomain LDAP 106 bindRequest(1) "ldapradiusauth" simple 202 10.419202 dc1.in.testdomain radius.in.testdomain LDAP 88 bindResponse(1) success
It really just seems like the LDAP server isn't responding quickly enough.
Okay, I'll start doing some debugging on the active directory LDAP side of things.
-Arran
Arran Cudbard-Bell <a.cudbardb@freeradius.org> FreeRADIUS development team
FD31 3077 42EC 7FCD 32FE 5EE2 56CF 27F9 30A8 CAA2
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
It really just seems like the LDAP server isn't responding quickly enough.
Okay, I'll start doing some debugging on the active directory LDAP side of things.
So after doing more packet captures I discovered that freeradius was querying an active directory server that has been decommissioned. Not sure why it was querying this server as it was not referenced anywhere in the freeradius config, but after looking into active directory DNS I found this decommissioned server still existed under domaindnszones and forestdnszones. Since removing the decommissioned server DNS entries everything appears to be golden. Appreciate you pointing me in the right direction. Cheers!
On 1 Dec 2015, at 23:37, Tynan Young <tynany@gmail.com> wrote:
It really just seems like the LDAP server isn't responding quickly enough.
Okay, I'll start doing some debugging on the active directory LDAP side of things.
So after doing more packet captures I discovered that freeradius was querying an active directory server that has been decommissioned. Not sure why it was querying this server as it was not referenced anywhere in the freeradius config,
Because you enabled reference following, and resolving something in the tree provided by your initial set of servers ended up causing libldap to rebind to the decommissioned server.
but after looking into active directory DNS I found this decommissioned server still existed under domaindnszones and forestdnszones. Since removing the decommissioned server DNS entries everything appears to be golden.
Appreciate you pointing me in the right direction.
No problem -Arran Arran Cudbard-Bell <a.cudbardb@freeradius.org> FreeRADIUS development team FD31 3077 42EC 7FCD 32FE 5EE2 56CF 27F9 30A8 CAA2
On Wed, Dec 2, 2015 at 3:59 PM, Arran Cudbard-Bell <a.cudbardb@freeradius.org> wrote:
On 1 Dec 2015, at 23:37, Tynan Young <tynany@gmail.com> wrote:
It really just seems like the LDAP server isn't responding quickly enough.
Okay, I'll start doing some debugging on the active directory LDAP side of things.
So after doing more packet captures I discovered that freeradius was querying an active directory server that has been decommissioned. Not sure why it was querying this server as it was not referenced anywhere in the freeradius config,
Because you enabled reference following, and resolving something in the tree provided by your initial set of servers ended up causing libldap to rebind to the decommissioned server.
Got it. options { # The following two configuration items control whether the # server follows references returned by LDAP directory. # They are mostly for Active Directory compatibility. # If you set these to 'no', then searches will likely return # 'operations error', instead of a useful result. # chase_referrals = yes rebind = yes } Thanks again.
On Dec 1, 2015, at 3:34 AM, Tynan Young <tynany@gmail.com> wrote:
Debug: rlm_ldap (ldap): Reserved connection (7) WARNING: (7) files: Search failed: Timed out while waiting for server to respond. Got new socket, retrying...
Fix your LDAP server so that it responds to the LDAP query. Alan DeKok.
participants (3)
-
Alan DeKok -
Arran Cudbard-Bell -
Tynan Young