(ITS#6034) Assert failure - connection_state_closing / send_ldap_ber / slap_send_search_entry / syncprov_sendresp

[oskar@deckle.co.za]

Full_Name: Oskar Pearson
Version: 2.4.15
OS: Ubuntu hardy
URL: ftp://ftp.openldap.org/incoming/slapd-configs-qualica-1.tar.gz
Submission from: (NULL) (94.194.140.71)


This is the same machine as ITS #6033. Details included here for easy
reference:

Openldap 2.4.15 (with no patches) was self-compiled with no patches
(CFLAGS="-ggdb3 -O0" ./configure), linked against standard OS libraries (ubuntu
hardy) for BDB etc. BDB is 4.6.21-6ubuntu1. Kernel is 2.6.24-19-server, libc is
libc6-i686/2.7-10ubuntu3.

I do not have a debug log of this crash as it occurred on a live server, which
is too busy for that level of logging. I also do not have a replaceable
example.
I have core dumps and can print out whatever is necessary there - I appreciate
your time and help.

If I've missed some important info, please let me know and I'll rectify asap.

System overview:

We have a master server which replicates to > 100 machines for Samba purposes
across ADSL lines with a VPN. These lines are quite busy, so replication writes
may be slow across the network, which may have implications for locks.

Config files are included at the url below.

gdb --core=../core.29266 --directory=servers/slapd/
--directory=servers/slapd/overlays  servers/slapd/slapd
(gdb) bt
#0  0xb7ef8410 in __kernel_vsyscall ()
#1  0xb7ad5085 in raise () from /lib/tls/i686/cmov/libc.so.6
#2  0xb7ad6a01 in abort () from /lib/tls/i686/cmov/libc.so.6
#3  0xb7ace10e in __assert_fail () from /lib/tls/i686/cmov/libc.so.6
#4  0x0806d6c6 in connection_state_closing (c=0xb79c9644) at connection.c:686
#5  0x08081bdd in send_ldap_ber (conn=0xb79c9644, ber=0xa143ab8c) at
result.c:147
#6  0x08085b20 in slap_send_search_entry (op=0xa143ae38, rs=0xa143acdc) at
result.c:1246
#7  0x0815dbcb in syncprov_sendresp (op=0xa143ae38, opc=0xa143adb8,
so=0x9ab66dc8, e=0xa143ade8, mode=1) at syncprov.c:825
#8  0x0815df12 in syncprov_qplay (op=0xa143ae38, rtask=0x9b303110) at
syncprov.c:896
#9  0x0815e1a7 in syncprov_qtask (ctx=0xa143b1f0, arg=0x9b303110) at
syncprov.c:959
#10 0x0817a99b in ldap_int_thread_pool_wrapper (xpool=0x829baf0) at tpool.c:663
#11 0xb7db14fb in start_thread () from /lib/tls/i686/cmov/libpthread.so.0
#12 0xb7b80e5e in clone () from /lib/tls/i686/cmov/libc.so.6

