https://bugs.openldap.org/show_bug.cgi?id=9633

Issue ID: 9633 Summary: Intermittent test030 failure caused by referral chasing Product: OpenLDAP Version: unspecified Hardware: All OS: All Status: UNCONFIRMED Severity: normal Priority: --- Component: libraries Assignee: bugs@openldap.org Reporter: hyc@openldap.org Target Milestone: ---

Not 100% reproducible but occurs frequently using ldif or wt backends. The test hits an assert failure in libldap.

...

...

...

...

Starting test030-relay for wt...

running defines.sh

Testing virtual naming context mapping with relay ldap meta backend(s)...

Using relay backend...

Starting slapd on TCP/IP port 9051... Using ldapsearch to check that slapd is running... Using ldapadd to populate the database... Searching base="dc=example,dc=com"... Searching base="o=Example,c=US"... Searching base="o=Esempio,c=IT"... Searching base="o=Beispiel,c=DE"... Modifying database "o=Beispiel,c=DE"... Modifying database "o=Example,c=US"... Searching base="o=Example,c=US"... Searching base="o=Esempio,c=IT"... Searching filter="(objectClass=referral)" attrs="'*' ref" base="dc=example,dc=com"... base="o=Example,c=US"... base="o=Esempio,c=IT"... Searching filter="(seeAlso=cn=all staff,ou=Groups,o=Example,c=US)" attrs="seeAlso" base="o=Example,c=US"... Searching filter="(uid=example)" attrs="uid" base="o=Example,c=US"... Searching filter="(member=cn=Another Added Group,ou=Groups,o=Example,c=US)" attrs="member" base="o=Example,c=US"... Filtering ldapsearch results... Filtering original ldif used to create database... Comparing filter output... Changing password to database "o=Example,c=US"... Binding with newly changed password to database "o=Beispiel,c=DE"... Comparing to database "o=Esempio,c=IT"...

...

...

...

...

waiting for things to exit

Using ldap backend...

Starting slapd on TCP/IP port 9051... Using ldapsearch to check that slapd is running... Using ldapadd to populate the database... Searching base="dc=example,dc=com"... Searching base="o=Example,c=US"... Searching base="o=Esempio,c=IT"... Searching base="o=Beispiel,c=DE"... Modifying database "o=Beispiel,c=DE"... Modifying database "o=Example,c=US"... Searching base="o=Example,c=US"... Search failed (255)! ../../head/tests/scripts/test030-relay: 240: kill: No such process

...

...

...

...

Failed test030-relay for wt after 3 seconds

(exit 255) make[1]: Leaving directory '/home/hyc/OD/hobj/tests'

backtrace:

