[Date Prev][Date Next] [Chronological] [Thread] [Top]
(ITS#6096) 2.4.16 replica segfault

To: openldap-its@openldap.org
Subject: (ITS#6096) 2.4.16 replica segfault
From: luca@OpenLDAP.org
Date: Thu, 7 May 2009 08:12:18 GMT
Auto-submitted: auto-generated (OpenLDAP-ITS)
Full_Name: Luca Scamoni
Version: 2.4.16
OS: Linux
URL: ftp://ftp.openldap.org/incoming/
Submission from: (NULL) (82.63.140.131)


Scenario:
OpenLDAP 2.4.16 with patches for back-bdb (up to may 1st) and syncrepl.
Master-slave configuration using syncrepl refreshAndPersist. Two hdb databases
per instance.
Replica hit assert in slap_modrdn2mods and dumped core. Since no MODRDN
operation is ever being performed on entries I wonder why. Anyway, here the bt
full:

#0  0x004017a2 in _dl_sysinfo_int80 () from /lib/ld-linux.so.2
No symbol table info available.
#1  0x004427a5 in raise () from /lib/tls/libc.so.6
No symbol table info available.
#2  0x00444209 in abort () from /lib/tls/libc.so.6
No symbol table info available.
#3  0x0043bd91 in __assert_fail () from /lib/tls/libc.so.6
No symbol table info available.
#4  0x0809c7e6 in slap_modrdn2mods (op=0x380acf0, rs=0x380a910) at
../../../servers/slapd/modrdn.c:394
        a_cnt = 0
        d_cnt = 0
        old_rdn = 0x0
        new_rdn = 0x0
        __PRETTY_FUNCTION__ = "slap_modrdn2mods"
#5  0x080f39f4 in syncrepl_entry (si=0x8fdebf8, op=0x380acf0, entry=0x54eba5f4,
modlist=0x380aaf4, syncstate=2, syncUUID=0x380ab50, syncCSN=0x4d3e0388)
    at ../../../servers/slapd/syncrepl.c:2278
        noldp = {bv_len = 1294991464, bv_val = 0x4d300048 ""}
        newp = {bv_len = 0, bv_val = 0x4d3691c8 ""}
        i = 4707898
        got_replace = 0
        just_rename = 0
        mod = (Modifications *) 0x54a371fc
        modtail = (Modifications **) 0x1d2d14
        ml = (Modifications **) 0x4565bac8
        m2 = (Modifications *) 0x4d300010
        be = (Backend *) 0x8fdd988
        cb = {sc_next = 0x0, sc_response = 0x80f7618 <null_callback>, sc_cleanup
= 0, sc_private = 0x8fdebf8}
        syncuuid_inserted = 0
        syncUUID_strrep = {bv_len = 36, bv_val = 0x4ae0300c
"6a0ba116-b291-11da-8006-87f6e679f1bd"}
        rs_search = {sr_type = REP_RESULT, sr_tag = 101, sr_msgid = 0, sr_err =
0, sr_matched = 0x0,
  sr_text = 0x813b938 "AttributeDescription contains inappropriate characters",
sr_ref = 0x0, sr_ctrls = 0x0, sr_un = {sru_sasl = {r_sasldata = 0x0},
    sru_extended = {r_rspoid = 0x0, r_rspdata = 0x0}, sru_search = {r_entry =
0x0, r_attr_flags = 0, r_operational_attrs = 0x0, r_attrs = 0x8172ce0,
      r_nentries = 0, r_v2ref = 0x0}}, sr_flags = 4}
        rs_delete = {sr_type = REP_RESULT, sr_tag = 0, sr_msgid = 0, sr_err = 0,
sr_matched = 0x0, sr_text = 0x0, sr_ref = 0x0, sr_ctrls = 0x0, sr_un = {
    sru_sasl = {r_sasldata = 0x0}, sru_extended = {r_rspoid = 0x0, r_rspdata =
0x0}, sru_search = {r_entry = 0x0, r_attr_flags = 0,
      r_operational_attrs = 0x0, r_attrs = 0x0, r_nentries = 0, r_v2ref = 0x0}},
sr_flags = 0}
        rs_add = {sr_type = REP_RESULT, sr_tag = 0, sr_msgid = 0, sr_err = 0,
sr_matched = 0x0, sr_text = 0x0, sr_ref = 0x0, sr_ctrls = 0x0, sr_un = {
    sru_sasl = {r_sasldata = 0x0}, sru_extended = {r_rspoid = 0x0, r_rspdata =
0x0}, sru_search = {r_entry = 0x0, r_attr_flags = 0,
      r_operational_attrs = 0x0, r_attrs = 0x0, r_nentries = 0, r_v2ref = 0x0}},
sr_flags = 0}
        rs_modify = {sr_type = REP_RESULT, sr_tag = 0, sr_msgid = 0, sr_err = 0,
sr_matched = 0x0, sr_text = 0x0, sr_ref = 0x0, sr_ctrls = 0x0, sr_un = {
    sru_sasl = {r_sasldata = 0x0}, sru_extended = {r_rspoid = 0x0, r_rspdata =
0x0}, sru_search = {r_entry = 0x0, r_attr_flags = 0,
      r_operational_attrs = 0x0, r_attrs = 0x0, r_nentries = 0, r_v2ref = 0x0}},
sr_flags = 0}
        f = {f_choice = 163, f_un = {f_un_result = 58763504, f_un_desc =
0x380a8f0, f_un_ava = 0x380a8f0, f_un_ssa = 0x380a8f0, f_un_mra = 0x380a8f0,
    f_un_complex = 0x380a8f0}, f_next = 0x0}
        ava = {aa_desc = 0x8f08d50, aa_value = {bv_len = 16, bv_val = 0x45614117
"j\v¡\026²\221\021Ú\200\006\207öæyñ½"}}
        rc = 0
        pdn = {bv_len = 0, bv_val = 0x0}
        dni = {new_entry = 0x54eba5f4, dn = {bv_len = 112,
    bv_val = 0x4ae03074 "cn=CRL19,ou=Regione Siciliana Certification Authority
Cittadini,o=Regione Siciliana,c=IT,dc=a,dc=prod,dc=actalis"}, ndn = {
    bv_len = 112, bv_val = 0x4ae030ec "cn=crl19,ou=regione siciliana
certification authority cittadini,o=regione
siciliana,c=it,dc=a,dc=prod,dc=actalis"},
  nnewSup = {bv_len = 0, bv_val = 0x4d31cff8 ""}, renamed = 1, delOldRDN = 0,
modlist = 0x380aaf4, mods = 0x456172e0, oldNattr = 0x54a38d74,
  oldDesc = 0x8f0ce90, newDesc = 0x0}
        retry = 1
        freecsn = 1
        __PRETTY_FUNCTION__ = "syncrepl_entry"
#6  0x080eebcf in do_syncrep2 (op=0x380acf0, si=0x8fdebf8) at
../../../servers/slapd/syncrepl.c:892
        rctrlp = (LDAPControl *) 0x45635200
        rctrls = (LDAPControl **) 0x4d371e08
        berbuf = {
  buffer = "\002\000\001", '\0' <repeats 17 times>, "\020AaE]AaE]AaE", '\0'
<repeats 16 times>, "¼«\200\003
*T\000\000\000\000\000\017\000\000\000ô/T\000\017\000\000\000?}S\000Ü«\200\003ô/T\000\a\000\000\000\000\000\000\000\001\000\000\000\020²\200\003È\200\0038¬\200\003fg\016\b\020²\200\003Õf\016\b\004¬\200\003\000\000\000\000ô/T\000È\200\003¤±\200\003\030¬\200\003\"ÙE\000ð\200\003\000\001\000\000zª\022\b,¬\200\003@ç\026\b8¬\200\003\211°\a\bð\200\003'~\022\000zª\022\b\2046s\000\000\000\000\000¤±\200\003\001\000\000\000³f`\0008>\027\b\204"...,
ialign = 65538, lalign = 65538, falign = 9.18382988e-41,
  dalign = 3.2380074297143616e-319, palign = 0x10002 <Address 0x10002 out of
bounds>}
        ber = (BerElement *) 0x380ab70
        msg = (LDAPMessage *) 0x4d3741f0
        retoid = 0x0
        retdata = (struct berval *) 0x0
        entry = (Entry *) 0x54eba5f4
        syncstate = 2
        syncUUID = {bv_len = 16, bv_val = 0x45614117
"j\v¡\026²\221\021Ú\200\006\207öæyñ½"}
        syncCookie = {ctxcsn = 0x4d3e0388, octet_str = {bv_len = 52, bv_val =
0x4d368850 "rid=002,csn=20090507070014.234380Z#000000#000#000000"}, rid = 2,
  sid = -1, numcsns = 1, sids = 0x4d3fa4a8, sc_next = {stqe_next = 0x0}}
        syncCookie_req = {ctxcsn = 0x45661888, octet_str = {bv_len = 52, bv_val
= 0x4d366330 "rid=002,csn=20090507070013.853843Z#000000#000#000000"},
  rid = 2, sid = -1, numcsns = 1, sids = 0x4d3655f8, sc_next = {stqe_next =
0x0}}
        cookie = {bv_len = 52, bv_val = 0x45614129
"rid=002,csn=20090507070014.234380Z#000000#000#000000"}
        rc = 0
        err = 0
        len = 52
        psub = (struct berval *) 0x8fde868
        modlist = (Modifications *) 0x4565ba00
        match = 4676822
        m = 58764284
        tout_p = (struct timeval *) 0x380aae0
        tout = {tv_sec = 0, tv_usec = 0}
        refreshDeletes = 0
        syncUUIDs = 0x0
        si_tag = 813739759
#7  0x080f081e in do_syncrepl (ctx=0x380b210, arg=0x8fdee98) at
../../../servers/slapd/syncrepl.c:1357
        rtask = (struct re_s *) 0x8fdee98
        si = (syncinfo_t *) 0x8fdebf8
        conn = {c_struct_state = 0, c_conn_state = 0, c_conn_idx = -1, c_sd = 0,
c_close_reason = 0x0, c_mutex = {__m_reserved = 0, __m_count = 0,
    __m_owner = 0x0, __m_kind = 0, __m_lock = {__status = 0, __spinlock = 0}},
c_sb = 0x0, c_starttime = 0, c_activitytime = 0, c_connid = 4294967295,
  c_peer_domain = {bv_len = 0, bv_val = 0x8123930 ""}, c_peer_name = {bv_len =
0, bv_val = 0x8123930 ""}, c_listener = 0x816e080, 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 = 0, 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 = 0x0},
  c_pending_ops = {stqh_first = 0x0, stqh_last = 0x0}, c_write1_mutex =
{__m_reserved = 0, __m_count = 0, __m_owner = 0x0, __m_kind = 0, __m_lock = {
      __status = 0, __spinlock = 0}}, c_write1_cv = {__c_lock = {__status = 0,
__spinlock = 0}, __c_waiting = 0x0, __padding = '\0' <repeats 27 times>,
    __align = 0}, c_write2_mutex = {__m_reserved = 0, __m_count = 0, __m_owner =
0x0, __m_kind = 0, __m_lock = {__status = 0, __spinlock = 0}},
  c_write2_cv = {__c_lock = {__status = 0, __spinlock = 0}, __c_waiting = 0x0,
__padding = '\0' <repeats 27 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 = 0, c_n_ops_executing = 0, c_n_ops_pending = 0,
  c_n_ops_completed = 0, c_n_get = 0, c_n_read = 0, c_n_write = 0, c_extensions
= 0x0, c_clientfunc = 0, c_clientarg = 0x0,
  c_send_ldap_result = 0x808e8de <slap_send_ldap_result>, c_send_search_entry =
0x808f65a <slap_send_search_entry>,
  c_send_search_reference = 0x80917d2 <slap_send_search_reference>,
c_send_ldap_extended = 0x808f180 <slap_send_ldap_extended>,
  c_send_ldap_intermediate = 0x808f420 <slap_send_ldap_intermediate>}
        opbuf = {ob_op = {o_hdr = 0x380adc8, o_tag = 108, o_time = 1241679614,
o_tincr = 9, o_bd = 0x8fdd988, o_req_dn = {bv_len = 112,
      bv_val = 0x4ae03074 "cn=CRL19,ou=Regione Siciliana Certification Authority
Cittadini,o=Regione Siciliana,c=IT,dc=a,dc=prod,dc=actalis"}, o_req_ndn = {
      bv_len = 112,
      bv_val = 0x4ae030ec "cn=crl19,ou=regione siciliana certification authority
cittadini,o=regione siciliana,c=it,dc=a,dc=prod,dc=actalis"}, o_request = {
      oq_add = {rs_modlist = 0x0, rs_e = 0x0}, oq_bind = {rb_method = 0, rb_cred
= {bv_len = 0, bv_val = 0x0}, rb_edn = {bv_len = 0,
          bv_val = 0x4d3691c8 ""}, rb_ssf = 0, rb_mech = {bv_len = 1295110136,
bv_val = 0x380a750 ""}}, oq_compare = {rs_ava = 0x0}, oq_modify = {
        rs_mods = {rs_modlist = 0x0, rs_no_opattrs = 0 '\0'}, rs_increment = 0},
oq_modrdn = {rs_mods = {rs_modlist = 0x0, rs_no_opattrs = 0 '\0'},
        rs_deleteoldrdn = 0, rs_newrdn = {bv_len = 0, bv_val = 0x4d3691c8 ""},
rs_nnewrdn = {bv_len = 0, bv_val = 0x4d31cff8 ""}, rs_newSup = 0x380a750,
        rs_nnewSup = 0x380a8b4}, oq_search = {rs_scope = 0, rs_deref = 0,
rs_slimit = 0, rs_tlimit = 0, rs_limit = 0x4d3691c8, rs_attrsonly = 0,
        rs_attrs = 0x4d31cff8, rs_filter = 0x380a750, rs_filterstr = {bv_len =
58763444,
          bv_val = 0x4ae0303c
"(entryUUID=6a0ba116-b291-11da-8006-87f6e679f1bd)"}}, oq_abandon = {rs_msgid =
0}, oq_cancel = {rs_msgid = 0}, oq_extended = {
        rs_reqoid = {bv_len = 0, bv_val = 0x0}, rs_flags = 0, rs_reqdata = 0x0},
oq_pwdexop = {rs_extended = {rs_reqoid = {bv_len = 0, bv_val = 0x0},
          rs_flags = 0, rs_reqdata = 0x0}, rs_old = {bv_len = 1295421896, bv_val
= 0x0}, rs_new = {bv_len = 1295110136, bv_val = 0x380a750 ""},
        rs_mods = 0x380a8b4, rs_modtail = 0x4ae0303c}}, o_abandon = 0, o_cancel
= 0, o_groups = 0x0, o_do_not_cache = 0 '\0', 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 = 1 '\001',
    o_no_subordinate_glue = 0 '\0', o_ctrlflag = '\0' <repeats 14 times>,
"\002", '\0' <repeats 16 times>, o_controls = 0x380aef0, o_authz = {
      sai_method = 0, sai_mech = {bv_len = 0, bv_val = 0x0}, sai_dn = {bv_len =
34, bv_val = 0x8fde900 "cn=Manager,dc=a,dc=prod,dc=actalis"}, sai_ndn = {
        bv_len = 34, bv_val = 0x8fde940 "cn=manager,dc=a,dc=prod,dc=actalis"},
sai_ssf = 0, sai_transport_ssf = 0, sai_tls_ssf = 0, sai_sasl_ssf = 0},
    o_ber = 0x0, o_res_ber = 0x0, o_callback = 0x380aa20, o_ctrls = 0x0, o_csn =
{bv_len = 40,
      bv_val = 0x4ae03164 "20090507070014.234380Z#000000#000#000000"}, o_private
= 0x0, o_extra = {slh_first = 0x0}, o_next = {stqe_next = 0x0}}, ob_hdr = {
    oh_opid = 0, oh_connid = 4294967295, oh_conn = 0x380af70, oh_msgid = 0,
oh_protocol = 0, oh_tid = 58768288, oh_threadctx = 0x380b210,
    oh_tmpmemctx = 0x94bd878, oh_tmpmfuncs = 0x8172f00, oh_counters = 0x81b65e0,
oh_log_prefix = "conn=-1 op=0", '\0' <repeats 243 times>}, ob_controls = {
    0x380ab30, 0x0 <repeats 31 times>}}
        op = (Operation *) 0x380acf0
        rc = 0
        dostop = 0
        s = 15
        i = 2
        defer = 1
        fail = 0
        be = (Backend *) 0x8fdd988
#8  0x08079db6 in connection_read_thread (ctx=0x380b210, argv=0xf) at
../../../servers/slapd/connection.c:1243
        rc = 0
        cri = {op = 0x0, func = 0x80f0371 <do_syncrepl>, arg = 0x8fdee98, ctx =
0x380b210, nullop = 0}
        s = 15
#9  0x00605389 in ldap_int_thread_pool_wrapper (xpool=0x8f0eab0) at
../../../libraries/libldap_r/tpool.c:663
        pool = (struct ldap_int_thread_pool_s *) 0x8f0eab0
        task = (ldap_int_thread_task_t *) 0x94bb930
        work_list = (ldap_int_tpool_plist_t *) 0x8f0eb30
        ctx = {ltu_id = 58768288, ltu_key = {{ltk_key = 0x80793bb, ltk_data =
0x94bd788, ltk_free = 0x80791ab <conn_counter_destroy>}, {
      ltk_key = 0x80e66d5, ltk_data = 0x94bd878, ltk_free = 0x80e64e8
<slap_sl_mem_destroy>}, {ltk_key = 0x90204a0, ltk_data = 0x942e8b8,
      ltk_free = 0x225796 <bdb_reader_free>}, {ltk_key = 0x8092ceb, ltk_data =
0x9439e10, ltk_free = 0x8092c48 <slap_op_q_destroy>}, {ltk_key = 0x90229a0,
      ltk_data = 0x943a4e0, ltk_free = 0x225796 <bdb_reader_free>}, {ltk_key =
0x213b96, ltk_data = 0x457f1008, ltk_free = 0x213b6b <search_stack_free>}, {
      ltk_key = 0x0, ltk_data = 0x0, ltk_free = 0} <repeats 26 times>}}
        kctx = (ldap_int_thread_userctx_t *) 0x0
        i = 32
        keyslot = 158
        hash = 5957790
        __PRETTY_FUNCTION__ = "ldap_int_thread_pool_wrapper"
#10 0x001263cc in start_thread () from /lib/tls/libpthread.so.0
No symbol table info available.
#11 0x004e3c3e in clone () from /lib/tls/libc.so.6
No symbol table info available.

soon after that (about 1 minute) master stopped accepting connection and load
average jumped to 18.

Last rows of replica log:
May  7 09:00:14 quercia02 slapd[13339]: slap_queue_csn: queing 0x4c1db4a0
20090507070013.733132Z#000000#000#000000
May  7 09:00:14 quercia02 slapd[13339]: conn=113 op=1705 SEARCH RESULT tag=101
err=0 nentries=1 text=
May  7 09:00:14 quercia02 slapd[13339]: slap_graduate_commit_csn: removing
0x548befa8 20090507070013.733132Z#000000#000#000000
May  7 09:00:14 quercia02 slapd[13339]: do_syncrep2:
cookie=rid=002,csn=20090507070013.853843Z#000000#000#000000
May  7 09:00:14 quercia02 slapd[13339]: syncrepl_entry: rid=002
LDAP_RES_SEARCH_ENTRY(LDAP_SYNC_MODIFY)
May  7 09:00:14 quercia02 slapd[13339]: syncrepl_entry: rid=002 be_search (0)
May  7 09:00:14 quercia02 slapd[13339]: syncrepl_entry: rid=002
cn=CRL37,ou=Regione Siciliana Certification Authority Cittadini,o=Regione
Siciliana,c=IT,dc=a
,dc=prod,dc=actalis
May  7 09:00:14 quercia02 slapd[13339]: slap_queue_csn: queing 0x4d32e218
20090507070013.853843Z#000000#000#000000
May  7 09:00:14 quercia02 slapd[13339]: slap_graduate_commit_csn: removing
0x4d3657d8 20090507070013.853843Z#000000#000#000000
May  7 09:00:14 quercia02 slapd[13339]: syncrepl_entry: rid=002 be_modify
cn=CRL37,ou=Regione Siciliana Certification Authority Cittadini,o=Regione
Siciliana
,c=IT,dc=a,dc=prod,dc=actalis (0)
May  7 09:00:14 quercia02 slapd[13339]: slap_queue_csn: queing 0x4d32e218
20090507070013.853843Z#000000#000#000000
May  7 09:00:14 quercia02 slapd[13339]: slap_graduate_commit_csn: removing
0x45659710 20090507070013.853843Z#000000#000#000000
May  7 09:00:14 quercia02 slapd[13339]: do_syncrep2:
cookie=rid=002,csn=20090507070014.234380Z#000000#000#000000
May  7 09:00:14 quercia02 slapd[13339]: syncrepl_entry: rid=002
LDAP_RES_SEARCH_ENTRY(LDAP_SYNC_MODIFY)
May  7 09:00:14 quercia02 slapd[13339]: syncrepl_entry: rid=002 be_search (0)
May  7 09:00:14 quercia02 slapd[13339]: syncrepl_entry: rid=002
May  7 09:00:14 quercia02 slapd[13339]: slap_queue_csn: queing 0x45663bb0
20090507070014.234380Z#000000#000#000000

Any further information available upon request
TIA
Prev by Date: Re: (ITS#6089) connection_destroy() c->c_writers == 0 assertion failure
Next by Date: Re: (ITS#6096) 2.4.16 replica segfault
Index(es):
- Chronological
- Thread