(gdb) frame 4
#4  0x0806d6c6 in connection_state_closing (c=0xb79c9644) at connection.c:686
686             assert( c->c_struct_state == SLAP_C_USED );
(gdb) p c->c_struct_state
$1 = 1 # maps to SLAP_C_UNUSED
(gdb) p *c
$4 = {c_struct_state = 1, c_conn_state = 0, c_conn_idx = 107, c_sd = -1,
c_close_reason = 0x81b647b "?", c_mutex = {__data = {__lock = 0, __count = 0, 
      __owner = 0, __kind = 0, __nusers = 0, {__spins = 0, __list = {__next =
0x0}}}, __size = '\0' <repeats 23 times>, __align = 0}, c_sb = 0x838c1b8, 
  c_starttime = 0, c_activitytime = 0, c_connid = 4294967295, c_peer_domain =
{bv_len = 0, bv_val = 0x0}, c_peer_name = {bv_len = 0, bv_val = 0x0}, 
  c_listener = 0x0, 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 = 0x0, c_authz_cookie = 0x0, c_authz = {sai_method = 128,
sai_mech = {bv_len = 0, bv_val = 0x0}, sai_dn = {bv_len = 0, bv_val = 0x0}, 
    sai_ndn = {bv_len = 0, bv_val = 0x0}, sai_ssf = 0, sai_transport_ssf = 0,
sai_tls_ssf = 0, sai_sasl_ssf = 0}, c_protocol = 0, c_ops = {
    stqh_first = 0x0, stqh_last = 0xb79c96e4}, c_pending_ops = {stqh_first =
0x0, stqh_last = 0xb79c96ec}, c_write1_mutex = {__data = {__lock = 1, 
      __count = 0, __owner = 29297, __kind = 0, __nusers = 1, {__spins = 0,
__list = {__next = 0x0}}}, 
    __size = "\001\000\000\000\000\000\000\000qr\000\000\000\000\000\000\001\000\000\000\000\000\000",
__align = 1}, c_write1_cv = {__data = {__lock = 0, 
      __futex = 0, __total_seq = 0, __wakeup_seq = 0, __woken_seq = 0, __mutex =
0x0, __nwaiters = 0, __broadcast_seq = 0}, 
    __size = '\0' <repeats 47 times>, __align = 0}, c_write2_mutex = {__data =
{__lock = 0, __count = 0, __owner = 0, __kind = 0, __nusers = 0, {
        __spins = 0, __list = {__next = 0x0}}}, __size = '\0' <repeats 23
times>, __align = 0}, c_write2_cv = {__data = {__lock = 0, __futex = 0, 
      __total_seq = 0, __wakeup_seq = 0, __woken_seq = 0, __mutex = 0x0,
__nwaiters = 0, __broadcast_seq = 0}, __size = '\0' <repeats 47 times>, 
    __align = 0}, c_currentber = 0x0, c_writers = 0, c_sasl_bind_in_progress = 0
'\0', c_writewaiter = 0 '\0', c_is_tls = 0 '\0', 
  c_needs_tls_accept = 0 '\0', c_sasl_layers = 0 '\0', c_sasl_done = 0 '\0',
c_sasl_authctx = 0x0, c_sasl_sockctx = 0x0, c_sasl_extra = 0x0, 
  c_sasl_bindop = 0x0, c_pagedresults_state = {ps_be = 0x0, ps_size = 0,
ps_count = 0, ps_cookie = 0, ps_cookieval = {bv_len = 0, bv_val = 0x0}}, 
  c_n_ops_received = 2, c_n_ops_executing = 0, c_n_ops_pending = 0,
c_n_ops_completed = 2, c_n_get = 3, c_n_read = 2, c_n_write = 0, c_extensions =
0x0, 
  c_clientfunc = 0, c_clientarg = 0x0, c_send_ldap_result = 0x8082e44
<slap_send_ldap_result>, c_send_search_entry = 0x8083b12
<slap_send_search_entry>, 
  c_send_search_reference = 0x8085e4b <slap_send_search_reference>,
c_send_ldap_extended = 0x8083676 <slap_send_ldap_extended>, 
  c_send_ldap_intermediate = 0x80838fe <slap_send_ldap_intermediate>}