gdb) bt #0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:49 #1 0x00007fb9119bd864 in __GI_abort () at abort.c:79 #2 0x00007fb9119bd749 in __assert_fail_base ( fmt=0x7fb911b46f78 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x7fb9123efc93 "lr->lr_refcnt == 0", file=0x7fb9123ef5c0 "../../../head/libraries/libldap/request.c", line=1671, function=<optimized out>) at assert.c:92 #3 0x00007fb9119cf3d6 in __GI___assert_fail ( assertion=0x7fb9123efc93 "lr->lr_refcnt == 0", file=0x7fb9123ef5c0 "../../../head/libraries/libldap/request.c", line=1671, function=0x7fb9123efe70 <__PRETTY_FUNCTION__.1> "ldap_find_request_by_msgid") at assert.c:101 #4 0x00007fb9121d671c in ldap_find_request_by_msgid (ld=0x7fb8fc124d70, msgid=3) at ../../../head/libraries/libldap/request.c:1671 #5 0x00007fb9121b882d in try_read1msg (ld=0x7fb8fc124d70, msgid=5, all=1, lc=0x7fb8fc128180, result=0x7fb90511bf48) at ../../../head/libraries/libldap/result.c:575 #6 0x00007fb9121b8135 in wait4msg (ld=0x7fb8fc124d70, msgid=5, all=1, timeout=0x7fb90511bf90, result=0x7fb90511bf48) at ../../../head/libraries/libldap/result.c:369 #7 0x00007fb9121b77cb in ldap_result (ld=0x7fb8fc124d70, msgid=5, all=1, timeout=0x7fb90511bf90, result=0x7fb90511bf48) --Type <RET> for more, q to quit, c to continue without paging-- at ../../../head/libraries/libldap/result.c:120 #8 0x00007fb9121d3b8c in ldap_new_connection (ld=0x7fb8fc124d70, srvlist=0x7fb90511c160, use_ldsb=0, connect=1, bind=0x7fb90511c1a0, m_req=1, m_res=1) at ../../../head/libraries/libldap/request.c:627 #9 0x00007fb9121d2ba0 in ldap_send_server_request (ld=0x7fb8fc124d70, ber=0x7fb8f0137ea0, msgid=4, parentreq=0x7fb8f0000fd0, srvlist=0x7fb90511c160, lc=0x0, bind=0x7fb90511c1a0, m_noconn=0, m_res=1) at ../../../head/libraries/libldap/request.c:253 #10 0x00007fb9121d56e5 in ldap_chase_v3referrals (ld=0x7fb8fc124d70, lr=0x7fb8f0000fd0, refs=0x0, sref=1, errstrp=0x7fb8f0001000, hadrefp=0x7fb90511c208) at ../../../head/libraries/libldap/request.c:1283 #11 0x00007fb9121b8b40 in try_read1msg (ld=0x7fb8fc124d70, msgid=3, all=0, lc=0x7fb8fc128180, result=0x7fb90511c4e8) at ../../../head/libraries/libldap/result.c:680 #12 0x00007fb9121b8135 in wait4msg (ld=0x7fb8fc124d70, msgid=3, all=0, timeout=0x7fb90511c520, result=0x7fb90511c4e8) at ../../../head/libraries/libldap/result.c:369 #13 0x00007fb9121b77cb in ldap_result (ld=0x7fb8fc124d70, msgid=3, all=0, timeout=0x7fb90511c520, result=0x7fb90511c4e8) at ../../../head/libraries/libldap/result.c:120 #14 0x000055a093724e35 in ldap_back_search (op=0x7fb8f0000be0, rs=0x7fb90511d990) at ../../../../head/servers/slapd/back-ldap/search.c:317 #15 0x000055a0936ff157 in overlay_op_walk (op=0x7fb8f0000be0, --Type <RET> for more, q to quit, c to continue without paging-- rs=0x7fb90511d990, which=op_search, oi=0x55a0943711d0, on=0x0) at ../../../head/servers/slapd/backover.c:706 #16 0x000055a0936ff417 in over_op_func (op=0x7fb8f0000be0, rs=0x7fb90511d990, which=op_search) at ../../../head/servers/slapd/backover.c:766 #17 0x000055a0936ff59b in over_op_search (op=0x7fb8f0000be0, rs=0x7fb90511d990) at ../../../head/servers/slapd/backover.c:796 #18 0x000055a09365d201 in fe_op_search (op=0x7fb8f0000be0, rs=0x7fb90511d990) at ../../../head/servers/slapd/search.c:426 #19 0x000055a09365c9fa in do_search (op=0x7fb8f0000be0, rs=0x7fb90511d990) at ../../../head/servers/slapd/search.c:267 #20 0x000055a093658e0c in connection_operation (ctx=0x7fb90511daf0, arg_v=0x7fb8f0000be0) at ../../../head/servers/slapd/connection.c:1113 #21 0x000055a09365956b in connection_read_thread (ctx=0x7fb90511daf0, argv=0x10) at ../../../head/servers/slapd/connection.c:1265 #22 0x00007fb9121feea3 in ldap_int_thread_pool_wrapper (xpool=0x55a094357ac0) at ../../../head/libraries/libldap/tpool.c:1053 #23 0x00007fb911b8c450 in start_thread (arg=0x7fb90511e640) at pthread_create.c:481 #24 0x00007fb911aaed53 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95 (gdb) frame 11 #11 0x00007fb9121b8b40 in try_read1msg (ld=0x7fb8fc124d70, msgid=3, all=0, lc=0x7fb8fc128180, result=0x7fb90511c4e8) at ../../../head/libraries/libldap/result.c:680 680 refer_cnt = ldap_chase_v3referrals( ld, lr, refs, (gdb) l 675 if ( ber_scanf( &tmpber, "{v}", &refs ) == LBER_ERROR ) { 676 rc = LDAP_DECODING_ERROR; 677 678 } else { 679 /* Note: refs array is freed by ldap_chase_v3referrals */ 680 refer_cnt = ldap_chase_v3referrals( ld, lr, refs, 681 1, &lr->lr_res_error, &hadref ); 682 if ( refer_cnt > 0 ) { 683 /* successfully chased reference */ 684 /* If haven't got end search, set chasing referrals */ (gdb) p *lr $7 = {lr_msgid = 3, lr_status = 1, lr_refcnt = 1, lr_outrefcnt = 1, lr_abandoned = 0, lr_origid = 3, lr_parentcnt = 0, lr_res_msgtype = 115, lr_res_errno = 0, lr_res_error = 0x0, lr_res_matched = 0x0, lr_ber = 0x7fb8f0139eb0, lr_conn = 0x7fb8fc128180, lr_dn = {bv_len = 17, bv_val = 0x7fb8f0128b79 "dc=example,dc=com\n\001\002\n\001"}, lr_parent = 0x0, lr_child = 0x0, lr_refnext = 0x0, lr_prev = 0x0, lr_next = 0x0} (gdb)

The problem appears to be due to recursion in try_read1msg() when chasing a referral. In this case it's processing msgid 3 and then while looking for response to msgid 5 it sees another response to msgid 3. It looks up the corresponding request and sees it already has a non-zero lr_refcnt and assert fails there.