openldap-devel December 2012

openldap-devel@openldap.org

9 participants
14 discussions

Re: slapd deadlock bug ITS#7296
by Howard Chu 02 Jan '13

02 Jan '13

Richard Silverman wrote: > I’ve done this, and it may well be epoll-specific; the test has now run > over twice as long as the longest it has ever required to produce the > deadlock. With this sort of bug no amount of waiting would make me sure, > but it seems likely. I’ll leave it running. > > epoll(7) specifically mentions the possibility of epoll_wait hanging even > though there is outstanding unread data on a socket, when using > edge-triggered operation, and I notice in daemon.c that you switch to > edge-triggered mode in the event that the client closes the connection (at > least that’s what the comment suggests): > > /* Don't keep reporting the hangup > */ > if ( SLAP_SOCK_IS_ACTIVE( tid, fd )) { > SLAP_EPOLL_SOCK_SET( tid, fd, EPOLLET ); > } > > Perhaps related? Indeed. Seems like ITS#5886 has resurfaced. You can get some insight into this looking at about commit 96192064f3a3daea994eb8293f0413def5379958 forward. I don't have time to dig further into it at the moment, Christmas dinner(s) calling... > >> Also, what kernel version(s) are you testing on? > > 2.6.32 (Red Hat Enterprise Linux) I see a lot of Linux-kernel email traffic about epoll bugs as well, but not sure which are relevant to this version. Just something to stay aware of. -- -- Howard Chu CTO, Symas Corp. http://www.symas.com Director, Highland Sun http://highlandsun.com/hyc/ Chief Architect, OpenLDAP http://www.openldap.org/project/

2 3

Re: slapd deadlock bug ITS#7296
by Howard Chu 23 Dec '12

23 Dec '12

Richard Silverman wrote: > >> OK, so thread 13 is waiting on conn 1370, sd 39. There are actually no error >> messages associated with this connection or socket anywhere in your logs. >> >> Likewise for thread 16: conn 1351, sd 20. No errors anywhere. >> >> This looks more like a problem with epoll() than anything else. Are the >> connections associated with socket 20 and 39 actually dead? > > The process which initiated those connections is gone; the test harness > runs slamd (a load generator) repeatedly and then kills it while it is running, to simulate the connections going down in a variety of states. Interestingly, though, here’s the lsof output for the slapd file descriptors: > > Most of the TCP connections are in CLOSE_WAIT, which is what you’d expect > if the client sent a FIN but the server is frozen and cannot close the socket. However, note the odd state of the two sockets you asked about, 20 and 39: “can’t identify protocol.” There are 25 IPv4 connections in CLOSE_WAIT shown above; by comparison, netstat shows all those, plus one more on port 43362 not shown above. > A little googling produced this and similar comments: > > https://idea.popcount.org/2012-12-09-lsof-cant-identify-protocol/ I'm not sure this applies here; perhaps there's more than one way for the socket to end up in this state. > ... which I verified using the sample program provided in that blog post; apparently, after a TCP connection is fully closed, Linux just drops the information about it and it shows up like that thereafter. This is the network trace of a connection which ends up in this state: > > 03:11:01.875853 IP client.52176 > server.9918: Flags [S], seq 4090195389, win 14600, options [mss 1460,sackOK,TS val 3524517096 ecr 0,nop,wscale 9], length 0 > 03:11:01.875870 IP server.9918 > client.52176: Flags [S.], seq 2724560604, ack 4090195390, win 14480, options [mss 1460,sackOK,TS val 1101728398 ecr 3524517096,nop,wscale 9], length 0 > 03:11:01.876773 IP client.52176 > server.9918: Flags [.], ack 1, win 29, options [nop,nop,TS val 3524517096 ecr 1101728398], length 0 > 03:11:01.876852 IP server.9918 > client.52176: Flags [F.], seq 1, ack 1, win 29, options [nop,nop,TS val 1101728399 ecr 3524517096], length 0 > 03:11:01.877894 IP client.52176 > server.9918: Flags [.], ack 2, win 29, options [nop,nop,TS val 3524517098 ecr 1101728399], length 0 > 03:11:01.878978 IP client.52176 > server.9918: Flags [F.], seq 1, ack 2, win 29, options [nop,nop,TS val 3524517099 ecr 1101728399], length 0 > 03:11:01.878993 IP server.9918 > client.52176: Flags [.], ack 2, win 29, options [nop,nop,TS val 1101728401 ecr 3524517099], length 0 > > ... which is just a normal server-initiated close. I wonder if this odd socket state is not producing the expected/necessary error indication somewhere (e.g. ber_flush2) and thus mucking things up. slapd definitely is not initiating the close though. Something else to try would be to disable the use of epoll() and go back to select(), to see if this problem is epoll-specific. In slapd/daemon.c, after the #include "portable.h" add a #undef HAVE_EPOLL and then recompile and test. Also, what kernel version(s) are you testing on? -- -- Howard Chu CTO, Symas Corp. http://www.symas.com Director, Highland Sun http://highlandsun.com/hyc/ Chief Architect, OpenLDAP http://www.openldap.org/project/

1 0

Re: slapd deadlock bug ITS#7296
by Howard Chu 20 Dec '12

20 Dec '12