frame 6 is the first location I have "op" access, so I then went
(gdb) frame 6
(gdb) p *op
$10 = {o_hdr = 0xa143af10, o_tag = 99, o_time = 1236686741, o_tincr = 0, o_bd =
0xa143b0b8, o_req_dn = {bv_len = 18, 
    bv_val = 0x9dcd15ee "dc=HIDDEN-gw,dc=com"}, o_req_ndn = {bv_len = 18, bv_val
= 0x9dcd1601 "dc=HIDDEN-gw,dc=com"}, o_request = {oq_add = {
      rs_modlist = 0x2, rs_e = 0x0}, oq_bind = {rb_method = 2, rb_cred = {bv_len
= 0, bv_val = 0xffffffff <Address 0xffffffff out of bounds>}, rb_edn = {
        bv_len = 4294967295, bv_val = 0x0}, rb_ssf = 0, rb_mech = {bv_len =
2647463064, bv_val = 0x9dc1bbe8 "\207"}}, oq_compare = {rs_ava = 0x2}, 
    oq_modify = {rs_mods = {rs_modlist = 0x2, rs_no_opattrs = 0 '\0'},
rs_increment = -1}, oq_modrdn = {rs_mods = {rs_modlist = 0x2, 
        rs_no_opattrs = 0 '\0'}, rs_deleteoldrdn = -1, rs_newrdn = {bv_len =
4294967295, bv_val = 0x0}, rs_nnewrdn = {bv_len = 0, 
        bv_val = 0x9dcd1498 "\t"}, rs_newSup = 0x9dc1bbe8, rs_nnewSup = 0xf},
oq_search = {rs_scope = 2, rs_deref = 0, rs_slimit = -1, rs_tlimit = -1, 
      rs_limit = 0x0, rs_attrsonly = 0, rs_attrs = 0x9dcd1498, rs_filter =
0x9dc1bbe8, rs_filterstr = {bv_len = 15, 
        bv_val = 0x9dcd1614 "(objectClass=*)"}}, oq_abandon = {rs_msgid = 2},
oq_cancel = {rs_msgid = 2}, oq_extended = {rs_reqoid = {bv_len = 2, 
        bv_val = 0x0}, rs_flags = -1, rs_reqdata = 0xffffffff}, oq_pwdexop =
{rs_extended = {rs_reqoid = {bv_len = 2, bv_val = 0x0}, rs_flags = -1, 
        rs_reqdata = 0xffffffff}, rs_old = {bv_len = 0, bv_val = 0x0}, rs_new =
{bv_len = 2647463064, bv_val = 0x9dc1bbe8 "\207"}, rs_mods = 0xf, 
      rs_modtail = 0x9dcd1614}}, o_abandon = 0, o_cancel = 0, o_groups = 0x0,
o_do_not_cache = 1 '\001', o_is_auth_check = 0 '\0', 
  o_dont_replicate = 0 '\0', o_acl_priv = ACL_NONE, o_nocaching = 0 '\0',
o_delete_glue_parent = 0 '\0', o_no_schema_check = 0 '\0', 
  o_no_subordinate_glue = 0 '\0', o_ctrlflag = '\0' <repeats 31 times>,
o_controls = 0xa143b038, o_authz = {sai_method = 128, sai_mech = {bv_len = 0, 
      bv_val = 0x0}, sai_dn = {bv_len = 27, bv_val = 0x9dcd15d2
"cn=admin,dc=HIDDEN-gw,dc=com"}, sai_ndn = {bv_len = 27, 
      bv_val = 0x9dcd15d2 "cn=admin,dc=HIDDEN-gw,dc=com"}, sai_ssf = 0,
sai_transport_ssf = 0, sai_tls_ssf = 0, sai_sasl_ssf = 0}, o_ber = 0x0, 
  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 = 0x0}}


Full backtrace:
Thread 10 (process 29266):
#0  0xb7ef8410 in __kernel_vsyscall ()
#1  0xb7db2775 in pthread_join () from /lib/tls/i686/cmov/libpthread.so.0
#2  0x0817ba95 in ldap_pvt_thread_join (thread=2730757008, thread_return=0x0) at
thr_posix.c:197
#3  0x0806ba57 in slapd_daemon () at daemon.c:2665
#4  0x0804e8c7 in main (argc=1, argv=0xbfe1d2e4) at main.c:948

Thread 9 (process 29268):
#0  0xb7ef8410 in __kernel_vsyscall ()
#1  0xb7b81676 in epoll_wait () from /lib/tls/i686/cmov/libc.so.6
#2  0x0806abee in slapd_daemon_task (ptr=0x0) at daemon.c:2291
#3  0xb7db14fb in start_thread () from /lib/tls/i686/cmov/libpthread.so.0
#4  0xb7b80e5e in clone () from /lib/tls/i686/cmov/libc.so.6

