limiting fail timeout for an LDAP module
Hi, I am working with a peculiar LDAP backend which, from time to time, will take upwards of 10 seconds to respond to a search request. I know that is what needs fixing, but let's say I have to live with it for now. There is a second LDAP backend which I can use a backup when the first one goes nuts. So I'm thinking let's setup two LDAP module instances and use them in a redundant group. For this to be usable for EAP authentication however, I need to make sure freeradius fails the first LDAP module within some (short) time limit. I have thus been trying to tweak the first LDAP module instance settings in order to achieve that. After experimenting with these settings: options.res_timeout options.srv_timelimit pool.start I found that if I set pool.start=0 and, say, options.res_timeout=2 freeradius reconnects (retrying the search once) and fails the module after a total of 4 seconds: Fri Feb 3 18:29:43 2017 : Debug: (1) ldap_first_bad: Waiting for search result... Fri Feb 3 18:29:44 2017 : Debug: Waking up in 0.4 seconds. Fri Feb 3 18:29:44 2017 : Debug: Waking up in 0.7 seconds. Fri Feb 3 18:29:45 2017 : Debug: Waking up in 1.1 seconds. Fri Feb 3 18:29:45 2017 : Debug: rlm_ldap: Closing libldap handle 0x7fa240000cb0 Fri Feb 3 18:29:45 2017 : Debug: rlm_ldap (ldap_first_bad): Reconnecting (0) Fri Feb 3 18:29:45 2017 : Debug: rlm_ldap (ldap_first_bad): Connecting to ldaps://xxxxxxxx Fri Feb 3 18:29:45 2017 : Debug: rlm_ldap (ldap_first_bad): New libldap handle 0x7fa238000da0 Fri Feb 3 18:29:45 2017 : Debug: rlm_ldap (ldap_first_bad): Waiting for bind result... Fri Feb 3 18:29:45 2017 : Debug: rlm_ldap (ldap_first_bad): Bind successful Fri Feb 3 18:29:45 2017 : WARNING: (1) ldap_first_bad: Search failed: Timed out while waiting for server to respond. Got new socket, retrying... Fri Feb 3 18:29:45 2017 : Debug: (1) ldap_first_bad: Waiting for search result... Fri Feb 3 18:29:46 2017 : Debug: Waking up in 1.6 seconds. Fri Feb 3 18:29:47 2017 : Debug: rlm_ldap: Closing libldap handle 0x7fa238000da0 Fri Feb 3 18:29:47 2017 : Debug: rlm_ldap (ldap_first_bad): Reconnecting (0) Fri Feb 3 18:29:47 2017 : Debug: rlm_ldap (ldap_first_bad): Connecting to ldaps://xxxxxxxx Fri Feb 3 18:29:47 2017 : Debug: rlm_ldap (ldap_first_bad): New libldap handle 0x7fa238000da0 Fri Feb 3 18:29:47 2017 : Debug: rlm_ldap (ldap_first_bad): Waiting for bind result... Fri Feb 3 18:29:47 2017 : Debug: rlm_ldap (ldap_first_bad): Bind successful Fri Feb 3 18:29:47 2017 : WARNING: (1) ldap_first_bad: Search failed: Timed out while waiting for server to respond. Got new socket, retrying... Fri Feb 3 18:29:47 2017 : Debug: (1) ldap_first_bad: Waiting for search result... Fri Feb 3 18:29:48 2017 : Debug: Waking up in 2.5 seconds. Fri Feb 3 18:29:48 2017 : Error: (1) Ignoring duplicate packet from client localhost port 34423 - ID: 11 due to unfinished request in component authorize module ldap_first_bad Fri Feb 3 18:29:48 2017 : Debug: Waking up in 1.9 seconds. Fri Feb 3 18:29:49 2017 : Debug: rlm_ldap: Closing libldap handle 0x7fa238000da0 Fri Feb 3 18:29:49 2017 : Debug: rlm_ldap (ldap_first_bad): Reconnecting (0) Fri Feb 3 18:29:49 2017 : Debug: rlm_ldap (ldap_first_bad): Connecting to ldaps://xxxxxxxx Fri Feb 3 18:29:49 2017 : Debug: rlm_ldap (ldap_first_bad): New libldap handle 0x7fa238000da0 Fri Feb 3 18:29:49 2017 : Debug: rlm_ldap (ldap_first_bad): Waiting for bind result... Fri Feb 3 18:29:49 2017 : Debug: rlm_ldap (ldap_first_bad): Bind successful Fri Feb 3 18:29:49 2017 : WARNING: (1) ldap_first_bad: Search failed: Timed out while waiting for server to respond. Got new socket, retrying... Fri Feb 3 18:29:49 2017 : ERROR: (1) ldap_first_bad: Hit reconnection limit Fri Feb 3 18:29:49 2017 : Debug: rlm_ldap (ldap_first_bad): Released connection (0) Fri Feb 3 18:29:49 2017 : Info: rlm_ldap (ldap_first_bad): Need 1 more connections to reach 10 spares Fri Feb 3 18:29:49 2017 : Info: rlm_ldap (ldap_first_bad): Opening additional connection (2), 1 of 30 pending slots used Fri Feb 3 18:29:49 2017 : Debug: rlm_ldap (ldap_first_bad): Connecting to ldaps://xxxxxxxx Fri Feb 3 18:29:49 2017 : Debug: rlm_ldap (ldap_first_bad): New libldap handle 0x7fa2380215b0 Fri Feb 3 18:29:50 2017 : Debug: rlm_ldap (ldap_first_bad): Waiting for bind result... Fri Feb 3 18:29:50 2017 : Debug: rlm_ldap (ldap_first_bad): Bind successful Fri Feb 3 18:29:50 2017 : Debug: (1) modsingle[authorize]: returned from ldap_first_bad (rlm_ldap) Fri Feb 3 18:29:50 2017 : Debug: (1) [ldap_first_bad] = fail Fri Feb 3 18:29:50 2017 : Debug: (1) modsingle[authorize]: calling ldap_backup (rlm_ldap) I am wondering if this is as good as it gets or if there are other things to tweak or to try, to get a shorter timeout in this particular case, perhaps avoiding the side effect of start=0 documented therein (Set to 0 to allow the server to start without the directory being available). This is on freeradius 3.0.12. Thanks for any insight, Z.
On Feb 3, 2017, at 12:21 PM, Zenon Mousmoulas <zmousm@noc.grnet.gr> wrote:
I am working with a peculiar LDAP backend which, from time to time, will take upwards of 10 seconds to respond to a search request. I know that is what needs fixing, but let's say I have to live with it for now. There is a second LDAP backend which I can use a backup when the first one goes nuts. So I'm thinking let's setup two LDAP module instances and use them in a redundant group.
That will help a bit, but not a lot. The server doesn't track status across multiple modules. So each time a request is passed through a "redundant" group, it will try all modules in order.
I am wondering if this is as good as it gets or if there are other things to tweak or to try, to get a shorter timeout in this particular case, perhaps avoiding the side effect of start=0 documented therein (Set to 0 to allow the server to start without the directory being available).
That's probably as good as it gets for now. We're looking at ways to fix this in v4, where architectural updates make this kind of tracking easier to do. Another alternative is to set up a local LDAP replica of the "bad" database. Since no one else uses it, it should be highly available. But the short answer is that if FreeRADIUS needs a back-end database.. .make sure that the database is available. If the database goes down, no amount of poking FreeRADIUS will make the database work. Alan DeKok.
On 2017-02-03 19:38, Alan DeKok wrote:
On Feb 3, 2017, at 12:21 PM, Zenon Mousmoulas <zmousm@noc.grnet.gr> wrote:
I am working with a peculiar LDAP backend which, from time to time, will take upwards of 10 seconds to respond to a search request. I know that is what needs fixing, but let's say I have to live with it for now. There is a second LDAP backend which I can use a backup when the first one goes nuts. So I'm thinking let's setup two LDAP module instances and use them in a redundant group.
That will help a bit, but not a lot. The server doesn't track status across multiple modules. So each time a request is passed through a "redundant" group, it will try all modules in order.
I expected that; and even if it were possible for the particular LDAP module to fail persistently, I'm not sure how that could be detected in this case (no on/off connection or bind issues).
I am wondering if this is as good as it gets or if there are other things to tweak or to try, to get a shorter timeout in this particular case, perhaps avoiding the side effect of start=0 documented therein (Set to 0 to allow the server to start without the directory being available).
That's probably as good as it gets for now. We're looking at ways to fix this in v4, where architectural updates make this kind of tracking easier to do.
Thanks, good to know.
Another alternative is to set up a local LDAP replica of the "bad" database. Since no one else uses it, it should be highly available.
It is actually sort of like that: the second LDAP backend reflects the contents of the first database, minus the password attributes however, so it is not an exact replica; this explains why I'd be tempted to try the first backend even in this case.
But the short answer is that if FreeRADIUS needs a back-end database.. .make sure that the database is available. If the database goes down, no amount of poking FreeRADIUS will make the database work.
Understood, thanks. Z.
Hi,
I am wondering if this is as good as it gets or if there are other things to tweak or to try, to get a shorter timeout in this
well, you've set those values to 2 and 2 - so 4 is what you should expect.... what is the time taken to do a query when the server is working? you might be able to do a 1s per value, you should also look at using caching etc to ensure that you hit the LDAP as few times as possible you have a bad LDAP - what is the issue - why cant it be fixed rather than putting sticking plasters on rest of intrastrucure... your logs already show a NAS resending when no just run a slave OpenLDAP server locally to keep the values you need on hand and quick? alan
On 2017-02-03 20:01, A.L.M.Buxey@lboro.ac.uk wrote:
Hi,
I am wondering if this is as good as it gets or if there are other things to tweak or to try, to get a shorter timeout in this
well, you've set those values to 2 and 2 - so 4 is what you should expect.... what is the time taken to do a query when the server is working? you might be able to do a 1s per value, you should also look at using caching etc to ensure that you hit the LDAP as few times as possible
Actually, looking at the log shows the LDAP module is timing out and reconnecting once after 2 seconds (options.res_timeout), retrying, timing out again after 2 seconds, reconnecting and failing the request. This pattern is apparently affected by pool.start, but despite setting that to 0 I could not get it to skip the first reconnect+retry. I wouldn't want to further reduce options.res_timeout in fear of hitting some "false positive" timeouts. Thanks for suggesting caching, maybe that could help at least reduce the latency for some subsequent re-authentications.
you have a bad LDAP - what is the issue - why cant it be fixed rather than putting sticking plasters on rest of intrastrucure... your logs already show a NAS resending
Yep, it's a mess.
when no just run a slave OpenLDAP server locally to keep the values you need on hand and quick?
The second backend is (sort of) a partial replica (no password attributes). We can do better than that, for sure. Thanks, Z.
participants (3)
-
A.L.M.Buxey＠lboro.ac.uk -
Alan DeKok -
Zenon Mousmoulas