Richard Silverman wrote: >> So the question is why are these threads still waiting on their sockets. >> >> Looking at your logs, it's clear that the error occurs and >> connection_closing() is called, which will call connection_abandon() to set >> the o_abandon flag on all of the connection's ops. > > I agree; I had followed that much. > >> Can you please provide the output for "print *op" and "print *op->o_hdr" >> in thread 13 and thread 16, frame 3? > > (gdb) thread 13 > [Switching to thread 13 (Thread 0x7f21f27fc700 (LWP 8470))]#0 pthread_cond_wait@@GLIBC_2.3.2 () > at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162 > 162 62: movl (%rsp), %edi > (gdb) frame 3 > #3 0x000000000043e716 in send_ldap_ber (op=0x7f21cc191420, ber=0x7f21f267a460) at result.c:379 > 379 ldap_pvt_thread_cond_wait( &conn->c_write2_cv, &conn->c_write2_mutex ); > (gdb) print *op > $1 = {o_hdr = 0x7f21cc191590, o_tag = 99, o_time = 1356070283, o_tincr = 46, o_bd = 0x18217e0, o_req_dn = { > bv_len = 13, bv_val = 0x7f21e0009e88 "dc=alu,dc=com"}, o_req_ndn = {bv_len = 13, > bv_val = 0x7f21e0009ec0 "dc=alu,dc=com"}, o_request = {oq_add = {rs_modlist = 0x2, rs_e = 0xffffffffffffffff}, > oq_bind = {rb_method = 2, rb_cred = {bv_len = 18446744073709551615, bv_val = 0x0}, rb_edn = {bv_len = 0, > bv_val = 0x0}, rb_ssf = 3758137048, rb_mech = {bv_len = 15, bv_val = 0x7f21e0009ef8 "(objectClass=*)"}}, > oq_compare = {rs_ava = 0x2}, oq_modify = {rs_mods = {rs_modlist = 0x2, rs_no_opattrs = -1 '\377'}, > rs_increment = 0}, oq_modrdn = {rs_mods = {rs_modlist = 0x2, rs_no_opattrs = -1 '\377'}, > rs_deleteoldrdn = 0, rs_newrdn = {bv_len = 0, bv_val = 0x0}, rs_nnewrdn = {bv_len = 139783468785368, > bv_val = 0xf <Address 0xf out of bounds>}, rs_newSup = 0x7f21e0009ef8, rs_nnewSup = 0x0}, oq_search = { > rs_scope = 2, rs_deref = 0, rs_slimit = -1, rs_tlimit = -1, rs_limit = 0x0, rs_attrsonly = 0, > rs_attrs = 0x0, rs_filter = 0x7f21e0009ed8, rs_filterstr = {bv_len = 15, > bv_val = 0x7f21e0009ef8 "(objectClass=*)"}}, oq_abandon = {rs_msgid = 2}, oq_cancel = {rs_msgid = 2}, > oq_extended = {rs_reqoid = {bv_len = 2, > bv_val = 0xffffffffffffffff <Address 0xffffffffffffffff out of bounds>}, rs_flags = 0, rs_reqdata = 0x0}, > oq_pwdexop = {rs_extended = {rs_reqoid = {bv_len = 2, > bv_val = 0xffffffffffffffff <Address 0xffffffffffffffff out of bounds>}, rs_flags = 0, > rs_reqdata = 0x0}, rs_old = {bv_len = 0, bv_val = 0x7f21e0009ed8 "\207"}, rs_new = {bv_len = 15, > bv_val = 0x7f21e0009ef8 "(objectClass=*)"}, rs_mods = 0x0, rs_modtail = 0x0}}, o_abandon = 0, > o_cancel = 0, o_groups = 0x0, o_do_not_cache = 0 '\000', o_is_auth_check = 0 '\000', > o_dont_replicate = 0 '\000', o_acl_priv = ACL_NONE, o_nocaching = 0 '\000', o_delete_glue_parent = 0 '\000', > o_no_schema_check = 0 '\000', o_no_subordinate_glue = 0 '\000', o_ctrlflag = '\000' <repeats 31 times>, > o_controls = 0x7f21cc1916d8, o_authz = {sai_method = 128, sai_mech = {bv_len = 0, bv_val = 0x0}, sai_dn = { > bv_len = 24, bv_val = 0x7f21e4110a60 "cn=manager,dc=alu,dc=com"}, sai_ndn = {bv_len = 24, > bv_val = 0x7f21e4128e50 "cn=manager,dc=alu,dc=com"}, sai_ssf = 0, sai_transport_ssf = 0, sai_tls_ssf = 0, > sai_sasl_ssf = 0}, o_ber = 0x7f21e41f9700, o_res_ber = 0x0, o_callback = 0x0, o_ctrls = 0x0, o_csn = { > bv_len = 0, bv_val = 0x0}, o_private = 0x0, o_extra = {slh_first = 0x0}, o_next = {stqe_next = 0x7f21d8009fc0}} > (gdb) print *op->o_hdr > $2 = {oh_opid = 4, oh_connid = 1370, oh_conn = 0x7f221069b758, oh_msgid = 5, oh_protocol = 3, > oh_tid = 139783779108608, oh_threadctx = 0x7f21f27fba00, oh_tmpmemctx = 0x7f21e0009cb0, oh_tmpmfuncs = 0x839840, > oh_counters = 0x7f21e0009b80, oh_log_prefix = "conn=1370 op=4", '\000' <repeats 241 times>} OK, so thread 13 is waiting on conn 1370, sd 39. There are actually no error messages associated with this connection or socket anywhere in your logs. Likewise for thread 16: conn 1351, sd 20. No errors anywhere. This looks more like a problem with epoll() than anything else. Are the connections associated with socket 20 and 39 actually dead? > (gdb) thread 16 > [Switching to thread 16 (Thread 0x7f21f3fff700 (LWP 8467))]#0 pthread_cond_wait@@GLIBC_2.3.2 () > at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162 > 162 62: movl (%rsp), %edi > (gdb) frame 3 > #3 0x000000000043e716 in send_ldap_ber (op=0x7f21c8111140, ber=0x7f21f3e7d460) at result.c:379 > 379 ldap_pvt_thread_cond_wait( &conn->c_write2_cv, &conn->c_write2_mutex ); > (gdb) print *op > $3 = {o_hdr = 0x7f21c81112b0, o_tag = 99, o_time = 1356070283, o_tincr = 37, o_bd = 0x18217e0, o_req_dn = { > bv_len = 13, bv_val = 0x7f21d0001088 "dc=alu,dc=com"}, o_req_ndn = {bv_len = 13, > bv_val = 0x7f21d00010c0 "dc=alu,dc=com"}, o_request = {oq_add = {rs_modlist = 0x2, rs_e = 0xffffffffffffffff}, > oq_bind = {rb_method = 2, rb_cred = {bv_len = 18446744073709551615, bv_val = 0x0}, rb_edn = {bv_len = 0, > bv_val = 0x0}, rb_ssf = 3489665240, rb_mech = {bv_len = 15, bv_val = 0x7f21d00010f8 "(objectClass=*)"}}, > oq_compare = {rs_ava = 0x2}, oq_modify = {rs_mods = {rs_modlist = 0x2, rs_no_opattrs = -1 '\377'}, > rs_increment = 0}, oq_modrdn = {rs_mods = {rs_modlist = 0x2, rs_no_opattrs = -1 '\377'}, > rs_deleteoldrdn = 0, rs_newrdn = {bv_len = 0, bv_val = 0x0}, rs_nnewrdn = {bv_len = 139783200313560, > bv_val = 0xf <Address 0xf out of bounds>}, rs_newSup = 0x7f21d00010f8, rs_nnewSup = 0x0}, oq_search = { > rs_scope = 2, rs_deref = 0, rs_slimit = -1, rs_tlimit = -1, rs_limit = 0x0, rs_attrsonly = 0, > rs_attrs = 0x0, rs_filter = 0x7f21d00010d8, rs_filterstr = {bv_len = 15, > bv_val = 0x7f21d00010f8 "(objectClass=*)"}}, oq_abandon = {rs_msgid = 2}, oq_cancel = {rs_msgid = 2}, > oq_extended = {rs_reqoid = {bv_len = 2, > bv_val = 0xffffffffffffffff <Address 0xffffffffffffffff out of bounds>}, rs_flags = 0, rs_reqdata = 0x0}, > oq_pwdexop = {rs_extended = {rs_reqoid = {bv_len = 2, > bv_val = 0xffffffffffffffff <Address 0xffffffffffffffff out of bounds>}, rs_flags = 0, > rs_reqdata = 0x0}, rs_old = {bv_len = 0, bv_val = 0x7f21d00010d8 "\207"}, rs_new = {bv_len = 15, > bv_val = 0x7f21d00010f8 "(objectClass=*)"}, rs_mods = 0x0, rs_modtail = 0x0}}, o_abandon = 0, > o_cancel = 0, o_groups = 0x0, o_do_not_cache = 0 '\000', o_is_auth_check = 0 '\000', > o_dont_replicate = 0 '\000', o_acl_priv = ACL_NONE, o_nocaching = 0 '\000', o_delete_glue_parent = 0 '\000', > o_no_schema_check = 0 '\000', o_no_subordinate_glue = 0 '\000', o_ctrlflag = '\000' <repeats 31 times>, > o_controls = 0x7f21c81113f8, o_authz = {sai_method = 128, sai_mech = {bv_len = 0, bv_val = 0x0}, sai_dn = { > bv_len = 24, bv_val = 0x7f21a813ed50 "cn=manager,dc=alu,dc=com"}, sai_ndn = {bv_len = 24, > bv_val = 0x7f21a813ce90 "cn=manager,dc=alu,dc=com"}, sai_ssf = 0, sai_transport_ssf = 0, sai_tls_ssf = 0, > sai_sasl_ssf = 0}, o_ber = 0x7f21a813ecb0, o_res_ber = 0x0, o_callback = 0x0, o_ctrls = 0x0, o_csn = { > bv_len = 0, bv_val = 0x0}, o_private = 0x0, o_extra = {slh_first = 0x0}, o_next = {stqe_next = 0x7f21c4167f80}} > (gdb) print *op->o_hdr > $4 = {oh_opid = 4, oh_connid = 1351, oh_conn = 0x7f2210697570, oh_msgid = 5, oh_protocol = 3, > oh_tid = 139783804286720, oh_threadctx = 0x7f21f3ffea00, oh_tmpmemctx = 0x7f21d0000eb0, oh_tmpmfuncs = 0x839840, > oh_counters = 0x7f21d0000d80, oh_log_prefix = "conn=1351 op=4", '\000' <repeats 241 times>} > -- -- Howard Chu CTO, Symas Corp. http://www.symas.com Director, Highland Sun http://highlandsun.com/hyc/ Chief Architect, OpenLDAP http://www.openldap.org/project/