Thread 8 (process 29269):
#0  0xb7ef8410 in __kernel_vsyscall ()
#1  0xb7db5aa5 in pthread_cond_wait@@GLIBC_2.3.2 () from
/lib/tls/i686/cmov/libpthread.so.0
#2  0x0817bb2a in ldap_pvt_thread_cond_wait (cond=0xb79ccf88, mutex=0xb79ccf70)
at thr_posix.c:277
#3  0x08081eac in send_ldap_ber (conn=0xb79cce78, ber=0xa203db8c) at
result.c:217
#4  0x08085b20 in slap_send_search_entry (op=0xa203de38, rs=0xa203dcdc) at
result.c:1246
#5  0x0815dbcb in syncprov_sendresp (op=0xa203de38, opc=0xa203ddb8,
so=0x9dc65f10, e=0xa203dde8, mode=1) at syncprov.c:825
#6  0x0815df12 in syncprov_qplay (op=0xa203de38, rtask=0x9b30c640) at
syncprov.c:896
#7  0x0815e1a7 in syncprov_qtask (ctx=0xa203e1f0, arg=0x9b30c640) at
syncprov.c:959
#8  0x0817a99b in ldap_int_thread_pool_wrapper (xpool=0x829baf0) at tpool.c:663
#9  0xb7db14fb in start_thread () from /lib/tls/i686/cmov/libpthread.so.0
#10 0xb7b80e5e in clone () from /lib/tls/i686/cmov/libc.so.6

Thread 7 (process 29295):
#0  0xb7ef8410 in __kernel_vsyscall ()
#1  0xb7db5aa5 in pthread_cond_wait@@GLIBC_2.3.2 () from
/lib/tls/i686/cmov/libpthread.so.0
#2  0x0817bb2a in ldap_pvt_thread_cond_wait (cond=0xb79ce090, mutex=0xb79ce078)
at thr_posix.c:277
#3  0x08081eac in send_ldap_ber (conn=0xb79cdf80, ber=0xa1c3cb8c) at
result.c:217
#4  0x08085b20 in slap_send_search_entry (op=0xa1c3ce38, rs=0xa1c3ccdc) at
result.c:1246
#5  0x0815dbcb in syncprov_sendresp (op=0xa1c3ce38, opc=0xa1c3cdb8,
so=0x9ab8ecd8, e=0xa1c3cde8, mode=1) at syncprov.c:825
#6  0x0815df12 in syncprov_qplay (op=0xa1c3ce38, rtask=0x9af477a8) at
syncprov.c:896
#7  0x0815e1a7 in syncprov_qtask (ctx=0xa1c3d1f0, arg=0x9af477a8) at
syncprov.c:959
#8  0x0817a99b in ldap_int_thread_pool_wrapper (xpool=0x829baf0) at tpool.c:663
#9  0xb7db14fb in start_thread () from /lib/tls/i686/cmov/libpthread.so.0
#10 0xb7b80e5e in clone () from /lib/tls/i686/cmov/libc.so.6

Thread 6 (process 29296):
#0  0xb7ef8410 in __kernel_vsyscall ()
#1  0xb7db5aa5 in pthread_cond_wait@@GLIBC_2.3.2 () from
/lib/tls/i686/cmov/libpthread.so.0
#2  0x0817bb2a in ldap_pvt_thread_cond_wait (cond=0xb79cf500, mutex=0xb79cf4e8)
at thr_posix.c:277
#3  0x08081eac in send_ldap_ber (conn=0xb79cf3f0, ber=0xa183bb8c) at
result.c:217
#4  0x08085b20 in slap_send_search_entry (op=0xa183be38, rs=0xa183bcdc) at
result.c:1246
#5  0x0815dbcb in syncprov_sendresp (op=0xa183be38, opc=0xa183bdb8,
so=0xa0ae45c8, e=0xa183bde8, mode=1) at syncprov.c:825
#6  0x0815df12 in syncprov_qplay (op=0xa183be38, rtask=0x9ab5e400) at
syncprov.c:896
#7  0x0815e1a7 in syncprov_qtask (ctx=0xa183c1f0, arg=0x9ab5e400) at
syncprov.c:959
#8  0x0817a99b in ldap_int_thread_pool_wrapper (xpool=0x829baf0) at tpool.c:663
#9  0xb7db14fb in start_thread () from /lib/tls/i686/cmov/libpthread.so.0
#10 0xb7b80e5e in clone () from /lib/tls/i686/cmov/libc.so.6

