openldap-bugs

openldap-bugs@openldap.org

1 participants
20961 discussions

(ITS#5261)
by abartlet＠samba.org 05 Dec '07

05 Dec '07

--=-sj7eji9lwVRllTKtUS/q Content-Type: text/plain Content-Transfer-Encoding: quoted-printable BTW, the SVN URL is: svn://svnanon.samba.org/samba/branches/SAMBA_4_0 --=20 Andrew Bartlett http://samba.org/~abartlet/ Authentication Developer, Samba Team http://samba.org Samba Developer, Red Hat Inc. --=-sj7eji9lwVRllTKtUS/q Content-Type: application/pgp-signature; name=signature.asc Content-Description: This is a digitally signed message part -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.7 (GNU/Linux) iD8DBQBHVmdyz4A8Wyi0NrsRAoR8AKClVLbCKEm+OVUqGX8lNYVAyt7QzgCfR9vh 0klH1DFlRZKV6POw3tC6lnQ= =aa6D -----END PGP SIGNATURE----- --=-sj7eji9lwVRllTKtUS/q--

1 0

(ITS#5261) Samba4 can 'hang' OpenLDAP slapd
by abartlet＠samba.org 05 Dec '07

05 Dec '07

Full_Name: Andrew Bartlett Version: cvs 2007-12-05 OS: Fedora 8 URL: ftp://ftp.openldap.org/incoming/ Submission from: (NULL) (59.167.251.137) Using Samba4's 'make test', I can hang OpenLDAP's slapd. Samba4 SVN -r 26305 That is, it will not process any further requests, but is waiting in pthread_join(), not stuck somewhere else. OpenLDAP was built with: `dirname $0`/configure --enable-overlays=yes --enable-modules --enable-dynamic --enable-syncprov=yes Samba4 was built with: CC="ccache gcc" CFLAGS="-O3" ./configure --enable-developer -C --prefix=/data/samba/samba4/prefix --with-winbindd-socket-dir=/data/samba/samba4/prefix/wb Samba4 testsuite command line: OPENLDAP_PATH=/usr/local/libexec:/usr/local/sbin TEST_LDAP=yes make test This hangs during the 'provision' processing. Note that this outputs an ldapi:// URL. Using that URL, this test shows it's not just samba that is stuck: ldapadd -H ldapi://%2Fhome%2Fdata%2Fsamba%2Fsamba4%2Fclean%2Fsource%2Fst%2Fdc%2Fprivate%2Fldap%2Fldapi -f st/dc/private/ldap/samba.example.com.ldif -D cn=Manager,dc=samba,dc=example,dc=com -w localdcpass -x

1 0

Re: (ITS#5257) test008 hanging in bdb
by hyc＠symas.com 05 Dec '07

05 Dec '07

h.b.furuseth(a)usit.uio.no wrote: > Hah. thr_debug found it (at least I presume it's the same bug) after 70 > iterations over test008. > > Compiled with > CPPFLAGS='-DLDAP_THREAD_DEBUG -DLDAP_REL_ENG' CFLAGS='-O0 -g' > run with export LDAP_THREAD_DEBUG=nocount > > backtrace and testrun directory: > http://folk.uio.no/hbf/test008bug-071204.tbz > > slapd.1.log ends with: > > ====> bdb_cache_delete( 146 ) > thr_debug.c:1024: ldap_pvt_thread_mutex_unlock error: !THREAD_MUTEX_OWNER( mutex ) > > The mutex owner is ldap_debug_thread_none, i.e. the mutex is not locked. > > It's cache.c:874:bdb_cache_entryinfo_unlock( *eip ); in bdb_cache_find_id(). > #3 0x00000000004e1df9 in bdb_cache_find_id (op=0x1ebb46a0, tid=0x0, id=4, eip=0x45809ad0, flag=1, locker=38, > lock=0x45809b20) at cache.c:874 > > > I had to patch thr_posix.c a bit to detect Linux NPTL threads: > > diff -u -2 -r1.50 thr_posix.c > --- thr_posix.c 25 Oct 2007 04:42:40 -0000 1.50 > +++ thr_posix.c 4 Dec 2007 23:06:29 -0000 > @@ -45,6 +45,6 @@ > #ifdef LDAP_THREAD_DEBUG > # if defined LDAP_INT_THREAD_MUTEXATTR /* May be defined in CPPFLAGS */ > -# elif defined HAVE_PTHREAD_KILL_OTHER_THREADS_NP > - /* LinuxThreads hack */ > +# elif 1 || defined HAVE_PTHREAD_KILL_OTHER_THREADS_NP > + /* LinuxThreads and NPTL hack */ > # define LDAP_INT_THREAD_MUTEXATTR PTHREAD_MUTEX_ERRORCHECK_NP > # else Ah, that one actually makes sense. Fix in HEAD. Unfortunately, this code path is only being triggered because of the other bug, it's not the root cause. -- -- Howard Chu Chief Architect, Symas Corp. http://www.symas.com Director, Highland Sun http://highlandsun.com/hyc/ Chief Architect, OpenLDAP http://www.openldap.org/project/

1 0

Re: (ITS#5161) delta-syncrepl mutex lockup
by quanah＠zimbra.com 05 Dec '07

05 Dec '07

Just hit this again today. (gdb) info threads 10 Thread 1082132800 (LWP 15704) 0xffffffffff600410 in ?? () * 9 Thread 1090525504 (LWP 15705) 0x00000038dcc0c758 in __lll_mutex_lock_wait () from /lib64/libpthread.so.0 8 Thread 1098918208 (LWP 15706) 0x00000038dcc0c758 in __lll_mutex_lock_wait () from /lib64/libpthread.so.0 7 Thread 1107310912 (LWP 15707) 0x00000038dcc0c758 in __lll_mutex_lock_wait () from /lib64/libpthread.so.0 6 Thread 1115703616 (LWP 32142) 0x00000038dcc0c758 in __lll_mutex_lock_wait () from /lib64/libpthread.so.0 5 Thread 1124096320 (LWP 1167) 0x00000038dcc0c758 in __lll_mutex_lock_wait () from /lib64/libpthread.so.0 4 Thread 1132489024 (LWP 1168) 0x00000038dcc0c758 in __lll_mutex_lock_wait () from /lib64/libpthread.so.0 3 Thread 1140881728 (LWP 1431) 0x00000038dcc0c758 in __lll_mutex_lock_wait () from /lib64/libpthread.so.0 2 Thread 1149274432 (LWP 1432) 0x00000038dcc0c758 in __lll_mutex_lock_wait () from /lib64/libpthread.so.0 1 Thread 46912515736208 (LWP 15700) 0x00000038dcc074e5 in pthread_join () from /lib64/libpthread.so.0 (gdb) thread 10 [Switching to thread 10 (Thread 1082132800 (LWP 15704))]#0 0xffffffffff600410 in ?? () (gdb) bt #0 0xffffffffff600410 in ?? () #1 0x00000038dc0862dd in time () from /lib64/libc.so.6 #2 0x0000000000428530 in slapd_daemon_task (ptr=0x0) at daemon.c:2033 #3 0x00000038dcc061b5 in start_thread () from /lib64/libpthread.so.0 #4 0x00000038dc0cd36d in clone () from /lib64/libc.so.6 #5 0x0000000000000000 in ?? () (gdb) thread 9 [Switching to thread 9 (Thread 1090525504 (LWP 15705))]#0 0x00000038dcc0c758 in __lll_mutex_lock_wait () from /lib64/libpthread.so.0 (gdb) bt #0 0x00000038dcc0c758 in __lll_mutex_lock_wait () from /lib64/libpthread.so.0 #1 0x00000038dcc087c4 in _L_mutex_lock_107 () from /lib64/libpthread.so.0 #2 0x00000038dcc08263 in pthread_mutex_lock () from /lib64/libpthread.so.0 #3 0x00002aaaaad1685e in ldap_pvt_thread_mutex_lock (mutex=0x7f7fa58) at thr_posix.c:333 #4 0x00002aaaae660500 in accesslog_op_mod (op=0xc48fc00, rs=0x41000d00) at accesslog.c:1236 #5 0x00000000004a0cfe in overlay_op_walk (op=0xc48fc00, rs=0x41000d00, which=op_delete, oi=0x7f86c40, on=0x7f868c0) at backover.c:640 #6 0x00000000004a0f90 in over_op_func (op=0xc48fc00, rs=0x41000d00, which=op_delete) at backover.c:702 #7 0x00000000004a10da in over_op_delete (op=0xc48fc00, rs=0x41000d00) at backover.c:754 #8 0x000000000044c4f9 in fe_op_delete (op=0xc48fc00, rs=0x41000d00) at delete.c:179 #9 0x000000000044c126 in do_delete (op=0xc48fc00, rs=0x41000d00) at delete.c:91 #10 0x000000000042c2da in connection_operation (ctx=0x41000de0, arg_v=0xc48fc00) at connection.c:1133 #11 0x00002aaaaad154ba in ldap_int_thread_pool_wrapper (xpool=0x7c0ff00) at tpool.c:478 #12 0x00000038dcc061b5 in start_thread () from /lib64/libpthread.so.0 #13 0x00000038dc0cd36d in clone () from /lib64/libc.so.6 #14 0x0000000000000000 in ?? () (gdb) thread 8 [Switching to thread 8 (Thread 1098918208 (LWP 15706))]#0 0x00000038dcc0c758 in __lll_mutex_lock_wait () from /lib64/libpthread.so.0 (gdb) bt #0 0x00000038dcc0c758 in __lll_mutex_lock_wait () from /lib64/libpthread.so.0 #1 0x00000038dcc087c4 in _L_mutex_lock_107 () from /lib64/libpthread.so.0 #2 0x00000038dcc08263 in pthread_mutex_lock () from /lib64/libpthread.so.0 #3 0x00002aaaaad1685e in ldap_pvt_thread_mutex_lock (mutex=0x7f7fa58) at thr_posix.c:333 #4 0x00002aaaae660500 in accesslog_op_mod (op=0xd5f7600, rs=0x41801ca0) at accesslog.c:1236 #5 0x00000000004a0cfe in overlay_op_walk (op=0xd5f7600, rs=0x41801ca0, which=op_delete, oi=0x7f86c40, on=0x7f868c0) at backover.c:640 #6 0x00000000004a0f90 in over_op_func (op=0xd5f7600, rs=0x41801ca0, which=op_delete) at backover.c:702 #7 0x00000000004a10da in over_op_delete (op=0xd5f7600, rs=0x41801ca0) at backover.c:754 #8 0x000000000044c4f9 in fe_op_delete (op=0xd5f7600, rs=0x41801ca0) at delete.c:179 #9 0x000000000044c126 in do_delete (op=0xd5f7600, rs=0x41801ca0) at delete.c:91 #10 0x000000000042c2da in connection_operation (ctx=0x41801de0, arg_v=0xd5f7600) at connection.c:1133 #11 0x000000000042c7b0 in connection_read_thread (ctx=0x41801de0, argv=0x1d) at connection.c:1261 #12 0x00002aaaaad154ba in ldap_int_thread_pool_wrapper (xpool=0x7c0ff00) at tpool.c:478 #13 0x00000038dcc061b5 in start_thread () from /lib64/libpthread.so.0 #14 0x00000038dc0cd36d in clone () from /lib64/libc.so.6 #15 0x0000000000000000 in ?? () (gdb) thread 7 [Switching to thread 7 (Thread 1107310912 (LWP 15707))]#0 0x00000038dcc0c758 in __lll_mutex_lock_wait () from /lib64/libpthread.so.0 (gdb) bt #0 0x00000038dcc0c758 in __lll_mutex_lock_wait () from /lib64/libpthread.so.0 #1 0x00000038dcc087c4 in _L_mutex_lock_107 () from /lib64/libpthread.so.0 #2 0x00000038dcc08263 in pthread_mutex_lock () from /lib64/libpthread.so.0 #3 0x00002aaaaad1685e in ldap_pvt_thread_mutex_lock (mutex=0x7f7fa58) at thr_posix.c:333 #4 0x00002aaaae660500 in accesslog_op_mod (op=0xc48f900, rs=0x42002ca0) at accesslog.c:1236 #5 0x00000000004a0cfe in overlay_op_walk (op=0xc48f900, rs=0x42002ca0, which=op_delete, oi=0x7f86c40, on=0x7f868c0) at backover.c:640 #6 0x00000000004a0f90 in over_op_func (op=0xc48f900, rs=0x42002ca0, which=op_delete) at backover.c:702 #7 0x00000000004a10da in over_op_delete (op=0xc48f900, rs=0x42002ca0) at backover.c:754 #8 0x000000000044c4f9 in fe_op_delete (op=0xc48f900, rs=0x42002ca0) at delete.c:179 #9 0x000000000044c126 in do_delete (op=0xc48f900, rs=0x42002ca0) at delete.c:91 #10 0x000000000042c2da in connection_operation (ctx=0x42002de0, arg_v=0xc48f900) at connection.c:1133 #11 0x000000000042c7b0 in connection_read_thread (ctx=0x42002de0, argv=0x1c) at connection.c:1261 #12 0x00002aaaaad154ba in ldap_int_thread_pool_wrapper (xpool=0x7c0ff00) at tpool.c:478 #13 0x00000038dcc061b5 in start_thread () from /lib64/libpthread.so.0 #14 0x00000038dc0cd36d in clone () from /lib64/libc.so.6 #15 0x0000000000000000 in ?? () (gdb) thread 6 [Switching to thread 6 (Thread 1115703616 (LWP 32142))]#0 0x00000038dcc0c758 in __lll_mutex_lock_wait () from /lib64/libpthread.so.0 (gdb) bt #0 0x00000038dcc0c758 in __lll_mutex_lock_wait () from /lib64/libpthread.so.0 #1 0x00000038dcc087c4 in _L_mutex_lock_107 () from /lib64/libpthread.so.0 #2 0x00000038dcc08263 in pthread_mutex_lock () from /lib64/libpthread.so.0 #3 0x00002aaaaad1685e in ldap_pvt_thread_mutex_lock (mutex=0x7f7fa58) at thr_posix.c:333 #4 0x00002aaaae660500 in accesslog_op_mod (op=0xb20ac00, rs=0x42803d00) at accesslog.c:1236 #5 0x00000000004a0cfe in overlay_op_walk (op=0xb20ac00, rs=0x42803d00, which=op_delete, oi=0x7f86c40, on=0x7f868c0) at backover.c:640 #6 0x00000000004a0f90 in over_op_func (op=0xb20ac00, rs=0x42803d00, which=op_delete) at backover.c:702 #7 0x00000000004a10da in over_op_delete (op=0xb20ac00, rs=0x42803d00) at backover.c:754 #8 0x000000000044c4f9 in fe_op_delete (op=0xb20ac00, rs=0x42803d00) at delete.c:179 #9 0x000000000044c126 in do_delete (op=0xb20ac00, rs=0x42803d00) at delete.c:91 #10 0x000000000042c2da in connection_operation (ctx=0x42803de0, arg_v=0xb20ac00) at connection.c:1133 #11 0x00002aaaaad154ba in ldap_int_thread_pool_wrapper (xpool=0x7c0ff00) at tpool.c:478 #12 0x00000038dcc061b5 in start_thread () from /lib64/libpthread.so.0 #13 0x00000038dc0cd36d in clone () from /lib64/libc.so.6 #14 0x0000000000000000 in ?? () (gdb) thread 5 [Switching to thread 5 (Thread 1124096320 (LWP 1167))]#0 0x00000038dcc0c758 in __lll_mutex_lock_wait () from /lib64/libpthread.so.0 (gdb) bt #0 0x00000038dcc0c758 in __lll_mutex_lock_wait () from /lib64/libpthread.so.0 #1 0x00000038dcc087c4 in _L_mutex_lock_107 () from /lib64/libpthread.so.0 #2 0x00000038dcc08263 in pthread_mutex_lock () from /lib64/libpthread.so.0 #3 0x00002aaaaad1685e in ldap_pvt_thread_mutex_lock (mutex=0x7f7fa58) at thr_posix.c:333 #4 0x00002aaaae660500 in accesslog_op_mod (op=0xd5f7c00, rs=0x43004d00) at accesslog.c:1236 #5 0x00000000004a0cfe in overlay_op_walk (op=0xd5f7c00, rs=0x43004d00, which=op_delete, oi=0x7f86c40, on=0x7f868c0) at backover.c:640 #6 0x00000000004a0f90 in over_op_func (op=0xd5f7c00, rs=0x43004d00, which=op_delete) at backover.c:702 #7 0x00000000004a10da in over_op_delete (op=0xd5f7c00, rs=0x43004d00) at backover.c:754 #8 0x000000000044c4f9 in fe_op_delete (op=0xd5f7c00, rs=0x43004d00) at delete.c:179 #9 0x000000000044c126 in do_delete (op=0xd5f7c00, rs=0x43004d00) at delete.c:91 #10 0x000000000042c2da in connection_operation (ctx=0x43004de0, arg_v=0xd5f7c00) at connection.c:1133 #11 0x00002aaaaad154ba in ldap_int_thread_pool_wrapper (xpool=0x7c0ff00) at tpool.c:478 #12 0x00000038dcc061b5 in start_thread () from /lib64/libpthread.so.0 #13 0x00000038dc0cd36d in clone () from /lib64/libc.so.6 #14 0x0000000000000000 in ?? () (gdb) thread 4 [Switching to thread 4 (Thread 1132489024 (LWP 1168))]#0 0x00000038dcc0c758 in __lll_mutex_lock_wait () from /lib64/libpthread.so.0 (gdb) bt #0 0x00000038dcc0c758 in __lll_mutex_lock_wait () from /lib64/libpthread.so.0 #1 0x00000038dcc087c4 in _L_mutex_lock_107 () from /lib64/libpthread.so.0 #2 0x00000038dcc08263 in pthread_mutex_lock () from /lib64/libpthread.so.0 #3 0x00002aaaaad1685e in ldap_pvt_thread_mutex_lock (mutex=0x7f7fa58) at thr_posix.c:333 #4 0x00002aaaae660500 in accesslog_op_mod (op=0xd5f7900, rs=0x43805ca0) at accesslog.c:1236 #5 0x00000000004a0cfe in overlay_op_walk (op=0xd5f7900, rs=0x43805ca0, which=op_delete, oi=0x7f86c40, on=0x7f868c0) at backover.c:640 #6 0x00000000004a0f90 in over_op_func (op=0xd5f7900, rs=0x43805ca0, which=op_delete) at backover.c:702 #7 0x00000000004a10da in over_op_delete (op=0xd5f7900, rs=0x43805ca0) at backover.c:754 #8 0x000000000044c4f9 in fe_op_delete (op=0xd5f7900, rs=0x43805ca0) at delete.c:179 #9 0x000000000044c126 in do_delete (op=0xd5f7900, rs=0x43805ca0) at delete.c:91 #10 0x000000000042c2da in connection_operation (ctx=0x43805de0, arg_v=0xd5f7900) at connection.c:1133 #11 0x000000000042c7b0 in connection_read_thread (ctx=0x43805de0, argv=0x1d) at connection.c:1261 #12 0x00002aaaaad154ba in ldap_int_thread_pool_wrapper (xpool=0x7c0ff00) at tpool.c:478 #13 0x00000038dcc061b5 in start_thread () from /lib64/libpthread.so.0 #14 0x00000038dc0cd36d in clone () from /lib64/libc.so.6 #15 0x0000000000000000 in ?? () (gdb) thread 3 [Switching to thread 3 (Thread 1140881728 (LWP 1431))]#0 0x00000038dcc0c758 in __lll_mutex_lock_wait () from /lib64/libpthread.so.0 (gdb) bt #0 0x00000038dcc0c758 in __lll_mutex_lock_wait () from /lib64/libpthread.so.0 #1 0x00000038dcc087c4 in _L_mutex_lock_107 () from /lib64/libpthread.so.0 #2 0x00000038dcc08263 in pthread_mutex_lock () from /lib64/libpthread.so.0 #3 0x00002aaaaad1685e in ldap_pvt_thread_mutex_lock (mutex=0x7f7fa58) at thr_posix.c:333 #4 0x00002aaaae660500 in accesslog_op_mod (op=0xd955c00, rs=0x44006d00) at accesslog.c:1236 #5 0x00000000004a0cfe in overlay_op_walk (op=0xd955c00, rs=0x44006d00, which=op_delete, oi=0x7f86c40, on=0x7f868c0) at backover.c:640 #6 0x00000000004a0f90 in over_op_func (op=0xd955c00, rs=0x44006d00, which=op_delete) at backover.c:702 #7 0x00000000004a10da in over_op_delete (op=0xd955c00, rs=0x44006d00) at backover.c:754 #8 0x000000000044c4f9 in fe_op_delete (op=0xd955c00, rs=0x44006d00) at delete.c:179 #9 0x000000000044c126 in do_delete (op=0xd955c00, rs=0x44006d00) at delete.c:91 #10 0x000000000042c2da in connection_operation (ctx=0x44006de0, arg_v=0xd955c00) at connection.c:1133 #11 0x00002aaaaad154ba in ldap_int_thread_pool_wrapper (xpool=0x7c0ff00) at tpool.c:478 #12 0x00000038dcc061b5 in start_thread () from /lib64/libpthread.so.0 #13 0x00000038dc0cd36d in clone () from /lib64/libc.so.6 #14 0x0000000000000000 in ?? () (gdb) thread 2 [Switching to thread 2 (Thread 1149274432 (LWP 1432))]#0 0x00000038dcc0c758 in __lll_mutex_lock_wait () from /lib64/libpthread.so.0 (gdb) bt #0 0x00000038dcc0c758 in __lll_mutex_lock_wait () from /lib64/libpthread.so.0 #1 0x00000038dcc087c4 in _L_mutex_lock_107 () from /lib64/libpthread.so.0 #2 0x00000038dcc08263 in pthread_mutex_lock () from /lib64/libpthread.so.0 #3 0x00002aaaaad1685e in ldap_pvt_thread_mutex_lock (mutex=0x7f7fa58) at thr_posix.c:333 #4 0x00002aaaae660500 in accesslog_op_mod (op=0xd955900, rs=0x44807ca0) at accesslog.c:1236 #5 0x00000000004a0cfe in overlay_op_walk (op=0xd955900, rs=0x44807ca0, which=op_delete, oi=0x7f86c40, on=0x7f868c0) at backover.c:640 #6 0x00000000004a0f90 in over_op_func (op=0xd955900, rs=0x44807ca0, which=op_delete) at backover.c:702 #7 0x00000000004a10da in over_op_delete (op=0xd955900, rs=0x44807ca0) at backover.c:754 #8 0x000000000044c4f9 in fe_op_delete (op=0xd955900, rs=0x44807ca0) at delete.c:179 #9 0x000000000044c126 in do_delete (op=0xd955900, rs=0x44807ca0) at delete.c:91 #10 0x000000000042c2da in connection_operation (ctx=0x44807de0, arg_v=0xd955900) at connection.c:1133 #11 0x000000000042c7b0 in connection_read_thread (ctx=0x44807de0, argv=0x1e) at connection.c:1261 #12 0x00002aaaaad154ba in ldap_int_thread_pool_wrapper (xpool=0x7c0ff00) at tpool.c:478 #13 0x00000038dcc061b5 in start_thread () from /lib64/libpthread.so.0 #14 0x00000038dc0cd36d in clone () from /lib64/libc.so.6 #15 0x0000000000000000 in ?? () (gdb) thread 1 [Switching to thread 1 (Thread 46912515736208 (LWP 15700))]#0 0x00000038dcc074e5 in pthread_join () from /lib64/libpthread.so.0 (gdb) bt #0 0x00000038dcc074e5 in pthread_join () from /lib64/libpthread.so.0 #1 0x00002aaaaad16767 in ldap_pvt_thread_join (thread=1082132800, thread_return=0x0) at thr_posix.c:193 #2 0x0000000000429bd3 in slapd_daemon () at daemon.c:2579 #3 0x0000000000412113 in main (argc=10, argv=0x7fffd07d4fe8) at main.c:859 --Quanah -- Quanah Gibson-Mount Principal Software Engineer Zimbra, Inc -------------------- Zimbra :: the leader in open source messaging and collaboration

1 0

Re: (ITS#5257) test008 hanging in bdb
by hyc＠symas.com 05 Dec '07

05 Dec '07

1 0

Re: (ITS#5257) test008 hanging in bdb
by h.b.furuseth＠usit.uio.no 05 Dec '07

05 Dec '07

Hah. thr_debug found it (at least I presume it's the same bug) after 70 iterations over test008. Compiled with CPPFLAGS='-DLDAP_THREAD_DEBUG -DLDAP_REL_ENG' CFLAGS='-O0 -g' run with export LDAP_THREAD_DEBUG=nocount backtrace and testrun directory: http://folk.uio.no/hbf/test008bug-071204.tbz slapd.1.log ends with: ====> bdb_cache_delete( 146 ) thr_debug.c:1024: ldap_pvt_thread_mutex_unlock error: !THREAD_MUTEX_OWNER( mutex ) The mutex owner is ldap_debug_thread_none, i.e. the mutex is not locked. It's cache.c:874:bdb_cache_entryinfo_unlock( *eip ); in bdb_cache_find_id(). #3 0x00000000004e1df9 in bdb_cache_find_id (op=0x1ebb46a0, tid=0x0, id=4, eip=0x45809ad0, flag=1, locker=38, lock=0x45809b20) at cache.c:874 I had to patch thr_posix.c a bit to detect Linux NPTL threads: diff -u -2 -r1.50 thr_posix.c --- thr_posix.c 25 Oct 2007 04:42:40 -0000 1.50 +++ thr_posix.c 4 Dec 2007 23:06:29 -0000 @@ -45,6 +45,6 @@ #ifdef LDAP_THREAD_DEBUG # if defined LDAP_INT_THREAD_MUTEXATTR /* May be defined in CPPFLAGS */ -# elif defined HAVE_PTHREAD_KILL_OTHER_THREADS_NP - /* LinuxThreads hack */ +# elif 1 || defined HAVE_PTHREAD_KILL_OTHER_THREADS_NP + /* LinuxThreads and NPTL hack */ # define LDAP_INT_THREAD_MUTEXATTR PTHREAD_MUTEX_ERRORCHECK_NP # else (BTW, I tried to put it in ftp://ftp.openldap.org/incoming/Hallvard-Furuseth-071203.tbz but got disk full.) -- Hallvard

1 0

(ITS#5260) delta-syncrepl infinite loop
by quanah＠zimbra.com 04 Dec '07

04 Dec '07

Full_Name: Quanah Gibson-Mount Version: 2.3.39 OS: Linux 2.6 URL: ftp://ftp.openldap.org/incoming/ Submission from: (NULL) (76.21.80.71) If the sync cookie is stale between a replica and the master, and the accesslog DB is emtpy, delta sync starts slamming the master with search requests: Dec 4 13:43:33 freelancer slapd[30805]: conn=3 op=19290 SEARCH RESULT tag=101 err=0 nentries=0 text= Dec 4 13:43:33 freelancer slapd[30805]: conn=3 op=19291 SRCH base="cn=accesslog" scope=2 deref=0 filter="(&(objectClass=auditWriteObject)(reqResult=0))" Dec 4 13:43:33 freelancer slapd[30805]: conn=3 op=19291 SRCH attr=reqDN reqType reqMod reqNewRDN reqDeleteOldRDN reqNewSuperior entryCSN Dec 4 13:43:33 freelancer slapd[30805]: conn=3 op=19291 SEARCH RESULT tag=101 err=4096 nentries=0 text=sync cookie is stale Dec 4 13:43:33 freelancer slapd[30805]: conn=3 op=19292 SRCH base="" scope=2 deref=0 filter="(objectClass=*)" Dec 4 13:43:33 freelancer slapd[30805]: conn=3 op=19292 SRCH attr=* + Dec 4 13:43:33 freelancer slapd[30805]: conn=3 op=19292 SEARCH RESULT tag=101 err=0 nentries=0 text= Dec 4 13:43:33 freelancer slapd[30805]: conn=3 op=19293 SRCH base="cn=accesslog" scope=2 deref=0 filter="(&(objectClass=auditWriteObject)(reqResult=0))" Dec 4 13:43:33 freelancer slapd[30805]: conn=3 op=19293 SRCH attr=reqDN reqType reqMod reqNewRDN reqDeleteOldRDN reqNewSuperior entryCSN Dec 4 13:43:33 freelancer slapd[30805]: conn=3 op=19293 SEARCH RESULT tag=101 err=4096 nentries=0 text=sync cookie is stale Dec 4 13:43:33 freelancer slapd[30805]: conn=3 op=19294 SRCH base="" scope=2 deref=0 filter="(objectClass=*)" Dec 4 13:43:33 freelancer slapd[30805]: conn=3 op=19294 SRCH attr=* + (as you can see, nearly 20,000 ops in just a few seconds)

1 0

(ITS#5259) SIGSEGV in slap_auxprop_store during SASL/OTP bind
by dwhite＠olp.net 04 Dec '07

04 Dec '07

Full_Name: Dan White Version: 2.3.39 OS: Linux URL: http://support.olp.net/ldap/log.txt Submission from: (NULL) (65.161.252.42) I'm experiencing crashes in slapd when attempting to bind via SASL using the OTP mech. I'm using openldap version 2.3.39 for both slapd and my ldap utils (ldapsearch). I'm using the bdb backend. I'm also using Debian Etch with the following versions of software: Cyrus SASL 2.1.22(.dfsg1-8) libdb 4.2.52(+dfsg-2) libc6 2.3.6(.ds1-13etch2) I've compiled cyrus sasl to use it's internal implementation of OTP, rather than OPIE: --enable-otp (--with-opie is not enabled) The problem I'm experiencing isn't when I successfully authenticate; that seems to work fine. It's when I run an ldapsearch, but instead of entering an OTP password, I press ctrl-c to cancel the search. >From the shell, when I perform an LDAP search, all appears normal: hiro:~# ldapsearch -Y OTP -U abrown(a)olp.net SASL/OTP authentication started Challenge: otp-md5 497 hi3182 ext Please enter your one-time password:<ctrl-c> hiro:~# However my slapd process dies. Here's a gdb backtrace of the server process: ... Core was generated by `/usr/sbin/slapd'. Program terminated with signal 11, Segmentation fault. #0 0x080b448e in slap_auxprop_store (glob_context=0x0, sparams=0x820b2a0, prctx=0x82351c0, user=0x820a148 "abrown(a)olp.net", ulen=14) at /usr/src/build/openldap/openldap2.3-2.3.39/servers/slapd/sasl.c:478 478 op.o_hdr = conn->c_sasl_bindop->o_hdr; (gdb) bt #0 0x080b448e in slap_auxprop_store (glob_context=0x0, sparams=0x820b2a0, prctx=0x82351c0, user=0x820a148 "abrown(a)olp.net", ulen=14) at /usr/src/build/openldap/openldap2.3-2.3.39/servers/slapd/sasl.c:478 #1 0xb7eb17d7 in sasl_auxprop_store () from /usr/lib/libsasl2.so.2 #2 0xb7973c89 in otp_server_plug_init () from /usr/lib/sasl2/libotp.so.2 #3 0xb7ebde36 in sasl_server_new () from /usr/lib/libsasl2.so.2 #4 0xb7eb6194 in sasl_dispose () from /usr/lib/libsasl2.so.2 #5 0x080b2992 in slap_sasl_close (conn=0xb7ec3618) at /usr/src/build/openldap/openldap2.3-2.3.39/servers/slapd/sasl.c:1331 #6 0x0806cf27 in connection_close (c=0xb75b1148) at /usr/src/build/openldap/openldap2.3-2.3.39/servers/slapd/connection.c:715 #7 0x0806e116 in connection_read (s=12) at /usr/src/build/openldap/openldap2.3-2.3.39/servers/slapd/connection.c:1458 #8 0x0806a49f in slapd_daemon_task (ptr=0x0) at /usr/src/build/openldap/openldap2.3-2.3.39/servers/slapd/daemon.c:2468 #9 0xb7cd3240 in start_thread () from /lib/tls/i686/cmov/libpthread.so.0 #10 0xb7c674ae in clone () from /lib/tls/i686/cmov/libc.so.6 (gdb) quit I've added a debug statement within slap_auxprop_store, so the openldap debug information below will include some additional information about what's being modified. The output can be obtained from: http://support.olp.net/ldap/log.txt Notice the two lines: Dec 3 13:39:06 hiro slapd[11134]: slap_auxprop_store [conn=3]: Getting ready to set cmusaslsecretOTP to md5^I0499^Ihi5935^I0e81b33e30182715^I00000000001196711046. Dec 3 13:39:07 hiro slapd[11134]: slap_auxprop_store [conn=-1]: Getting ready to set cmusaslsecretOTP to md5^I0499^Ihi5935^I0e81b33e30182715^I00000000000000000000. If I enter a good OTP password, I get this in my logs: Dec 3 13:43:26 hiro slapd[11159]: slap_auxprop_store [conn=3]: Getting ready to set cmusaslsecretOTP to md5^I0499^Ihi5865^Iec8123986aec6550^I00000000001196711306. Dec 3 13:44:26 hiro slapd[11159]: slap_auxprop_store [conn=3]: Getting ready to set cmusaslsecretOTP to md5^I0498^Ihi5865^Ic3570f027cf46ed0^I00000000000000000000. If I enter an incorrect password, I get this: Dec 3 13:45:21 hiro slapd[11159]: slap_auxprop_store [conn=4]: Getting ready to set cmusaslsecretOTP to md5^I0498^Ihi5865^Ic3570f027cf46ed0^I00000000001196711421. Dec 3 13:45:22 hiro slapd[11159]: slap_auxprop_store [conn=4]: Getting ready to set cmusaslsecretOTP to md5^I0498^Ihi5865^Ic3570f027cf46ed0^I00000000000000000000. So in the case where it's crashing, it appears the Cyrus SASL is attempting to revert the OTP entry back to the previous version to "unlock" it. I assume that the connection id of '-1' is relevant to the crash. You should be able to reproduce this error with the following steps: Compile SASL with OTP, but without OPIE Configure a dummy SASL service configuration file to be used with saslpasswd2 below, e.g.: hiro:~# cat > /usr/lib/sasl2/test.conf <<EOF > auxprop_plugin: ldapdb > ldapdb_uri: ldapi:/// > ldapdb_mech: EXTERNAL > EOF hiro:~# Create a schema including an attribute of cmusaslsecretOTP, and create an entry in the directory which can use this attribute. Configure slapd.conf with the appropriate sasl configuration to convert both the shell (root) user (connecting via ldapi:///) and the user specified in the ldapsearch, for example: sasl-regexp "gidNumber=0\\\+uidNumber=0,cn=peercred,cn=external,cn=auth" cn=admin,dc=olp,dc=net sasl-regexp "uid=([^,]+),cn=otp,cn=auth" ldap:///ou=people,dc=olp,dc=net??one?(btcAltUid=$1) Issue a saslpasswd2 to initialize the cmusaslsecretOTP attribute for the user: hiro:~# saslpasswd2 -a test -n abrown(a)olp.net Password: Again (for verification): The cmusaslsecretOTP attribute should look something like: md5 0499 hi8351 1c19abc81f35dc63 00000000000000000000 opiekey can be used to convert the OTP challenge into the appropriate response. For instance: hiro:~# ldapsearch -Y OTP -U abrown(a)olp.net SASL/OTP authentication started Challenge: otp-md5 498 hi8351 ext Please enter your one-time password: Using opiekey to obtain response: dwhite@zek:~$ opiekey -5 -x 498 hi8351 Using the MD5 algorithm to compute response. Reminder: Don't use opiekey from telnet or dial-in sessions. Enter secret pass phrase: 556A 99B3 52FA CEB1 Feed the result back into ldapsearch for a successful bind. To reproduce the bug, of course just kill the ldapsearch before entering any response.

1 0

Problem to connect à LDAP server
by rodrigue Boyom 04 Dec '07

04 Dec '07

Hi , i m a technician of computer science and telecommunication.I have some problem when i configure LDAP server on RedHat 9.0 this a bugs i have when i want cretead a password to connect a LDAP server please help me : root@serveur root]# ldappasswd -s danse SASL/GSSAPI authentication started ldap_sasl_interactive_bind_s: Local error [root@serveur root]#

2 1

SIGSEGV in slap_auxprop_store during SASL/OTP bind
by Dan White 04 Dec '07

04 Dec '07

I'm experiencing crashes in slapd when attempting to bind via SASL using the OTP mech. I'm using openldap version 2.3.39 for both slapd and my ldap utils (ldapsearch). I'm using the bdb backend. I'm also using Debian Etch with the following versions of software: Cyrus SASL 2.1.22(.dfsg1-8) libdb 4.2.52(+dfsg-2) libc6 2.3.6(.ds1-13etch2) I've compiled cyrus sasl to use it's internal implementation of OTP, rather than OPIE: --enable-otp (--with-opie is not enabled) The problem I'm experiencing isn't when I successfully authenticate; that seems to work fine. It's when I run an ldapsearch, but instead of entering an OTP password, I press ctrl-c to cancel the search. From the shell, when I perform an LDAP search, all appears normal: hiro:~# ldapsearch -Y OTP -U abrown(a)olp.net SASL/OTP authentication started Challenge: otp-md5 497 hi3182 ext Please enter your one-time password:<ctrl-c> hiro:~# However my slapd process dies. Here's a gdb backtrace of the server process: ... Core was generated by `/usr/sbin/slapd'. Program terminated with signal 11, Segmentation fault. #0 0x080b448e in slap_auxprop_store (glob_context=0x0, sparams=0x820b2a0, prctx=0x82351c0, user=0x820a148 "abrown(a)olp.net", ulen=14) at /usr/src/build/openldap/openldap2.3-2.3.39/servers/slapd/sasl.c:478 478 op.o_hdr = conn->c_sasl_bindop->o_hdr; (gdb) bt #0 0x080b448e in slap_auxprop_store (glob_context=0x0, sparams=0x820b2a0, prctx=0x82351c0, user=0x820a148 "abrown(a)olp.net", ulen=14) at /usr/src/build/openldap/openldap2.3-2.3.39/servers/slapd/sasl.c:478 #1 0xb7eb17d7 in sasl_auxprop_store () from /usr/lib/libsasl2.so.2 #2 0xb7973c89 in otp_server_plug_init () from /usr/lib/sasl2/libotp.so.2 #3 0xb7ebde36 in sasl_server_new () from /usr/lib/libsasl2.so.2 #4 0xb7eb6194 in sasl_dispose () from /usr/lib/libsasl2.so.2 #5 0x080b2992 in slap_sasl_close (conn=0xb7ec3618) at /usr/src/build/openldap/openldap2.3-2.3.39/servers/slapd/sasl.c:1331 #6 0x0806cf27 in connection_close (c=0xb75b1148) at /usr/src/build/openldap/openldap2.3-2.3.39/servers/slapd/connection.c:715 #7 0x0806e116 in connection_read (s=12) at /usr/src/build/openldap/openldap2.3-2.3.39/servers/slapd/connection.c:1458 #8 0x0806a49f in slapd_daemon_task (ptr=0x0) at /usr/src/build/openldap/openldap2.3-2.3.39/servers/slapd/daemon.c:2468 #9 0xb7cd3240 in start_thread () from /lib/tls/i686/cmov/libpthread.so.0 #10 0xb7c674ae in clone () from /lib/tls/i686/cmov/libc.so.6 (gdb) quit I've added a debug statement within slap_auxprop_store, so the openldap debug information below will include some additional information about what's being modified. Here's output from an attempt that crashed (when I pressed ctrl-c in my ldapsearch): Dec 3 13:39:06 hiro slapd[11134]: daemon: activity on 1 descriptor Dec 3 13:39:06 hiro slapd[11134]: daemon: activity on: Dec 3 13:39:06 hiro slapd[11134]: Dec 3 13:39:06 hiro slapd[11134]: >>> slap_listener(ldapi:///) Dec 3 13:39:06 hiro slapd[11134]: daemon: listen=12, new connection on 16 Dec 3 13:39:06 hiro slapd[11134]: daemon: added 16r (active) listener=(nil) Dec 3 13:39:06 hiro slapd[11134]: conn=3 fd=16 ACCEPT from PATH=/var/run/slapd/ldapi (PATH=/var/run/slapd/ldapi) Dec 3 13:39:06 hiro slapd[11134]: daemon: epoll: listen=8 active_threads=0 tvp=NULL Dec 3 13:39:06 hiro slapd[11134]: daemon: epoll: listen=9 active_threads=0 tvp=NULL Dec 3 13:39:06 hiro slapd[11134]: daemon: epoll: listen=10 active_threads=0 tvp=NULL Dec 3 13:39:06 hiro slapd[11134]: daemon: epoll: listen=11 active_threads=0 tvp=NULL Dec 3 13:39:06 hiro slapd[11134]: daemon: epoll: listen=12 active_threads=0 tvp=NULL Dec 3 13:39:06 hiro slapd[11134]: daemon: activity on 1 descriptor Dec 3 13:39:06 hiro slapd[11134]: daemon: activity on: Dec 3 13:39:06 hiro slapd[11134]: 16r Dec 3 13:39:06 hiro slapd[11134]: Dec 3 13:39:06 hiro slapd[11134]: daemon: read active on 16 Dec 3 13:39:06 hiro slapd[11134]: connection_get(16) Dec 3 13:39:06 hiro slapd[11134]: connection_get(16): got connid=3 Dec 3 13:39:06 hiro slapd[11134]: connection_read(16): checking for input on id=3 Dec 3 13:39:06 hiro slapd[11134]: daemon: epoll: listen=8 active_threads=0 tvp=NULL Dec 3 13:39:06 hiro slapd[11134]: daemon: epoll: listen=9 active_threads=0 tvp=NULL Dec 3 13:39:06 hiro slapd[11134]: do_bind Dec 3 13:39:06 hiro slapd[11134]: daemon: epoll: listen=10 active_threads=0 tvp=NULL Dec 3 13:39:06 hiro slapd[11134]: >>> dnPrettyNormal: <> Dec 3 13:39:06 hiro slapd[11134]: daemon: epoll: listen=11 active_threads=0 tvp=NULL Dec 3 13:39:06 hiro slapd[11134]: <<< dnPrettyNormal: <>, <> Dec 3 13:39:06 hiro slapd[11134]: daemon: epoll: listen=12 active_threads=0 tvp=NULL Dec 3 13:39:06 hiro slapd[11134]: do_sasl_bind: dn () mech OTP Dec 3 13:39:06 hiro slapd[11134]: conn=3 op=0 BIND dn="" method=163 Dec 3 13:39:06 hiro slapd[11134]: ==> sasl_bind: dn="" mech=OTP datalen=29 Dec 3 13:39:06 hiro slapd[11134]: SASL Canonicalize [conn=3]: authcid="abrown(a)olp.net" Dec 3 13:39:06 hiro slapd[11134]: slap_sasl_getdn: conn 3 id=abrown(a)olp.net [len=14] Dec 3 13:39:06 hiro slapd[11134]: slap_sasl_getdn: u:id converted to uid=abrown(a)olp.net,cn=OTP,cn=auth Dec 3 13:39:06 hiro slapd[11134]: >>> dnNormalize: <uid=abrown(a)olp.net,cn=OTP,cn=auth> Dec 3 13:39:06 hiro slapd[11134]: <<< dnNormalize: <uid=abrown(a)olp.net,cn=otp,cn=auth> Dec 3 13:39:06 hiro slapd[11134]: ==>slap_sasl2dn: converting SASL name uid=abrown(a)olp.net,cn=otp,cn=auth to a DN Dec 3 13:39:06 hiro slapd[11134]: slap_authz_regexp: converting SASL name uid=abrown(a)olp.net,cn=otp,cn=auth Dec 3 13:39:06 hiro slapd[11134]: slap_authz_regexp: converted SASL name to ldap:///ou=people,dc=olp,dc=net??one?(btcAltUid=abrown@olp.net) Dec 3 13:39:06 hiro slapd[11134]: slap_parseURI: parsing ldap:///ou=people,dc=olp,dc=net??one?(btcAltUid=abrown@olp.net) Dec 3 13:39:06 hiro slapd[11134]: str2filter "(btcAltUid=abrown(a)olp.net)" Dec 3 13:39:06 hiro slapd[11134]: begin get_filter Dec 3 13:39:06 hiro slapd[11134]: EQUALITY Dec 3 13:39:06 hiro slapd[11134]: end get_filter 0 Dec 3 13:39:06 hiro slapd[11134]: >>> dnNormalize: <ou=people,dc=olp,dc=net> Dec 3 13:39:06 hiro slapd[11134]: <<< dnNormalize: <ou=people,dc=olp,dc=net> Dec 3 13:39:06 hiro slapd[11134]: slap_sasl2dn: performing internal search (base=ou=people,dc=olp,dc=net, scope=1) Dec 3 13:39:06 hiro slapd[11134]: => bdb_search Dec 3 13:39:06 hiro slapd[11134]: bdb_dn2entry("ou=people,dc=olp,dc=net") Dec 3 13:39:06 hiro slapd[11134]: search_candidates: base="ou=people,dc=olp,dc=net" (0x00000003) scope=1 Dec 3 13:39:06 hiro slapd[11134]: => bdb_dn2idl("ou=people,dc=olp,dc=net") Dec 3 13:39:06 hiro slapd[11134]: bdb_idl_fetch_key: %ou=people,dc=olp,dc=net Dec 3 13:39:06 hiro slapd[11134]: <= bdb_dn2idl: id=68 first=7 last=136 Dec 3 13:39:06 hiro slapd[11134]: => bdb_filter_candidates Dec 3 13:39:06 hiro slapd[11134]: ^IAND Dec 3 13:39:06 hiro slapd[11134]: => bdb_list_candidates 0xa0 Dec 3 13:39:06 hiro slapd[11134]: => bdb_filter_candidates Dec 3 13:39:06 hiro slapd[11134]: ^IOR Dec 3 13:39:06 hiro slapd[11134]: => bdb_list_candidates 0xa1 Dec 3 13:39:06 hiro slapd[11134]: => bdb_filter_candidates Dec 3 13:39:06 hiro slapd[11134]: ^IEQUALITY Dec 3 13:39:06 hiro slapd[11134]: => bdb_equality_candidates (objectClass) Dec 3 13:39:06 hiro slapd[11134]: => key_read Dec 3 13:39:06 hiro slapd[11134]: bdb_idl_fetch_key: [b49d1940] Dec 3 13:39:06 hiro slapd[11134]: <= bdb_index_read: failed (-30990) Dec 3 13:39:06 hiro slapd[11134]: <= bdb_equality_candidates: id=0, first=0, last=0 Dec 3 13:39:06 hiro slapd[11134]: <= bdb_filter_candidates: id=0 first=0 last=0 Dec 3 13:39:06 hiro slapd[11134]: => bdb_filter_candidates Dec 3 13:39:06 hiro slapd[11134]: ^IEQUALITY Dec 3 13:39:06 hiro slapd[11134]: => bdb_equality_candidates (btcAltUID) Dec 3 13:39:06 hiro slapd[11134]: => key_read Dec 3 13:39:06 hiro slapd[11134]: bdb_idl_fetch_key: [b0f0ea63] Dec 3 13:39:06 hiro slapd[11134]: <= bdb_index_read 1 candidates Dec 3 13:39:06 hiro slapd[11134]: <= bdb_equality_candidates: id=1, first=7, last=7 Dec 3 13:39:06 hiro slapd[11134]: <= bdb_filter_candidates: id=1 first=7 last=7 Dec 3 13:39:06 hiro slapd[11134]: <= bdb_list_candidates: id=1 first=7 last=7 Dec 3 13:39:06 hiro slapd[11134]: <= bdb_filter_candidates: id=1 first=7 last=7 Dec 3 13:39:06 hiro slapd[11134]: <= bdb_list_candidates: id=1 first=7 last=7 Dec 3 13:39:06 hiro slapd[11134]: <= bdb_filter_candidates: id=1 first=7 last=7 Dec 3 13:39:06 hiro slapd[11134]: bdb_search_candidates: id=1 first=7 last=7 Dec 3 13:39:06 hiro slapd[11134]: => test_filter Dec 3 13:39:06 hiro slapd[11134]: EQUALITY Dec 3 13:39:06 hiro slapd[11134]: => access_allowed: auth access to "uid=abrown(a)olp.net,ou=People,dc=olp,dc=net" "btcAltUID" requested Dec 3 13:39:06 hiro slapd[11134]: => dnpat: [1] ou=addressbooks,uid=([^,]+),ou=people,dc=olp,dc=net$ nsub: 1 Dec 3 13:39:06 hiro slapd[11134]: => dnpat: [2] .*,ou=addressbooks,uid=([^,]+),ou=people,dc=olp,dc=net$ nsub: 1 Dec 3 13:39:06 hiro slapd[11134]: => dn: [3] ou=people,dc=olp,dc=net Dec 3 13:39:06 hiro slapd[11134]: => dn: [4] ou=groups,dc=olp,dc=net Dec 3 13:39:06 hiro slapd[11134]: => acl_get: [7] attr btcAltUID Dec 3 13:39:06 hiro slapd[11134]: => acl_mask: access to entry "uid=abrown(a)olp.net,ou=People,dc=olp,dc=net", attr "btcAltUID" requested Dec 3 13:39:06 hiro slapd[11134]: => acl_mask: to value by "", (=0) Dec 3 13:39:06 hiro slapd[11134]: <= check a_dn_pat: anonymous Dec 3 13:39:06 hiro slapd[11134]: <= acl_mask: [1] applying auth(=xd) (stop) Dec 3 13:39:06 hiro slapd[11134]: <= acl_mask: [1] mask: auth(=xd) Dec 3 13:39:06 hiro slapd[11134]: => slap_access_allowed: auth access granted by auth(=xd) Dec 3 13:39:06 hiro slapd[11134]: => access_allowed: auth access granted by auth(=xd) Dec 3 13:39:06 hiro slapd[11134]: <= test_filter 6 Dec 3 13:39:06 hiro slapd[11134]: send_ldap_result: conn=3 op=0 p=3 Dec 3 13:39:06 hiro slapd[11134]: send_ldap_result: err=0 matched="" text="" Dec 3 13:39:06 hiro slapd[11134]: <==slap_sasl2dn: Converted SASL name to uid=abrown(a)olp.net,ou=people,dc=olp,dc=net Dec 3 13:39:06 hiro slapd[11134]: slap_sasl_getdn: dn:id converted to uid=abrown(a)olp.net,ou=people,dc=olp,dc=net Dec 3 13:39:06 hiro slapd[11134]: SASL Canonicalize [conn=3]: slapAuthcDN="uid=abrown(a)olp.net,ou=people,dc=olp,dc=net" Dec 3 13:39:06 hiro slapd[11134]: => bdb_search Dec 3 13:39:06 hiro slapd[11134]: bdb_dn2entry("uid=abrown(a)olp.net,ou=people,dc=olp,dc=net") Dec 3 13:39:06 hiro slapd[11134]: base_candidates: base: "uid=abrown(a)olp.net,ou=people,dc=olp,dc=net" (0x00000007) Dec 3 13:39:06 hiro slapd[11134]: => test_filter Dec 3 13:39:06 hiro slapd[11134]: PRESENT Dec 3 13:39:06 hiro slapd[11134]: => access_allowed: auth access to "uid=abrown(a)olp.net,ou=People,dc=olp,dc=net" "objectClass" requested Dec 3 13:39:06 hiro slapd[11134]: => dnpat: [1] ou=addressbooks,uid=([^,]+),ou=people,dc=olp,dc=net$ nsub: 1 Dec 3 13:39:06 hiro slapd[11134]: => dnpat: [2] .*,ou=addressbooks,uid=([^,]+),ou=people,dc=olp,dc=net$ nsub: 1 Dec 3 13:39:06 hiro slapd[11134]: => dn: [3] ou=people,dc=olp,dc=net Dec 3 13:39:06 hiro slapd[11134]: => dn: [4] ou=groups,dc=olp,dc=net Dec 3 13:39:06 hiro slapd[11134]: => dnpat: [12] .*n=([^,]+),ou=groups,dc=olp,dc=net$ nsub: 1 Dec 3 13:39:06 hiro slapd[11134]: => dnpat: [13] .*n=([^,]+),ou=groups,dc=olp,dc=net$ nsub: 1 Dec 3 13:39:06 hiro slapd[11134]: => dnpat: [14] ^cn=admin,cn=([^,]+),ou=groups,dc=olp,dc=net$ nsub: 1 Dec 3 13:39:06 hiro slapd[11134]: => dnpat: [15] ^cn=([^,]+),ou=groups,dc=olp,dc=net$ nsub: 1 Dec 3 13:39:06 hiro slapd[11134]: => dnpat: [16] ^cn=admin,cn=([^,]+),ou=groups,dc=olp,dc=net$ nsub: 1 Dec 3 13:39:06 hiro slapd[11134]: => acl_get: [17] attr objectClass Dec 3 13:39:06 hiro slapd[11134]: => acl_mask: access to entry "uid=abrown(a)olp.net,ou=People,dc=olp,dc=net", attr "objectClass" requested Dec 3 13:39:06 hiro slapd[11134]: => acl_mask: to all values by "", (=0) Dec 3 13:39:06 hiro slapd[11134]: <= check a_dn_pat: self Dec 3 13:39:06 hiro slapd[11134]: <= check a_dn_pat: anonymous Dec 3 13:39:06 hiro slapd[11134]: <= acl_mask: [8] applying auth(=xd) (stop) Dec 3 13:39:06 hiro slapd[11134]: <= acl_mask: [8] mask: auth(=xd) Dec 3 13:39:06 hiro slapd[11134]: => slap_access_allowed: auth access granted by auth(=xd) Dec 3 13:39:06 hiro slapd[11134]: => access_allowed: auth access granted by auth(=xd) Dec 3 13:39:06 hiro slapd[11134]: <= test_filter 6 Dec 3 13:39:06 hiro slapd[11134]: => access_allowed: auth access to "uid=abrown(a)olp.net,ou=People,dc=olp,dc=net" "cmusaslsecretOTP" requested Dec 3 13:39:06 hiro slapd[11134]: => dnpat: [1] ou=addressbooks,uid=([^,]+),ou=people,dc=olp,dc=net$ nsub: 1 Dec 3 13:39:06 hiro slapd[11134]: => dnpat: [2] .*,ou=addressbooks,uid=([^,]+),ou=people,dc=olp,dc=net$ nsub: 1 Dec 3 13:39:06 hiro slapd[11134]: => dn: [3] ou=people,dc=olp,dc=net Dec 3 13:39:06 hiro slapd[11134]: => dn: [4] ou=groups,dc=olp,dc=net Dec 3 13:39:06 hiro slapd[11134]: => acl_get: [8] attr cmusaslsecretOTP Dec 3 13:39:06 hiro slapd[11134]: => acl_mask: access to entry "uid=abrown(a)olp.net,ou=People,dc=olp,dc=net", attr "cmusaslsecretOTP" requested Dec 3 13:39:06 hiro slapd[11134]: => acl_mask: to all values by "", (=0) Dec 3 13:39:06 hiro slapd[11134]: <= check a_dn_pat: anonymous Dec 3 13:39:06 hiro slapd[11134]: <= acl_mask: [1] applying auth(=xd) (stop) Dec 3 13:39:06 hiro slapd[11134]: <= acl_mask: [1] mask: auth(=xd) Dec 3 13:39:06 hiro slapd[11134]: => slap_access_allowed: auth access granted by auth(=xd) Dec 3 13:39:06 hiro slapd[11134]: => access_allowed: auth access granted by auth(=xd) Dec 3 13:39:06 hiro slapd[11134]: send_ldap_result: conn=3 op=0 p=3 Dec 3 13:39:06 hiro slapd[11134]: send_ldap_result: err=0 matched="" text="" Dec 3 13:39:06 hiro slapd[11134]: SASL Canonicalize [conn=3]: authzid="abrown(a)olp.net" Dec 3 13:39:06 hiro slapd[11134]: slap_auxprop_store [conn=3]: Getting ready to set cmusaslsecretOTP to md5^I0499^Ihi5935^I0e81b33e30182715^I00000000001196711046. Dec 3 13:39:06 hiro slapd[11134]: bdb_modify: uid=abrown(a)olp.net,ou=people,dc=olp,dc=net Dec 3 13:39:06 hiro slapd[11134]: bdb_dn2entry("uid=abrown(a)olp.net,ou=people,dc=olp,dc=net") Dec 3 13:39:06 hiro slapd[11134]: bdb_modify_internal: 0x00000007: uid=abrown(a)olp.net,ou=People,dc=olp,dc=net Dec 3 13:39:06 hiro slapd[11134]: => access_allowed: delete access to "uid=abrown(a)olp.net,ou=People,dc=olp,dc=net" "cmusaslsecretOTP" requested Dec 3 13:39:06 hiro slapd[11134]: => dnpat: [1] ou=addressbooks,uid=([^,]+),ou=people,dc=olp,dc=net$ nsub: 1 Dec 3 13:39:06 hiro slapd[11134]: => dnpat: [2] .*,ou=addressbooks,uid=([^,]+),ou=people,dc=olp,dc=net$ nsub: 1 Dec 3 13:39:06 hiro slapd[11134]: => dn: [3] ou=people,dc=olp,dc=net Dec 3 13:39:06 hiro slapd[11134]: => dn: [4] ou=groups,dc=olp,dc=net Dec 3 13:39:06 hiro slapd[11134]: => acl_get: [8] attr cmusaslsecretOTP Dec 3 13:39:06 hiro slapd[11134]: => slap_access_allowed: no res from state (cmusaslsecretOTP) Dec 3 13:39:06 hiro slapd[11134]: => acl_mask: access to entry "uid=abrown(a)olp.net,ou=People,dc=olp,dc=net", attr "cmusaslsecretOTP" requested Dec 3 13:39:06 hiro slapd[11134]: => acl_mask: to all values by "uid=abrown(a)olp.net,ou=people,dc=olp,dc=net", (=0) Dec 3 13:39:06 hiro slapd[11134]: <= check a_dn_pat: anonymous Dec 3 13:39:06 hiro slapd[11134]: <= check a_dn_pat: self Dec 3 13:39:06 hiro slapd[11134]: <= acl_mask: [2] applying write(=wrscxd) (stop) Dec 3 13:39:06 hiro slapd[11134]: <= acl_mask: [2] mask: write(=wrscxd) Dec 3 13:39:06 hiro slapd[11134]: => slap_access_allowed: delete access granted by write(=wrscxd) Dec 3 13:39:06 hiro slapd[11134]: => access_allowed: delete access granted by write(=wrscxd) Dec 3 13:39:06 hiro slapd[11134]: acl: internal mod entryCSN: modify access granted Dec 3 13:39:06 hiro slapd[11134]: acl: internal mod modifiersName: modify access granted Dec 3 13:39:06 hiro slapd[11134]: acl: internal mod modifyTimestamp: modify access granted Dec 3 13:39:06 hiro slapd[11134]: bdb_modify_internal: replace cmusaslsecretOTP Dec 3 13:39:06 hiro slapd[11134]: bdb_modify_internal: replace entryCSN Dec 3 13:39:06 hiro slapd[11134]: bdb_modify_internal: replace modifiersName Dec 3 13:39:06 hiro slapd[11134]: bdb_modify_internal: replace modifyTimestamp Dec 3 13:39:06 hiro slapd[11134]: oc_check_required entry (uid=abrown(a)olp.net,ou=People,dc=olp,dc=net), objectClass "account" Dec 3 13:39:06 hiro slapd[11134]: oc_check_required entry (uid=abrown(a)olp.net,ou=People,dc=olp,dc=net), objectClass "posixAccount" Dec 3 13:39:06 hiro slapd[11134]: oc_check_required entry (uid=abrown(a)olp.net,ou=People,dc=olp,dc=net), objectClass "shadowAccount" Dec 3 13:39:06 hiro slapd[11134]: oc_check_required entry (uid=abrown(a)olp.net,ou=People,dc=olp,dc=net), objectClass "krb5KDCEntry" Dec 3 13:39:06 hiro slapd[11134]: oc_check_required entry (uid=abrown(a)olp.net,ou=People,dc=olp,dc=net), objectClass "krb5Principal" Dec 3 13:39:06 hiro slapd[11134]: oc_check_required entry (uid=abrown(a)olp.net,ou=People,dc=olp,dc=net), objectClass "sambaSamAccount" Dec 3 13:39:06 hiro slapd[11134]: oc_check_required entry (uid=abrown(a)olp.net,ou=People,dc=olp,dc=net), objectClass "radiusprofile" Dec 3 13:39:06 hiro slapd[11134]: oc_check_required entry (uid=abrown(a)olp.net,ou=People,dc=olp,dc=net), objectClass "btcAuthUser" Dec 3 13:39:06 hiro slapd[11134]: oc_check_required entry (uid=abrown(a)olp.net,ou=People,dc=olp,dc=net), objectClass "cmuSaslUser" Dec 3 13:39:06 hiro slapd[11134]: oc_check_required entry (uid=abrown(a)olp.net,ou=People,dc=olp,dc=net), objectClass "pkiUser" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "uid" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "cn" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "uidNumber" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "gidNumber" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "homeDirectory" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "loginShell" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "shadowMin" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "shadowMax" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "shadowWarning" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "shadowExpire" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "gecos" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "structuralObjectClass" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "entryUUID" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "creatorsName" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "createTimestamp" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "krb5PrincipalName" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "krb5MaxLife" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "krb5MaxRenew" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "krb5KDCFlags" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "sambaSID" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "sambaAcctFlags" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "sambaPrimaryGroupSID" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "shadowLastChange" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "radiusGroupName" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "btcCertificatePassword" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "btcAltUID" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "UNDEFINED" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "userPassword" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "sambaPwdLastSet" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "sambaLMPassword" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "sambaNTPassword" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "krb5KeyVersionNumber" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "krb5Key" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "UNDEFINED" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "objectClass" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "UNDEFINED" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "cmusaslsecretOTP" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "entryCSN" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "modifiersName" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "modifyTimestamp" Dec 3 13:39:06 hiro slapd[11134]: => entry_encode(0x00000007): uid=abrown(a)olp.net,ou=People,dc=olp,dc=net Dec 3 13:39:06 hiro slapd[11134]: bdb_modify: updated id=00000007 dn="uid=abrown(a)olp.net,ou=people,dc=olp,dc=net" Dec 3 13:39:06 hiro slapd[11134]: send_ldap_result: conn=3 op=0 p=3 Dec 3 13:39:06 hiro slapd[11134]: send_ldap_result: err=0 matched="" text="" Dec 3 13:39:06 hiro slapd[11134]: send_ldap_sasl: err=14 len=22 Dec 3 13:39:06 hiro slapd[11134]: send_ldap_response: msgid=1 tag=97 err=14 Dec 3 13:39:06 hiro slapd[11134]: conn=3 op=0 RESULT tag=97 err=14 text= Dec 3 13:39:06 hiro slapd[11134]: <== slap_sasl_bind: rc=14 Dec 3 13:39:07 hiro slapd[11134]: daemon: activity on 1 descriptor Dec 3 13:39:07 hiro slapd[11134]: daemon: activity on: Dec 3 13:39:07 hiro slapd[11134]: 16r Dec 3 13:39:07 hiro slapd[11134]: Dec 3 13:39:07 hiro slapd[11134]: daemon: read active on 16 Dec 3 13:39:07 hiro slapd[11134]: connection_get(16) Dec 3 13:39:07 hiro slapd[11134]: connection_get(16): got connid=3 Dec 3 13:39:07 hiro slapd[11134]: connection_read(16): checking for input on id=3 Dec 3 13:39:07 hiro slapd[11134]: ber_get_next on fd 16 failed errno=0 (Success) Dec 3 13:39:07 hiro slapd[11134]: connection_read(16): input error=-2 id=3, closing. Dec 3 13:39:07 hiro slapd[11134]: connection_closing: readying conn=3 sd=16 for close Dec 3 13:39:07 hiro slapd[11134]: connection_close: conn=3 sd=-1 Dec 3 13:39:07 hiro slapd[11134]: slap_auxprop_store [conn=-1]: Getting ready to set cmusaslsecretOTP to md5^I0499^Ihi5935^I0e81b33e30182715^I00000000000000000000. If I enter a good OTP password, I get this in my logs: Dec 3 13:43:26 hiro slapd[11159]: slap_auxprop_store [conn=3]: Getting ready to set cmusaslsecretOTP to md5^I0499^Ihi5865^Iec8123986aec6550^I00000000001196711306. Dec 3 13:44:26 hiro slapd[11159]: slap_auxprop_store [conn=3]: Getting ready to set cmusaslsecretOTP to md5^I0498^Ihi5865^Ic3570f027cf46ed0^I00000000000000000000. If I enter an incorrect password, I get this: Dec 3 13:45:21 hiro slapd[11159]: slap_auxprop_store [conn=4]: Getting ready to set cmusaslsecretOTP to md5^I0498^Ihi5865^Ic3570f027cf46ed0^I00000000001196711421. Dec 3 13:45:22 hiro slapd[11159]: slap_auxprop_store [conn=4]: Getting ready to set cmusaslsecretOTP to md5^I0498^Ihi5865^Ic3570f027cf46ed0^I00000000000000000000. So in the case where it's crashing, it appears the Cyrus SASL is attempting to revert the OTP entry back to the previous version to "unlock" it. I assume that the connection id of '-1' is relevant to the crash. You should be able to reproduce this error with the following steps: Compile SASL with OTP, but without OPIE Configure a dummy SASL service configuration file, e.g.: hiro:~# cat > /usr/lib/sasl2/test.conf <<EOF > auxprop_plugin: ldapdb > ldapdb_uri: ldapi:/// > ldapdb_mech: EXTERNAL > EOF hiro:~# Create a schema including an attribute of cmusaslsecretOTP, and create an entry in the directory which can use this attribute. Configure slapd.conf with the appropriate sasl configuration to convert both the openldap user (connecting via ldapi:///) and the user specified in the ldapsearch, for example: sasl-regexp "gidNumber=0\\\+uidNumber=0,cn=peercred,cn=external,cn=auth" cn=admin,dc=olp,dc=net sasl-regexp "uid=([^,]+),cn=otp,cn=auth" ldap:///ou=people,dc=olp,dc=net??one?(btcAltUid=$1) Issue a saslpasswd2 to initialize the cmusaslsecretOTP attribute for the user: hiro:~# saslpasswd2 -a test -n abrown(a)olp.net Password: Again (for verification): The cmusaslsecretOTP attribute should look something like: md5 0499 hi8351 1c19abc81f35dc63 00000000000000000000 opiekey can be used to convert the OTP challenge into the appropriate response. For instance: hiro:~# ldapsearch -Y OTP -U abrown(a)olp.net SASL/OTP authentication started Challenge: otp-md5 498 hi8351 ext Please enter your one-time password: Using opiekey to obtain response: dwhite@zek:~$ opiekey -5 -x 498 hi8351 Using the MD5 algorithm to compute response. Reminder: Don't use opiekey from telnet or dial-in sessions. Enter secret pass phrase: 556A 99B3 52FA CEB1 Feed the secret pass phrase back into ldapsearch for a successful bind. To reproduce the bug, of course just kill the ldapsearch before entering any response. - Dan White BTC Broadband

2 1

Jump to page:

2025

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

2010

2009

2008

2007

2006

openldap-bugs