1 0

Re: slapd deadlock bug ITS#7296
by Howard Chu 20 Dec '12

20 Dec '12

Richard Silverman wrote: > On Thu, 20 Dec 2012, Howard Chu wrote: > >> Please post the entire stack trace for all threads. Since we have >> c_writers = 8, c_writing = 1, c_writewaiter = 1 >> >> then one of the threads ought to be blocked on the write2_cv (result.c:373). >> That implies that they're still waiting for epoll() to say that the socket is >> writable. > > Sure; here is a dump of the stacks of all 18 executing threads: > [Switching to thread 2 (Thread 0x7f21de7fc700 (LWP 8482))]#0 pthread_cond_wait@@GLIBC_2.3.2 () > at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162 > 162 62: movl (%rsp), %edi > #0 pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162 > #1 0x000000000056926e in ldap_int_thread_cond_wait (cond=0x7f2210697720, mutex=0x7f22106976d0) at thr_posix.c:277 > #2 0x000000000056b1c2 in ldap_pvt_thread_cond_wait (cond=0x7f2210697720, mutex=0x7f22106976d0) at thr_debug.c:954 > #3 0x000000000043e487 in send_ldap_ber (op=0x7f21e0140260, ber=0x7f21de67a460) at result.c:309 > #4 0x000000000044160b in slap_send_search_entry (op=0x7f21e0140260, rs=0x7f21de7fb920) at result.c:1435 > #5 0x00000000004c5c27 in bdb_search (op=0x7f21e0140260, rs=0x7f21de7fb920) at search.c:1014 > #6 0x000000000042dd6a in fe_op_search (op=0x7f21e0140260, rs=0x7f21de7fb920) at search.c:402 > #7 0x000000000042d5ae in do_search (op=0x7f21e0140260, rs=0x7f21de7fb920) at search.c:247 > #8 0x000000000042a776 in connection_operation (ctx=0x7f21de7fba00, arg_v=0x7f21e0140260) at connection.c:1218 > #9 0x0000000000567cc7 in ldap_int_thread_pool_wrapper (xpool=0x17f0e90) at tpool.c:688 > #10 0x000000000056a767 in ldap_debug_thread_wrapper (arg=0x7f21ec136ad0) at thr_debug.c:770 > #11 0x00000039e3407851 in start_thread (arg=0x7f21de7fc700) at pthread_create.c:301 > #12 0x00000039e2ce811d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115 OK, most of the threads look like thread 2. Thread 13 and thread 16 are waiting for their respective sockets to be writable. > [Switching to thread 13 (Thread 0x7f21f27fc700 (LWP 8470))]#0 pthread_cond_wait@@GLIBC_2.3.2 () > at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162 > 162 62: movl (%rsp), %edi > #0 pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162 > #1 0x000000000056926e in ldap_int_thread_cond_wait (cond=0x7f221069b9a8, mutex=0x7f221069b958) at thr_posix.c:277 > #2 0x000000000056b1c2 in ldap_pvt_thread_cond_wait (cond=0x7f221069b9a8, mutex=0x7f221069b958) at thr_debug.c:954 > #3 0x000000000043e716 in send_ldap_ber (op=0x7f21cc191420, ber=0x7f21f267a460) at result.c:379 > #4 0x000000000044160b in slap_send_search_entry (op=0x7f21cc191420, rs=0x7f21f27fb920) at result.c:1435 > #5 0x00000000004c5c27 in bdb_search (op=0x7f21cc191420, rs=0x7f21f27fb920) at search.c:1014 > #6 0x000000000042dd6a in fe_op_search (op=0x7f21cc191420, rs=0x7f21f27fb920) at search.c:402 > #7 0x000000000042d5ae in do_search (op=0x7f21cc191420, rs=0x7f21f27fb920) at search.c:247 > #8 0x000000000042a776 in connection_operation (ctx=0x7f21f27fba00, arg_v=0x7f21cc191420) at connection.c:1218 > #9 0x0000000000567cc7 in ldap_int_thread_pool_wrapper (xpool=0x17f0e90) at tpool.c:688 > #10 0x000000000056a767 in ldap_debug_thread_wrapper (arg=0x7f21f4000f20) at thr_debug.c:770 > #11 0x00000039e3407851 in start_thread (arg=0x7f21f27fc700) at pthread_create.c:301 > #12 0x00000039e2ce811d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115 > [Switching to thread 16 (Thread 0x7f21f3fff700 (LWP 8467))]#0 pthread_cond_wait@@GLIBC_2.3.2 () > at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162 > 162 62: movl (%rsp), %edi > #0 pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162 > #1 0x000000000056926e in ldap_int_thread_cond_wait (cond=0x7f22106977c0, mutex=0x7f2210697770) at thr_posix.c:277 > #2 0x000000000056b1c2 in ldap_pvt_thread_cond_wait (cond=0x7f22106977c0, mutex=0x7f2210697770) at thr_debug.c:954 > #3 0x000000000043e716 in send_ldap_ber (op=0x7f21c8111140, ber=0x7f21f3e7d460) at result.c:379 > #4 0x000000000044160b in slap_send_search_entry (op=0x7f21c8111140, rs=0x7f21f3ffe920) at result.c:1435 > #5 0x00000000004c5c27 in bdb_search (op=0x7f21c8111140, rs=0x7f21f3ffe920) at search.c:1014 > #6 0x000000000042dd6a in fe_op_search (op=0x7f21c8111140, rs=0x7f21f3ffe920) at search.c:402 > #7 0x000000000042d5ae in do_search (op=0x7f21c8111140, rs=0x7f21f3ffe920) at search.c:247 > #8 0x000000000042a776 in connection_operation (ctx=0x7f21f3ffea00, arg_v=0x7f21c8111140) at connection.c:1218 > #9 0x0000000000567cc7 in ldap_int_thread_pool_wrapper (xpool=0x17f0e90) at tpool.c:688 > #10 0x000000000056a767 in ldap_debug_thread_wrapper (arg=0x7f21f4000a60) at thr_debug.c:770 > #11 0x00000039e3407851 in start_thread (arg=0x7f21f3fff700) at pthread_create.c:301 > #12 0x00000039e2ce811d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115 So the question is why are these threads still waiting on their sockets. Looking at your logs, it's clear that the error occurs and connection_closing() is called, which will call connection_abandon() to set the o_abandon flag on all of the connection's ops. Can you please provide the output for "print *op" and "print *op->o_hdr" in thread 13 and thread 16, frame 3? -- -- Howard Chu CTO, Symas Corp. http://www.symas.com Director, Highland Sun http://highlandsun.com/hyc/ Chief Architect, OpenLDAP http://www.openldap.org/project/