Thread 5 (process 29298):
#0  0xb7ef8410 in __kernel_vsyscall ()
#1  0xb7db5aa5 in pthread_cond_wait@@GLIBC_2.3.2 () from
/lib/tls/i686/cmov/libpthread.so.0
#2  0x0817bb2a in ldap_pvt_thread_cond_wait (cond=0xb79c8d1c, mutex=0xb79c8d04)
at thr_posix.c:277
#3  0x08081eac in send_ldap_ber (conn=0xb79c8c0c, ber=0xa1039b8c) at
result.c:217
#4  0x08085b20 in slap_send_search_entry (op=0xa1039e38, rs=0xa1039cdc) at
result.c:1246
#5  0x0815dbcb in syncprov_sendresp (op=0xa1039e38, opc=0xa1039db8,
so=0x9dc0bed0, e=0xa1039de8, mode=2) at syncprov.c:825
#6  0x0815df12 in syncprov_qplay (op=0xa1039e38, rtask=0x83781c8) at
syncprov.c:896
#7  0x0815e1a7 in syncprov_qtask (ctx=0xa103a1f0, arg=0x83781c8) at
syncprov.c:959
#8  0x0817a99b in ldap_int_thread_pool_wrapper (xpool=0x829baf0) at tpool.c:663
#9  0xb7db14fb in start_thread () from /lib/tls/i686/cmov/libpthread.so.0
#10 0xb7b80e5e in clone () from /lib/tls/i686/cmov/libc.so.6

Thread 4 (process 29300):
#0  0xb7ef8410 in __kernel_vsyscall ()
#1  0xb7db5aa5 in pthread_cond_wait@@GLIBC_2.3.2 () from
/lib/tls/i686/cmov/libpthread.so.0
#2  0x0817bb2a in ldap_pvt_thread_cond_wait (cond=0xb79cefe4, mutex=0xb79cefcc)
at thr_posix.c:277
#3  0x08081eac in send_ldap_ber (conn=0xb79ceed4, ber=0x9dbfeb8c) at
result.c:217
#4  0x08085b20 in slap_send_search_entry (op=0x9dbfee38, rs=0x9dbfecdc) at
result.c:1246
#5  0x0815dbcb in syncprov_sendresp (op=0x9dbfee38, opc=0x9dbfedb8,
so=0x9ab63788, e=0x9dbfede8, mode=1) at syncprov.c:825
#6  0x0815df12 in syncprov_qplay (op=0x9dbfee38, rtask=0xa0a03b60) at
syncprov.c:896
#7  0x0815e1a7 in syncprov_qtask (ctx=0x9dbff1f0, arg=0xa0a03b60) at
syncprov.c:959
#8  0x0817a99b in ldap_int_thread_pool_wrapper (xpool=0x829baf0) at tpool.c:663
#9  0xb7db14fb in start_thread () from /lib/tls/i686/cmov/libpthread.so.0
#10 0xb7b80e5e in clone () from /lib/tls/i686/cmov/libc.so.6

