I'm running into the following scenario. Shortly after slapd gets bombarded by a burst of operations (from several different clients) on existing connections (well under the max number of connections, about 3000 out of 16384), it suddenly hangs. It's not responsive to any new connections, and doesn't process operations on existing connections. Load average is near zero during this time, so it's not doing anything. After 20 minutes (idletimeout), slapd frees several connections (maybe say 1000), and resumes working again as if nothing happened.
The load pattern that gets it into this state happens every hour, almost on the hour (most likely associated with nslcd and cron jobs, which we're looking to mitigate elsewise). Another strange thing is that slapd will survive one instance's worth of bombardment without hanging, but the *next* hour will go into a hang state.
Are there any resources other than file descriptors that are freed up during the idletimeout processing? Are there any other parameters that can be tuned besides idletimeout here? Could it possibly be a case of deadlock somewhere, something grabbing all the locks? Would things like set_lk_max_locks be relevant to investigate here? Any log level settings that might reveal more of what's happening here?
Thanks for any suggestions on things to look at and try.
-Kartik
On 06/01/2011 08:43 AM, Kartik Subbarao wrote:
Are there any resources other than file descriptors that are freed up during the idletimeout processing? Are there any other parameters that can be tuned besides idletimeout here? Could it possibly be a case of deadlock somewhere, something grabbing all the locks? Would things like set_lk_max_locks be relevant to investigate here? Any log level settings that might reveal more of what's happening here?
Update: It's not a locks issue. I ran db4.8_stat -C A while one of the servers was in this hang state and there are plenty of locks available. Also another clarification -- all of the operations during the "bombardment" times in question are read operations from clients, no writes.
-Kartik
On 06/01/2011 09:08 AM, Kartik Subbarao wrote:
Update: It's not a locks issue.
Another update -- after I reduced the idletimeout to 60 seconds, the problem seems to have gone away. It would still be useful to know what might be causing this problem and to be able to support higher levels of idletimeout, but at least I have another workable option now.
-Kartik
Kartik Subbarao wrote:
On 06/01/2011 09:08 AM, Kartik Subbarao wrote:
Update: It's not a locks issue.
Another update -- after I reduced the idletimeout to 60 seconds, the problem seems to have gone away. It would still be useful to know what might be causing this problem and to be able to support higher levels of idletimeout, but at least I have another workable option now.
As usual, when investigating a hang, you should attach to slapd with gdb and get a snapshot of what all the threads are doing. Working around it before you know what caused it isn't all that useful in the long run.
On 06/01/2011 02:02 PM, Howard Chu wrote:
Kartik Subbarao wrote:
On 06/01/2011 09:08 AM, Kartik Subbarao wrote:
Update: It's not a locks issue.
Another update -- after I reduced the idletimeout to 60 seconds, the problem seems to have gone away. It would still be useful to know what might be causing this problem and to be able to support higher levels of idletimeout, but at least I have another workable option now.
As usual, when investigating a hang, you should attach to slapd with gdb and get a snapshot of what all the threads are doing. Working around it before you know what caused it isn't all that useful in the long run.
Unfortunately this instance of slapd doesn't have debugging symbols enabled (it's a stock Debian 2.4.25 slapd package), so I didn't think gdb would be that helpful...But now that you mention it, I could probably get some basic stack trace info that might yield some clues.
Thanks for the reminder :-)
-Kartik
--On Wednesday, June 01, 2011 2:22 PM -0400 Kartik Subbarao subbarao@computer.org wrote:
On 06/01/2011 02:02 PM, Howard Chu wrote:
Kartik Subbarao wrote:
On 06/01/2011 09:08 AM, Kartik Subbarao wrote:
Update: It's not a locks issue.
Another update -- after I reduced the idletimeout to 60 seconds, the problem seems to have gone away. It would still be useful to know what might be causing this problem and to be able to support higher levels of idletimeout, but at least I have another workable option now.
As usual, when investigating a hang, you should attach to slapd with gdb and get a snapshot of what all the threads are doing. Working around it before you know what caused it isn't all that useful in the long run.
Unfortunately this instance of slapd doesn't have debugging symbols enabled (it's a stock Debian 2.4.25 slapd package), so I didn't think gdb would be that helpful...But now that you mention it, I could probably get some basic stack trace info that might yield some clues.
Thanks for the reminder :-)
Debian ships the debugging symbols as a separate package. All you need to do is install that package, and you can get a full backtrace.
p slapd-dbg - Debugging information for the OpenLDAP server (slapd)
--Quanah
--
Quanah Gibson-Mount Sr. Member of Technical Staff Zimbra, Inc A Division of VMware, Inc. -------------------- Zimbra :: the leader in open source messaging and collaboration
On 06/01/2011 02:49 PM, Quanah Gibson-Mount wrote:
Unfortunately this instance of slapd doesn't have debugging symbols enabled (it's a stock Debian 2.4.25 slapd package), so I didn't think gdb would be that helpful...But now that you mention it, I could probably get some basic stack trace info that might yield some clues.
Thanks for the reminder :-)
Debian ships the debugging symbols as a separate package. All you need to do is install that package, and you can get a full backtrace.
p slapd-dbg - Debugging information for the OpenLDAP server (slapd)
Even better! Thanks for the info.
-Kartik
On 06/01/2011 02:02 PM, Howard Chu wrote:
Kartik Subbarao wrote:
On 06/01/2011 09:08 AM, Kartik Subbarao wrote:
Update: It's not a locks issue.
Another update -- after I reduced the idletimeout to 60 seconds, the problem seems to have gone away. It would still be useful to know what might be causing this problem and to be able to support higher levels of idletimeout, but at least I have another workable option now.
As usual, when investigating a hang, you should attach to slapd with gdb and get a snapshot of what all the threads are doing. Working around it before you know what caused it isn't all that useful in the long run.
Attached is the gdb stack trace from the hang state. It looks like the the threads are stuck in pthread_cond_wait() from send_ldap_ber(). Are there other relevant variables/structures to inspect for this scenario?
-Kartik
On 06/02/2011 09:20 AM, Kartik Subbarao wrote:
Attached is the gdb stack trace from the hang state. It looks like the the threads are stuck in pthread_cond_wait() from send_ldap_ber(). Are there other relevant variables/structures to inspect for this scenario?
Looking at the source a bit more, this is the line that the threads are stuck on (line 372 in result.c, in the send_ldap_ber() function):
ldap_pvt_thread_cond_wait( &conn->c_write2_cv, &conn->c_write2_mutex );
It would appear that there may be some deadlock around the c_write2_mutex that seems to be freed when the idletimeout processing kicks in and clears out the offending connection(s).
-Kartik
Kartik Subbarao wrote:
On 06/01/2011 02:02 PM, Howard Chu wrote:
Kartik Subbarao wrote:
On 06/01/2011 09:08 AM, Kartik Subbarao wrote:
Update: It's not a locks issue.
Another update -- after I reduced the idletimeout to 60 seconds, the problem seems to have gone away. It would still be useful to know what might be causing this problem and to be able to support higher levels of idletimeout, but at least I have another workable option now.
As usual, when investigating a hang, you should attach to slapd with gdb and get a snapshot of what all the threads are doing. Working around it before you know what caused it isn't all that useful in the long run.
Attached is the gdb stack trace from the hang state. It looks like the the threads are stuck in pthread_cond_wait() from send_ldap_ber(). Are there other relevant variables/structures to inspect for this scenario?
-Kartik
Also get a netstat -nA inet. Threads waiting in send_ldap_ber() means their output buffers got full, clients didn't read the pending data.
On 06/02/2011 01:36 PM, Howard Chu wrote:
Attached is the gdb stack trace from the hang state. It looks like the the threads are stuck in pthread_cond_wait() from send_ldap_ber(). Are there other relevant variables/structures to inspect for this scenario?
Also get a netstat -nA inet. Threads waiting in send_ldap_ber() means their output buffers got full, clients didn't read the pending data.
(Un)fortunately that hang state hasn't occurred since yesterday (even with idletimeout set to 20 min).
I did run that netstat command periodically in any case, just to observe what happens during times of high traffic. The one thing I do notice sporadically is a bunch of connections in FIN_WAIT_1. But they do seem to clear up on their own within a minute or so. So it doesn't look like there's a long-term problem with accumulating TCP connections.
I'll try to capture the netstat during the hang time if/when it happens again.
-Kartik
On 06/01/2011 12:19 PM, Kartik Subbarao wrote:
On 06/01/2011 09:08 AM, Kartik Subbarao wrote:
Update: It's not a locks issue.
Another update -- after I reduced the idletimeout to 60 seconds, the problem seems to have gone away. It would still be useful to know what might be causing this problem and to be able to support higher levels of idletimeout, but at least I have another workable option now.
Well it looks like I spoke somewhat too soon. The problem hasn't entirely gone away, but now it happens less frequently, and only hangs for 60 seconds instead of 20 minutes. Which confirms my observation that this is idletimeout-related. Any thoughts/ideas would be greatly appreciated.
-Kartik
On 06/01/2011 08:43 AM, Kartik Subbarao wrote:
I'm running into the following scenario. Shortly after slapd gets bombarded by a burst of operations (from several different clients) on existing connections (well under the max number of connections, about 3000 out of 16384), it suddenly hangs. It's not responsive to any new connections, and doesn't process operations on existing connections. Load average is near zero during this time, so it's not doing anything. After 20 minutes (idletimeout), slapd frees several connections (maybe say 1000), and resumes working again as if nothing happened.
The load pattern that gets it into this state happens every hour, almost on the hour (most likely associated with nslcd and cron jobs, which we're looking to mitigate elsewise). Another strange thing is that slapd will survive one instance's worth of bombardment without hanging, but the *next* hour will go into a hang state.
Are there any resources other than file descriptors that are freed up during the idletimeout processing? Are there any other parameters that can be tuned besides idletimeout here? Could it possibly be a case of deadlock somewhere, something grabbing all the locks? Would things like set_lk_max_locks be relevant to investigate here? Any log level settings that might reveal more of what's happening here?
I have noticed similar behavior on a handful of occasions with 2.4.23 and bdb-4.7.25p4.
When this happens, the last log entry I typically see is a search that misses the indexes (e.g. (mail=*a*)).
The server has the default idletimeout (disabled).
I have as yet been unable to force the hang, though I have not tried heavier loads with SLAMD. It has also been a while since I have seen this, so I do not have a stacktrace handy.
I just wanted to add this anecdotal evidence of the hang. I hope at some point I'll be able to get a working stacktrace. Of course, I should also try newer versions of OpenLDAP and BDB.
openldap-technical@openldap.org