1 0

Re: slapd deadlock bug ITS#7296
by Howard Chu 20 Dec '12

20 Dec '12

Richard Silverman wrote: > As for the rest of the conversation: your insulting and snarky comments > like “use grep” and “you haven’t read enough” have killed any interest I had in it. Let’s just restrict ourselves to something you presumably *are* interested in: fixing this showstopper bug which locks up your entire server if just a few client TCP connections fail in a particular way. I will be happy to provide more information on reproducing the problem, if you need it. In case you hadn't noticed, I've been investigating and trying to help you. "Use grep" is nothing more than standard practice for a C programmer. it is what it is, you're reading an attitude into it that doesn't exist. -- -- Howard Chu CTO, Symas Corp. http://www.symas.com Director, Highland Sun http://highlandsun.com/hyc/ Chief Architect, OpenLDAP http://www.openldap.org/project/

1 0

slapd deadlock bug ITS#7296
by Richard Silverman 20 Dec '12

20 Dec '12

Hello, I’m working on this bug: http://www.openldap.org/lists/openldap-bugs/201206/msg00026.html If slapd client connections are torn down in mid-query -- the server has received the query and has a pending reply to send, but the connection is closed by the client before it can be sent -- this deadlocks slapd worker threads. Eventually all threads are deadlocked in send_ldap_ber() which serializes their network access to send PDUs, and the server becomes unresponsive and has to be killed. send_ldap_ber() notices the connection drop and calls connection_closing(). The problem appears to be that then connection_abandon() abandons all outstanding executing ops, but does not empty the c_ops queue (as it does with c_pending_ops). When connection_close() looks at the connection, it always sees there are outstanding ops and defers the close. I see this pattern: 50cb3104 connection_closing: readying conn=1519 sd=33 for close 50cb3104 connection_close: deferring conn=1519 sd=33 50cb3104 connection_resched: attempting closing conn=1519 sd=33 50cb3104 connection_close: deferring conn=1519 sd=33 50cb3104 connection_resched: attempting closing conn=1519 sd=33 ... which repeats until the server freezes entirely. If I add code to connection_abandon() to empty c_ops, it causes slapd to crash later with a mutex usage error, so that's apparently not the right place/way to do it. If I note that the connection is dying and have connection_destroy() skip the assertion that c_ops must be empty, it fixes the bug: the deadlock no longer occurs. However, I'm concerned this will leak memory as the ops aren't being freed. So my question is: what's the right way to get the outstanding executing ops abandoned by connection_abandon() to be freed? The code is complex and I may have misunderstood how best to go about fixing this, but hopefully this is enough to make sense. Thanks, -- Richard E. Silverman