Thread 3 (process 29301):
#0  0xb7ef8410 in __kernel_vsyscall ()
#1  0xb7db5aa5 in pthread_cond_wait@@GLIBC_2.3.2 () from
/lib/tls/i686/cmov/libpthread.so.0
#2  0x0817bb2a in ldap_pvt_thread_cond_wait (cond=0xb79bfaa4, mutex=0xb79bfa8c)
at thr_posix.c:277
#3  0x08081eac in send_ldap_ber (conn=0xb79bf994, ber=0x9cefbb8c) at
result.c:217
#4  0x08085b20 in slap_send_search_entry (op=0x9cefbe38, rs=0x9cefbcdc) at
result.c:1246
#5  0x0815dbcb in syncprov_sendresp (op=0x9cefbe38, opc=0x9cefbdb8,
so=0x9af1df00, e=0x9cefbde8, mode=1) at syncprov.c:825
#6  0x0815df12 in syncprov_qplay (op=0x9cefbe38, rtask=0xa0a33d90) at
syncprov.c:896
#7  0x0815e1a7 in syncprov_qtask (ctx=0x9cefc1f0, arg=0xa0a33d90) at
syncprov.c:959
#8  0x0817a99b in ldap_int_thread_pool_wrapper (xpool=0x829baf0) at tpool.c:663
#9  0xb7db14fb in start_thread () from /lib/tls/i686/cmov/libpthread.so.0
#10 0xb7b80e5e in clone () from /lib/tls/i686/cmov/libc.so.6

Thread 2 (process 29302):
#0  0xb7ef8410 in __kernel_vsyscall ()
#1  0xb7db5aa5 in pthread_cond_wait@@GLIBC_2.3.2 () from
/lib/tls/i686/cmov/libpthread.so.0
#2  0x0817bb2a in ldap_pvt_thread_cond_wait (cond=0xb79cb0e0, mutex=0xb79cb0c8)
at thr_posix.c:277
#3  0x08081eac in send_ldap_ber (conn=0xb79cafd0, ber=0x9cafab8c) at
result.c:217
#4  0x08085b20 in slap_send_search_entry (op=0x9cafae38, rs=0x9cafacdc) at
result.c:1246
#5  0x0815dbcb in syncprov_sendresp (op=0x9cafae38, opc=0x9cafadb8,
so=0x9af21c10, e=0x9cafade8, mode=1) at syncprov.c:825
#6  0x0815df12 in syncprov_qplay (op=0x9cafae38, rtask=0xa0a31988) at
syncprov.c:896
#7  0x0815e1a7 in syncprov_qtask (ctx=0x9cafb1f0, arg=0xa0a31988) at
syncprov.c:959
#8  0x0817a99b in ldap_int_thread_pool_wrapper (xpool=0x829baf0) at tpool.c:663
#9  0xb7db14fb in start_thread () from /lib/tls/i686/cmov/libpthread.so.0
#10 0xb7b80e5e in clone () from /lib/tls/i686/cmov/libc.so.6

Thread 1 (process 29297):
#0  0xb7ef8410 in __kernel_vsyscall ()
#1  0xb7ad5085 in raise () from /lib/tls/i686/cmov/libc.so.6
#2  0xb7ad6a01 in abort () from /lib/tls/i686/cmov/libc.so.6
#3  0xb7ace10e in __assert_fail () from /lib/tls/i686/cmov/libc.so.6
#4  0x0806d6c6 in connection_state_closing (c=0xb79c9644) at connection.c:686
#5  0x08081bdd in send_ldap_ber (conn=0xb79c9644, ber=0xa143ab8c) at
result.c:147
#6  0x08085b20 in slap_send_search_entry (op=0xa143ae38, rs=0xa143acdc) at
result.c:1246
#7  0x0815dbcb in syncprov_sendresp (op=0xa143ae38, opc=0xa143adb8,
so=0x9ab66dc8, e=0xa143ade8, mode=1) at syncprov.c:825
#8  0x0815df12 in syncprov_qplay (op=0xa143ae38, rtask=0x9b303110) at
syncprov.c:896
#9  0x0815e1a7 in syncprov_qtask (ctx=0xa143b1f0, arg=0x9b303110) at
syncprov.c:959
#10 0x0817a99b in ldap_int_thread_pool_wrapper (xpool=0x829baf0) at tpool.c:663
#11 0xb7db14fb in start_thread () from /lib/tls/i686/cmov/libpthread.so.0
#12 0xb7b80e5e in clone () from /lib/tls/i686/cmov/libc.so.6


Thanks for your time!

Oskar