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

To: openldap-its@OpenLDAP.org
Subject: Re: (ITS#6096) 2.4.16 replica segfault
From: hyc@symas.com
Date: Thu, 7 May 2009 08:50:49 GMT
Auto-submitted: auto-generated (OpenLDAP-ITS)
luca@OpenLDAP.org wrote:
> 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.

An assert is not a segfault...

> Since no MODRDN
> operation is ever being performed on entries I wonder why.

Apparently the name of the entry in the consumer doesn't match the name of the 
entry received from the provider.

> Anyway, here the bt
> full:

In frame 5, print *entry

> #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
>


-- 
   -- Howard Chu
   CTO, Symas Corp.           http://www.symas.com
   Director, Highland Sun     http://highlandsun.com/hyc/
   Chief Architect, OpenLDAP  http://www.openldap.org/project/
Prev by Date: (ITS#6096) 2.4.16 replica segfault
Next by Date: Re: (ITS#6096) 2.4.16 replica segfault
Index(es):
- Chronological
- Thread