[Date Prev][Date Next] [Chronological] [Thread] [Top]
(ITS#5853) LDAP search crashes when chasing multiple referrals

To: openldap-its@OpenLDAP.org
Subject: (ITS#5853) LDAP search crashes when chasing multiple referrals
From: jsafrane@redhat.com
Date: Tue, 9 Dec 2008 15:31:47 GMT
Full_Name: Jan Safranek
Version: 2.4.13
OS: Linux. Fedora 9, x86_64
URL: http://people.redhat.com/jsafrane/openldap-referral-crash/
Submission from: (NULL) (89.102.11.105)


Following ldapsearch crashes when referral chasing is enabled in very unusual
environment with many AD servers referring to each other (I had to increase
refhoplimit to chase all the referrals).

$ ldapsearch -x -C -D
cn=uzivatelk,ou=Services,ou=BOUDA,ou=administrace,dc=broken,dc=net -w
'mojeheslo' -b "dc=broken,dc=net" -h f9 "(sAMAccountName=uzivatel)"

ldapsearch: sockbuf.c:88: ber_sockbuf_ctrl: Assertion `sb != ((void *)0)'
failed.

You can find the stack trace below and ldapsearch -d -1 output at
http://people.redhat.com/jsafrane/openldap-referral-crash/, together with LDAP
traffic in pcap format.

IMO, if there are more referrals involved (A refers to B, which refers to C),
wait4msg() and try_read1msg() functions are called recursively several times.
When referral to C is being resolved, the stack looks like this:

1: try_read1msg
2: wait4msg
3: ldap_result
...
4: ldap_chase_v3referrals
5: try_read1msg
6: wait4msg
7: ldap_result
...
8: ldap_chase_v3referrals
9: try_read1msg
10: ldap_result
11: wait4msg
12: do_search
13: main

Looking at the wait4msg(), result.c:393, it goes through all connections inside
LDAP structure:
for ( lc = ld->ld_conns;
        rc == LDAP_MSG_X_KEEP_LOOKING && lc != NULL; )
{
        if ( lc->lconn_status == LDAP_CONNST_CONNECTED &&
                ldap_is_read_ready( ld, lc->lconn_sb ) )
        {
<...mutexes...>
                rc = try_read1msg( ld, msgid, all, &lc, result );
<...mutexes...>
                if ( lc == NULL ) {
                        /* if lc gets free()'d,
                         * there's no guarantee
                         * lc->lconn_next is still
                         * sane; better restart
                         * (ITS#4405) */
                        lc = ld->ld_conns;

                        /* don't get to next conn! */
                        break;
                }
        }

        /* next conn */
        lc = lc->lconn_next;
}


And try_read1msg() can release the connection and change the list of
connections, see result.c:944:

ldap_free_connection( ld, lc, 0, 1 );
<...mutexes...>
lc = *lcp = NULL;

The calling wait4msg() expects that called try_read1msg() may free a connection
and does not crash. But if more wait4msg() are called recursively, the "bottom
ones", #6 and #11 in my stack example above, do not know about the change which
try_read1msg() in #1 has made and can hold already freed 'lc' pointer -> crash.


IMHO there should be some other check, that ensures that wait4msg() restarts the
loop even if some inner try_read1msg() modifies the list. Or there could be some
ldap_use_connecion() in try_read1msg() when referrals are being chased, so the
connection does get freed only by the right try_read1msg() - #5 in my case and
not #1. However, my knowledge of OpenLDAP internals is somewhat limited and I am
not able to tell which way is the best.

It's quite hard to reproduce the bug, the packets must arrive in the right
order, so the connection to B is being freed when referral to C is being chased.
I am not able to reproduce it in more controlled environment, the log is quite
huge and it contains some other not so interesting referrals. The connection,
which is freed too early, is connection to 'sec.broken.net' - look for the last
'ldap_free_connection: actually freed' in the log.

I hope my explanation above is somewhat readable and I didn't confuse you too
much :). Do not hesitate to ask for specific details.


Here is the promised real stack trace. It asserts when the 'lc' in wait4msg()
has been freed by previous call to try_read1msg.
 
(gdb) bt full
#0  0x0000003b49632215 in raise () from /lib64/libc.so.6
No symbol table info available.
#1  0x0000003b49633d83 in abort () from /lib64/libc.so.6
No symbol table info available.
#2  0x0000003b4962b039 in __assert_fail () from /lib64/libc.so.6
No symbol table info available.
#3  0x000000000044d4b1 in ber_sockbuf_ctrl (sb=0x0, opt=8, arg=0x0) at
sockbuf.c:88
	p = (Sockbuf_IO_Desc *) 0x452f65
	ret = 0
	__PRETTY_FUNCTION__ = "ber_sockbuf_ctrl"
#4  0x0000000000416222 in try_read1msg (ld=0x1b80fa0, msgid=18, all=1,
lcp=0x7fffe4f67ae8, result=0x7fffe4f67be8) at result.c:1190
	ber = (BerElement *) 0x1b8c040
	newmsg = (LDAPMessage *) 0x1b91ca0
	l = (LDAPMessage *) 0x0
	prev = (LDAPMessage *) 0x1b8d370
	id = 2
	idx = 0
	tag = 115
	len = 78
	foundit = 0
	lr = (LDAPRequest *) 0x0
	tmplr = (LDAPRequest *) 0x1b8d220
	dummy_lr = {lr_msgid = 0, lr_status = 0, lr_refcnt = 0, lr_outrefcnt = 0,
lr_abandoned = 0, lr_origid = 0, lr_parentcnt = 0, 
  lr_res_msgtype = 0, lr_res_errno = 0, lr_res_error = 0x0, lr_res_matched =
0x0, lr_ber = 0x0, lr_conn = 0x0, lr_dn = {bv_len = 0, bv_val = 0x0}, 
  lr_parent = 0x0, lr_child = 0x0, lr_refnext = 0x0, lr_prev = 0x0, lr_next =
0x0}
	lc = (LDAPConn *) 0x1b8e3e0
	tmpber = {ber_opts = {lbo_valid = 2, lbo_options = 1, lbo_debug = -1}, ber_tag
= 0, ber_len = 87, ber_usertag = 0, 
  ber_buf = 0x1b8c0a0 "\002\001\005s\204", ber_ptr = 0x1b8c0f7 "", ber_end =
0x1b8c0f7 "", ber_sos = 0x0, ber_rwptr = 0x0, ber_memctx = 0x0}
	rc = -2
	refer_cnt = 1
	hadref = 1
	simple_request = 0
	err = 5
	lderr = 1
	__PRETTY_FUNCTION__ = "try_read1msg"
	bv_nod = {bv_len = 22, bv_val = 0x452b0b "1.3.6.1.4.1.1466.20036"}
#5  0x0000000000414c67 in wait4msg (ld=0x1b80fa0, msgid=18, all=1,
timeout=0x7fffe4f67bf0, result=0x7fffe4f67be8) at result.c:402
	err = 0
	lc_ready = 0
	rc = -2
	tv = {tv_sec = 0, tv_usec = 100000}
	tv0 = {tv_sec = 0, tv_usec = 100000}
	start_time_tv = {tv_sec = 1228828417, tv_usec = 878311}
	tvp = (struct timeval *) 0x7fffe4f67b10
	lc = (LDAPConn *) 0x1b8e3e0
	__PRETTY_FUNCTION__ = "wait4msg"
#6  0x0000000000414433 in ldap_result (ld=0x1b80fa0, msgid=18, all=1,
timeout=0x7fffe4f67bf0, result=0x7fffe4f67be8) at result.c:127
	lm = (LDAPMessage *) 0x0
	rc = 18
	__PRETTY_FUNCTION__ = "ldap_result"
#7  0x0000000000428313 in ldap_new_connection (ld=0x1b80fa0,
srvlist=0x7fffe4f67df0, use_ldsb=0, connect=1, bind=0x7fffe4f67dc0) at
request.c:560
	tv = {tv_sec = 0, tv_usec = 100000}
	res = (LDAPMessage *) 0x0
	msgid = 18
	rc = 0
	passwd = {bv_len = 0, bv_val = 0x0}
	err = 1
	savedefconn = (LDAPConn *) 0x1b8a380
	lc = (LDAPConn *) 0x1b8c690
	async = 0
	__PRETTY_FUNCTION__ = "ldap_new_connection"
---Type <return> to continue, or q <return> to quit---
#8  0x00000000004276b5 in ldap_send_server_request (ld=0x1b80fa0, ber=0x1b8d290,
msgid=17, parentreq=0x1b8a6e0, srvlist=0x7fffe4f67df0, lc=0x0, 
    bind=0x7fffe4f67dc0) at request.c:207
	lr = (LDAPRequest *) 0x1b8d290
	incparent = 1
	rc = 389
#9  0x0000000000429be6 in ldap_chase_v3referrals (ld=0x1b80fa0, lr=0x1b8cb40,
refs=0x0, sref=1, errstrp=0x1b8cb70, hadrefp=0x7fffe4f67f2c)
    at request.c:1209
	unfollowed = 0x0
	unfollowedcnt = 0
	origreq = (LDAPRequest *) 0x1b8a6e0
	srv = (LDAPURLDesc *) 0x1b8c7b0
	ber = (BerElement *) 0x1b8d290
	refarray = (char **) 0x1b8c670
	lc = (LDAPConn *) 0x0
	rc = 0
	count = 0
	i = 0
	j = 0
	id = 17
	rinfo = {ri_msgid = 2, ri_request = 99, ri_url = 0x1b91c30
"ldap://DomainDnsZones.sec.broken.net/DC=DomainDnsZones,DC=sec,DC=broken,DC=net"}
#10 0x000000000041553d in try_read1msg (ld=0x1b80fa0, msgid=-1, all=0,
lcp=0x7fffe4f680e8, result=0x7fffe4f68228) at result.c:729
	refs = (char **) 0x1b8c670
	ber = (BerElement *) 0x1b8ae00
	newmsg = (LDAPMessage *) 0x0
	l = (LDAPMessage *) 0x1e4f68080
	prev = (LDAPMessage *) 0x7fffe4f68080
	id = 2
	idx = 0
	tag = 115
	len = 80
	foundit = 0
	lr = (LDAPRequest *) 0x1b8cb40
	tmplr = (LDAPRequest *) 0x1b8a550
	dummy_lr = {lr_msgid = 0, lr_status = 0, lr_refcnt = 0, lr_outrefcnt = 0,
lr_abandoned = 0, lr_origid = 0, lr_parentcnt = 0, 
  lr_res_msgtype = 0, lr_res_errno = 0, lr_res_error = 0x0, lr_res_matched =
0x0, lr_ber = 0x0, lr_conn = 0x0, lr_dn = {bv_len = 0, bv_val = 0x0}, 
  lr_parent = 0x0, lr_child = 0x0, lr_refnext = 0x0, lr_prev = 0x0, lr_next =
0x0}
	lc = (LDAPConn *) 0x1b8beb0
	tmpber = {ber_opts = {lbo_valid = 2, lbo_options = 1, lbo_debug = -1}, ber_tag
= 0, ber_len = 89, ber_usertag = 0, 
  ber_buf = 0x1b8c600 "\002\001\003s\204", ber_ptr = 0x1b8c659 "", ber_end =
0x1b8c659 "", ber_sos = 0x0, ber_rwptr = 0x0, ber_memctx = 0x0}
	rc = -2
	refer_cnt = 0
	hadref = 0
	simple_request = 0
	err = 4
	lderr = 1
	__PRETTY_FUNCTION__ = "try_read1msg"
	bv_nod = {bv_len = 22, bv_val = 0x452b0b "1.3.6.1.4.1.1466.20036"}
#11 0x0000000000414c67 in wait4msg (ld=0x1b80fa0, msgid=-1, all=0, timeout=0x0,
result=0x7fffe4f68228) at result.c:402
	err = 0
	lc_ready = 0
	rc = -2
	tv = {tv_sec = 0, tv_usec = 0}
	tv0 = {tv_sec = 0, tv_usec = 0}
	start_time_tv = {tv_sec = 0, tv_usec = 0}
	tvp = (struct timeval *) 0x0
	lc = (LDAPConn *) 0x1b8beb0
	__PRETTY_FUNCTION__ = "wait4msg"
#12 0x0000000000414433 in ldap_result (ld=0x1b80fa0, msgid=-1, all=0,
timeout=0x0, result=0x7fffe4f68228) at result.c:127
	lm = (LDAPMessage *) 0x0
	rc = 100
	__PRETTY_FUNCTION__ = "ldap_result"
---Type <return> to continue, or q <return> to quit---
#13 0x0000000000408dbf in dosearch (ld=0x1b80fa0, base=0x1b7f5e0
"dc=broken,dc=net", scope=2, filtpatt=0x0, 
    value=0x7fffe4f6b881 "(sAMAccountName=uzivatel)", attrs=0x0, attrsonly=0,
sctrls=0x0, cctrls=0x0, timeout=0x0, sizelimit=-1) at ldapsearch.c:1280
	filter = 0x7fffe4f6b881 "(sAMAccountName=uzivatel)"
	rc = 0
	nresponses = 7
	nentries = 1
	nreferences = 6
	nextended = 0
	npartial = 0
	res = (LDAPMessage *) 0x0
	msg = (LDAPMessage *) 0x0
	msgid = 2
	retoid = 0x0
	retdata = (struct berval *) 0x0
	nresponses_psearch = -1
	cancel_msgid = -1
#14 0x00000000004084cc in main (argc=14, argv=0x7fffe4f6a4f8) at
ldapsearch.c:1112
	filtpattern = 0x7fffe4f6b881 "(sAMAccountName=uzivatel)"
	attrs = (char **) 0x0
	line = '\0' <repeats 1344 times>,
"\006\000\000\000\000\000\000\000\200\220öäÿ\177\000\000\220\220öäÿ\177\000\000\231C!J;\000\000\000\237C!J;\000\000\000\023pdI;",
'\0' <repeats 47 times>,
"º\005\000\000\004\000\000\000\000\000\000\000à\220öäÿ\177\000\000ð\220öäÿ\177\000\000ÔB!J;\000\000\000ØB!J;\000\000\000\023pdI;",
'\0' <repeats 47 times>, "º\005\000\000X\220öäÿ\177\000\000x\220öäÿ\177\000\000
\220öäÿ\177\000\000p\220öäÿ\177\000\000Ð\213öäÿ\177", '\0' <repeats 18 times>,
"\205ç Iøÿÿÿ\000\000\000\000\000\000\000\000èÔAI;\000\000\000"...
	fp = (FILE *) 0x0
	rc = 4213523
	rc1 = 0
	i = 0
	first = 32767
	ld = (LDAP *) 0x1b80fa0
	seber = (BerElement *) 0x0
	vrber = (BerElement *) 0x0
	syncber = (BerElement *) 0x0
	syncbvalp = (struct berval *) 0x0
	err = 4216832
(gdb)
Prev by Date: Re: (ITS#5840) bdb_online_index and shutdown
Next by Date: Re: (ITS#5853) LDAP search crashes when chasing multiple referrals
Index(es):
- Chronological
- Thread