2 4

Re: slapd deadlock bug ITS#7296
by Howard Chu 20 Dec '12

20 Dec '12

Richard Silverman wrote: > On Thu, 20 Dec 2012, Howard Chu wrote: > >> It would probably be helpful for you to post your test code as well so other >> developers can use it to reproduce the issue. > > As I said in the paragraph you quoted just above, I’m using the test code > provided in the referenced bug report. It required only minimal obvious > tweaking to get it to work. I can provide a tarball of my own setup if > that would be helpful. Hm, I missed the link to attachments in the original ITS. I see it now. >>> The problem is that they are *all* here; there is no one left to signal >>> that condition variable, so slapd locks up forever. >> >> The previously quoted code clearly sets conn->c_writing to 0 if a hard error >> occurs. What are the values in *conn when this hang happens? Also, when a connection error is detected, if you had CONNS debug enabled, there would be an error message to this effect. Have you enabled connection debug output, and do you see these messages in the slapd debug output right before the hang? > Yes, it does do that; nevertheless, conn->c_writing == 1 in all threads > when the deadlock occurs. > >> Which thread owns the write1 mutex at that point? > > I don’t know how to determine that. Here’s a dump of *conn in one of the > threads: > > $21 = {c_struct_state = SLAP_C_USED, c_conn_state = SLAP_C_ACTIVE, c_conn_idx = 39, c_sd = 39, > c_close_reason = 0x5add3b "?", c_mutex = {wrapped = {__data = {__lock = 0, __count = 0, __owner = 0, > __nusers = 0, __kind = 2, __spins = 0, __list = {__prev = 0x0, __next = 0x0}}, > __size = '\000' <repeats 16 times>, "\002", '\000' <repeats 22 times>, __align = 0}, usage = { > magic = ldap_debug_magic, self = 18446603377522038887, mem = {ptr = 0x0, num = 0}, > state = ldap_debug_state_inited}, owner = 18446744073709551615}, c_sb = 0x7ff5f0114c30, > c_starttime = 1356066580, c_activitytime = 1356066580, c_connid = 1370, c_peer_domain = {bv_len = 7, > bv_val = 0x7ff630001140 "unknown"}, c_peer_name = {bv_len = 18, bv_val = 0x7ff630001120 "IP=127.0.0.1:42441"}, > c_listener = 0x1325390, c_sasl_bind_mech = {bv_len = 0, bv_val = 0x0}, c_sasl_dn = {bv_len = 0, bv_val = 0x0}, > c_sasl_authz_dn = {bv_len = 0, bv_val = 0x0}, c_authz_backend = 0x13767e0, c_authz_cookie = 0x0, c_authz = { > sai_method = 128, sai_mech = {bv_len = 0, bv_val = 0x0}, sai_dn = {bv_len = 24, > bv_val = 0x7ff624111980 "cn=manager,dc=alu,dc=com"}, sai_ndn = {bv_len = 24, > bv_val = 0x7ff6241086c0 "cn=manager,dc=alu,dc=com"}, sai_ssf = 0, sai_transport_ssf = 0, sai_tls_ssf = 0, > sai_sasl_ssf = 0}, c_protocol = 3, c_ops = {stqh_first = 0x7ff62813db60, stqh_last = 0x7ff6241108c8}, > c_pending_ops = {stqh_first = 0x7ff6240020c0, stqh_last = 0x7ff624139028}, c_write1_mutex = {wrapped = { > __data = {__lock = 0, __count = 0, __owner = 0, __nusers = 7, __kind = 2, __spins = 0, __list = { > __prev = 0x0, __next = 0x0}}, c_write1_mutex owner=0, which means nobody owns it currently. >> As for the rest - "reverse engineering" would be something like taking a >> compiled binary and trying to decompile it. Reading source code is simply >> that, it's not reverse engineering. > > This is a matter of definition. To me, reverse engineering is when you > take insufficiently commented code and try to divine the organizing > principles behind it; it doesn’t matter if the code you’re looking at it > is machine code, assembly, or C (and I’ve done plenty of all of those). > >> The variables are documented with their purpose and usage, the comments >> show what a block of code aims to do. What more do you expect? > > Perhaps I have missed some documentation. What would help here is some > high-level description of the various synchronization primitives involved, > their consumers, what critical regions they aim to protect and how their > usage is supposed to avoid deadlock, along with detailed comments to that > effect. Here are some examples. This code in send_ldap_ber(): > > conn->c_writers++; > > while ( conn->c_writers > 0 && conn->c_writing ) { > ldap_pvt_thread_cond_wait( &conn->c_write1_cv, &conn->c_write1_mutex ); > } > > /* connection was closed under us */ > if ( conn->c_writers < 0 ) { > /* we're the last waiter, let the closer continue */ > if ( conn->c_writers == -1 ) > ldap_pvt_thread_cond_signal( &conn->c_write1_cv ); > conn->c_writers++; > ldap_pvt_thread_mutex_unlock( &conn->c_write1_mutex ); > return 0; > } > > There are almost no comments here. conn->c_writers is mysteriously > incremented, perhaps to indicate that we are now intending to write? slap.h c_writers /* number of writers waiting */ > But > then this thread blocks waiting for it to become <= 0. Why would it do > that after we incremented it, when other threads will presumably only > decrement if they had previously incremented it? Use grep. > We are signalling > c_write1_cv; who is waiting on it? Use grep. > Why will waking them up help? The next > section refers to magic numbers 0 and -1 with important implications such > as our being the “last waiter,” without explaining why that would be so, /* connection was closed under us */ is the explanation. > again silently increments conn->c_writers (why when we already did that?), The c_writers is now negative, obviously. The increment is moving it toward zero. > signals a condition variable and unlocks a mutex without mentioning the > purpose of doing so, and returns 0 without saying what the effect of that > should be. > > I can make lots of guesses as to what might be going on here, but that’s > all: guesses, along with lots of experimentation to figure out what’s > missing, and that is reverse engineering. The entire code base is at your fingertips. If you're making guesses then you just haven't read enough. -- -- Howard Chu CTO, Symas Corp. http://www.symas.com Director, Highland Sun http://highlandsun.com/hyc/ Chief Architect, OpenLDAP http://www.openldap.org/project/

1 0

make check: slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49)
by John Smith 20 Dec '12

20 Dec '12

Hi, When running 'make check' of openldap-2.4.33, I get a lot of these type of errors: "slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49)" for test 'test008-concurrency'. I have build openldap with '--with-cyrus-sasl'. Could something be wrong with the test script, or is there something wrong with my build ? Regards, John Smith. ------------------------------------------------------------------------------------------------------------------------------------ >>>>> Starting test008-concurrency for mdb... running defines.sh Running slapadd to build slapd database... Starting slapd on TCP/IP port 9011... Using ldapsearch to check that slapd is running... MONITORDB yes SRCDIR ./testdata DSTDIR /usr/local/src/openldap/openldap-2.4.33/tests/testrun pwd /usr/local/src/openldap/openldap-2.4.33/tests Using tester for concurrent server access... PID=10668 - Search(500): base="dc=example,dc=com" scope=sub filter="(cn=Bjorn Jensen)" attrs=cn (more...). PID=10650 - Search(500): base="dc=example,dc=com" scope=sub filter="(cn=Barbara Jensen)" attrs=cn (more...). PID=10655 - Bind(1000): dn="cn=Barbara Jensen,ou=Information Technology Division,ou=People,dc=example,dc=com". PID=10661 - Bind(1000): dn="cn=Bjorn Jensen,ou=Information Technology Division,ou=People,dc=example,dc=com". PID=10657 - Read(1000): entry="cn=ITD Staff,ou=Groups,dc=example,dc=com". PID=10663 - Read(1000): entry="ou=Groups, dc=example,dc=com". PID=10669 - Read(1000): entry="ou=Alumni Association, ou=People, dc=example,dc=com". PID=10666 - Add/Delete(50): entry="cn=James A Jones 5,dc=example,dc=com". PID=10659 - Modify(50): entry="cn=Bjorn Jensen,ou=Information Technology Division,ou=People,dc=example,dc=com". PID=10662 - Search(500): base="ou=people,dc=example,dc=com" scope=sub filter="(cn=James A Jones 1)" attrs=cn (more...). PID=10653 - Modify(50): entry="cn=Barbara Jensen,ou=Information Technology Division,ou=People,dc=example,dc=com". PID=10664 - Modrdn(50): entry="cn=Ursula Hampster,ou=Alumni Association,ou=People,dc=example,dc=com". PID=10651 - Read(1000): entry="cn=Barbara Jensen,ou=Information Technology Division,ou=People,dc=example,dc=com". PID=10658 - Modrdn(50): entry="cn=John Doe,ou=Information Technology Division,ou=People,dc=example,dc=com". PID=10652 - Modrdn(50): entry="cn=Dorothy Stevens,ou=Alumni Association,ou=People,dc=example,dc=com". PID=10660 - Add/Delete(50): entry="cn=James A Jones 2,ou=Alumni Association,ou=People,dc=example,dc=com". PID=10654 - Add/Delete(50): entry="cn=James A Jones 3,ou=Alumni Association,ou=People,dc=example,dc=com". PID=10665 - Modify(50): entry="cn=James A Jones 1,ou=Alumni Association,ou=People,dc=example,dc=com". PID=10656 - Search(500): base="ou=people,dc=example,dc=com" scope=sub filter="(cn=Bjorn Jensen)" attrs=cn (more...). PID=10667 - Bind(1000): base="ou=People,dc=example,dc=com", filter="(userPassword=*)" attr="userPassword". PID=10667 - Bind base="ou=People,dc=example,dc=com" filter="(userPassword=*)" got 3 values. PID=10662 - Search done (0). PID=10684 - Modrdn(50): entry="cn=James A Jones 2,ou=Information Technology Division,ou=People,dc=example,dc=com". PID=10668 - Search done (0). PID=10685 - Modify(50): entry="cn=ITD Staff,ou=Groups,dc=example,dc=com". PID=10656 - Search done (0). PID=10686 - Add/Delete(50): entry="cn=James A Jones 4,ou=People,dc=example,dc=com". PID=10650 - Search done (0). PID=10687 - Bind(1000): dn="cn=Barbara Jensen,ou=Information Technology Division,ou=People,dc=example,dc=com". PID=10667 - Bind done 1000 in 15.904214 seconds. PID=10688 - Search(500): base="dc=example,dc=com" scope=sub filter="(cn=Alumni Assoc Staff)" attrs=cn (more...). PID=10655 - Bind done (0). PID=10689 - Read(1000): entry="cn=James A Jones 1, ou=Alumni Association, ou=People, dc=example,dc=com". PID=10661 - Bind done (0). PID=10690 - Bind(1000): dn="cn=Bjorn Jensen,ou=Information Technology Division,ou=People,dc=example,dc=com". PID=10659 - Modify done (0). PID=10691 - Search(500): base="dc=example,dc=com" scope=sub filter="(cn=James*)" attrs=cn (more...). PID=10657 - Read done (0). PID=10692 - Read(1000): entry="cn=Backend 1,cn=Backends,cn=Monitor". PID=10664 - Modrdn done (0). PID=10693 - Bind(1000): base="ou=People,dc=example,dc=com", filter="(userPassword=*)" attr="userPassword". PID=10693 - Bind base="ou=People,dc=example,dc=com" filter="(userPassword=*)" got 4 values. PID=10669 - Read done (0). PID=10694 - Search(500): base="cn=Monitor" scope=sub filter="(objectClass=*)" attrs=cn (more...). PID=10652 - Modrdn done (0). PID=10658 - Modrdn done (0). PID=10696 - Bind(1000): dn="cn=Barbara Jensen,ou=Information Technology Division,ou=People,dc=example,dc=com". PID=10695 - Read(1000): entry="cn=Entries,cn=Statistics,cn=Monitor". PID=10651 - Read done (0). PID=10663 - Read done (0). slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) PID=10665 - Modify done (0). PID=10698 - Read(1000): entry="cn=Database 1,cn=Databases,cn=Monitor". PID=10653 - Modify done (0). PID=10699 - Bind(1000): dn="cn=Bjorn Jensen,ou=Information Technology Division,ou=People,dc=example,dc=com". PID=10697 - Search(500): base="cn=Monitor" scope=sub filter="(objectClass=*)" attrs=cn (more...). PID=10700 - Search(500): base="cn=Monitor" scope=sub filter="(objectClass=*)" attrs=cn (more...). slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) PID=10654 - Add/Delete done (0). PID=10701 - Read(1000): entry="cn=Barbara Jensen,ou=Information Technology Division,ou=People,dc=example,dc=com". PID=10666 - Add/Delete done (0). PID=10702 - Bind(1000): base="ou=People,dc=example,dc=com", filter="(userPassword=*)" attr="userPassword". PID=10702 - Bind base="ou=People,dc=example,dc=com" filter="(userPassword=*)" got 4 values. slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) PID=10660 - Add/Delete done (0). PID=10703 - Search(500): base="cn=Monitor" scope=sub filter="(objectClass=*)" attrs=cn (more...). slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) PID=10684 - Modrdn done (0). PID=10704 - Read(1000): entry="cn=ITD Staff,ou=Groups,dc=example,dc=com". slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) PID=10685 - Modify done (0). slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) PID=10705 - Bind(1000): dn="cn=Barbara Jensen,ou=Information Technology Division,ou=People,dc=example,dc=com". slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) PID=10686 - Add/Delete done (0). slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) PID=10706 - Search(500): base="dc=example,dc=com" scope=sub filter="(cn=Barbara Jensen)" attrs=cn (more...). slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) PID=10688 - Search done (0). PID=10707 - Read(1000): entry="ou=Groups, dc=example,dc=com". slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) PID=10687 - Bind done (0). slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) PID=10708 - Bind(1000): dn="cn=Bjorn Jensen,ou=Information Technology Division,ou=People,dc=example,dc=com". slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) PID=10691 - Search done (0). PID=10709 - Search(500): base="ou=people,dc=example,dc=com" scope=sub filter="(cn=Bjorn Jensen)" attrs=cn (more...). slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) PID=10690 - Bind done (0). slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) PID=10710 - Read(1000): entry="ou=Alumni Association, ou=People, dc=example,dc=com". slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) PID=10689 - Read done (0). slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) PID=10711 - Bind(1000): base="ou=People,dc=example,dc=com", filter="(userPassword=*)" attr="userPassword". slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) PID=10711 - Bind base="ou=People,dc=example,dc=com" filter="(userPassword=*)" got 3 values. slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) PID=10706 - Search done (0). PID=10712 - Search(500): base="ou=people,dc=example,dc=com" scope=sub filter="(cn=James A Jones 1)" attrs=cn (more...). slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) PID=10699 - Bind done (0). PID=10713 - Read(1000): entry="cn=James A Jones 1, ou=Alumni Association, ou=People, dc=example,dc=com". slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) PID=10698 - Read done (0). slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) PID=10714 - Bind(1000): dn="cn=Barbara Jensen,ou=Information Technology Division,ou=People,dc=example,dc=com". slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) PID=10692 - Read done (0). slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) PID=10715 - Search(500): base="dc=example,dc=com" scope=sub filter="(cn=Bjorn Jensen)" attrs=cn (more...). slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) PID=10696 - Bind done (0). PID=10716 - Read(1000): entry="cn=Backend 1,cn=Backends,cn=Monitor". slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10702: ldap_sasl_bind_s: Invalid credentials (49) PID=10702 - Bind done 1000 in 20.179235 seconds. slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) PID=10717 - Bind(1000): dn="cn=Bjorn Jensen,ou=Information Technology Division,ou=People,dc=example,dc=com". slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) slapd-bind PID=10693: ldap_sasl_bind_s: Invalid credentials (49) PID=10693 - Bind done 1000 in 22.158312 seconds. PID=10718 - Search(500): base="dc=example,dc=com" scope=sub filter="(cn=Alumni Assoc Staff)" attrs=cn (more...). PID=10695 - Read done (0). PID=10719 - Read(1000): entry="cn=Entries,cn=Statistics,cn=Monitor". PID=10701 - Read done (0). PID=10720 - Bind(1000): base="ou=People,dc=example,dc=com", filter="(userPassword=*)" attr="userPassword". PID=10720 - Bind base="ou=People,dc=example,dc=com" filter="(userPassword=*)" got 3 values. PID=10704 - Read done (0). PID=10721 - Search(500): base="dc=example,dc=com" scope=sub filter="(cn=James*)" attrs=cn (more...). PID=10709 - Search done (0). PID=10722 - Read(1000): entry="cn=Database 1,cn=Databases,cn=Monitor". PID=10705 - Bind done (0). PID=10723 - Bind(1000): dn="cn=Barbara Jensen,ou=Information Technology Division,ou=People,dc=example,dc=com". PID=10708 - Bind done (0). PID=10724 - Search(500): base="cn=Monitor" scope=sub filter="(objectClass=*)" attrs=cn (more...). PID=10707 - Read done (0). PID=10725 - Read(1000): entry="cn=Barbara Jensen,ou=Information Technology Division,ou=People,dc=example,dc=com". PID=10712 - Search done (0). PID=10726 - Bind(1000): dn="cn=Bjorn Jensen,ou=Information Technology Division,ou=People,dc=example,dc=com". PID=10718 - Search done (0). PID=10715 - Search done (0). PID=10727 - Search(500): base="cn=Monitor" scope=sub filter="(objectClass=*)" attrs=cn (more...). PID=10728 - Read(1000): entry="cn=ITD Staff,ou=Groups,dc=example,dc=com". PID=10714 - Bind done (0). PID=10729 - Bind(1000): base="ou=People,dc=example,dc=com", filter="(userPassword=*)" attr="userPassword". PID=10729 - Bind base="ou=People,dc=example,dc=com" filter="(userPassword=*)" got 3 values. PID=10711 - Bind done 1000 in 18.610251 seconds. PID=10730 - Search(500): base="cn=Monitor" scope=sub filter="(objectClass=*)" attrs=cn (more...). PID=10710 - Read done (0). PID=10731 - Read(1000): entry="ou=Groups, dc=example,dc=com". PID=10721 - Search done (0). PID=10732 - Bind(1000): dn="cn=Barbara Jensen,ou=Information Technology Division,ou=People,dc=example,dc=com". PID=10720 - Bind done 1000 in 17.321421 seconds. PID=10733 - Search(500): base="cn=Monitor" scope=sub filter="(objectClass=*)" attrs=cn (more...). PID=10717 - Bind done (0). PID=10734 - Read(1000): entry="ou=Alumni Association, ou=People, dc=example,dc=com". PID=10716 - Read done (0). PID=10735 - Bind(1000): dn="cn=Bjorn Jensen,ou=Information Technology Division,ou=People,dc=example,dc=com". PID=10713 - Read done (0). PID=10719 - Read done (0). PID=10723 - Bind done (0). PID=10726 - Bind done (0). PID=10722 - Read done (0). PID=10728 - Read done (0). PID=10725 - Read done (0). PID=10729 - Bind done 1000 in 13.882164 seconds. PID=10735 - Bind done (0). PID=10734 - Read done (0). PID=10732 - Bind done (0). PID=10731 - Read done (0). PID=10700 - Search done (0). PID=10694 - Search done (0). PID=10703 - Search done (0). PID=10697 - Search done (0). PID=10724 - Search done (0). PID=10727 - Search done (0). PID=10733 - Search done (0). PID=10730 - Search done (0). real 2m5.220s user 0m1.511s sys 0m23.731s Using ldapsearch to retrieve all the entries... Filtering ldapsearch results... Filtering original ldif used to create database... Comparing filter output... >>>>> Test succeeded >>>>> test008-concurrency completed OK for mdb.

2 1

RE24 Testing call #1 (OpenLDAP 2.4.34)
by Quanah Gibson-Mount 16 Dec '12

16 Dec '12

Current RE24 is ready for testing for the 2.4.34 release. Thanks! --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

3 2

Re: openldap.git branch mdb.master updated. 0ce6bb4be0034120c850917bc4f59b4d4efc1432
by Hallvard Breien Furuseth 15 Dec '12

15 Dec '12

openldap-commit2devel(a)OpenLDAP.org writes: > commit aff2693fc0721df4ccb6ceb357f80501c413ed38 > Author: Howard Chu <hyc(a)symas.com> > Date: Mon Dec 10 12:16:50 2012 -0800 > > ITS#7455 simplify > > Don't try to reclaim overflow pages while operating on > the freelist (for now). The circular dependencies are much like > the single-page case, but worse. Maybe look into this in the > future, but it's not absolutely necessary now. Suggestions to reduce freelist changes during commit: Let a freelist entry steal page numbers listed in the next entries. Then mdb_page_alloc can grab more old pages without deleting/updating their entries and producing new dirty pages. Next txn does the updates. Preallocate the final MDB_oldpages with MDB_RESERVE in mdb_txn_commit() and leave some room to spare. Then use page numbers from it and/or steal new ones at need. BTW, could MDB offer an MDB_RESERVE2 which says "give me data->mv_size bytes plus as much more as will fit without growing the page"? And MDB_RESERVE2_SHRINK which shrinks the size to the final size. Stolen pages -- one way would be to search for particular pages to seal, and list the stolen ones at the end of the freelist entry. Or: Stealing only from the end of the previous entry/entries should be simpler, but doesn't let us choose some specific pages to steal in order to gain a big enough contiguous page range: typedef struct MDB_freelist_entry { /* freelist entry in the DB */ short mf_len; /* saved length */ short mf_stolen_entries; /* #fully stolen entries */ short mf_nextlen; /* 0 or remaining length of next entry */ MDB_ID mf_pages[]; /* length mf_len. */ } MDB_freelist_entry; Thus, if the free DB contains (txnid_t)123 => { .mf_stolen_entries = 1, .mf_nextlen = 7 } (txnid_t)124 => { ... } (txnid_t)125 => { .mf_len = 20 } then mdb should henceforth skip entry#124 and entry#125.mf_pages[7..19]. A simple variant of page ranges, to save space and simplify range handling: /* Page range: (pagecount << MDB_PGNO_BITS) | (pageno + pagecount) */ typedef pgno_t mdb_pages_t; Lone pages get pagecount=1. With MDB_PGCOUNT_BITS = (64bit 4 ? 19 : 12) and page size 4096, that limits MDB to a 128 petabyte DB and 2G entry size. Or 4G database and 16M entry size on 32-bit machines. (I'd call limiting the entry size a bonus compared to today's mdb: The current freelist doesn't exactly handle 2 billion freed pages gracefully.) -- Hallvard

1 2

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

2010

2009

2008

2007

2006

openldap-devel December 2012