- openldap-bugs - openldap.org

Re: (ITS#6330) slapd memory leak
by h.b.furuseth＠usit.uio.no 16 Oct '09

16 Oct '09

hyc(a)symas.com writes: > Merely increasing --num-callers isn't going to be sufficient to track this. > Since valgrind only reports leaks after a program exits, The statement VALGRIND_DO_LEAK_CHECK; will check for leaks at that point in the code. The source file must #include <stdio.h> #include <valgrind/memcheck.h> Then run the program under valgrind. Regarding Cyrus SASL, I often ./configure --without-cyrus-sasl when testing OpenLDAP, to shut valgrind up about SASL. And I build Berkeley DB with ../dist/configure --enable-umrw trying to shut it up about DB. -- Hallvard

1 0

Re: (ITS#6330) slapd memory leak
by whm＠stanford.edu 16 Oct '09

16 Oct '09

--On Friday, October 16, 2009 07:16:23 AM +0000 Bill MacAllister <whm(a)stanford.edu> wrote: > > > --On Friday, October 16, 2009 12:02:59 AM -0700 Howard Chu <hyc(a)symas.com> wrote: > >> whm(a)stanford.edu wrote: >>> Here is the valgrind output. The complete log is at >>> >>> http://www.stanford.edu/~whm/files/slapd/valgrind-memcheck.txt >> >> All of this indicates memory leaks and errors in the SASL library, >> not any bug in OpenLDAP. > > That is what I suspected when I looked at the output, but I wanted > confirmation from someone that is more familar with valgrind output > and the code than me. Of course, until we resolve the issue it > effectively disables OpenLDAP 2.4 for us. And in researching the problem I see that this is a well trodden path. I found a particularly useful thread from 2006 entitled "better malloc strageties" in the OpenLDAP archives. As I result I packaged up libhoard, installed it, and re-ran the valgrind test. The short test showed no memory leaks. I will perform more extensive tests, but this appears to have fixed the problem. Thanks for your work, then and now. Bill -- Bill MacAllister, System Software Programmer Unix Systems Group, Stanford University

1 0

Re: (ITS#6330) slapd memory leak
by hyc＠symas.com 16 Oct '09

16 Oct '09

quanah(a)zimbra.com wrote: > --On Friday, October 16, 2009 7:57 AM +0000 masarati(a)aero.polimi.it wrote: > >> hyc(a)symas.com wrote: >>> whm(a)stanford.edu wrote: >>>> Here is the valgrind output. The complete log is at >>>> >>>> http://www.stanford.edu/~whm/files/slapd/valgrind-memcheck.txt >>> >>> All of this indicates memory leaks and errors in the SASL library, not >>> any bug in OpenLDAP. >> >> That was exactly my suspect when you originally stated that the leak >> only appeared after wrapping dynlist requests within a SASL bind/unbind. >> The leak could still be related to an improper use of SASL library >> calls by OpenLDAP, although unlikely. However, that valgrind output >> does not help as leaks related to malloc are too hidden into SASL; you >> should add --num-callers=<more than 12, the default; enough to see >> something related to OpenLDAP's code>. > > > Given that the memory issue is not seen with OpenLDAP 2.3 + dyngroup, I'd > still have to agree there's something wrong with what OpenLDAP 2.4 + > dynlist is doing. Merely increasing --num-callers isn't going to be sufficient to track this. Since valgrind only reports leaks after a program exits, and the Cyrus SASL library unloads the offending plugin before it exits, most of the stack trace will be missing any useful symbols. You'll have to run a modified libsasl2.so that omits its dlclose() calls so that the libgssapiv2 plugin will remain loaded, so that its symbols will still be accessible when slapd exits. Also, since the trace only shows leaks triggered from sasl_client_step and sasl_server_step, which are only executed during SASL Bind processing, you ought to be able to duplicate these leaks regardless of dynlist or any other overlays, since the leaks are occurring before any of these overlays have even started to run. Of course, if you're unable to reproduce these leaks with dynlist out of the picture, then I guess the finger points into dynlist again... -- -- Howard Chu CTO, 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#6330) slapd memory leak
by quanah＠zimbra.com 16 Oct '09

16 Oct '09

--On Friday, October 16, 2009 7:57 AM +0000 masarati(a)aero.polimi.it wrote: > hyc(a)symas.com wrote: >> whm(a)stanford.edu wrote: >>> Here is the valgrind output. The complete log is at >>> >>> http://www.stanford.edu/~whm/files/slapd/valgrind-memcheck.txt >> >> All of this indicates memory leaks and errors in the SASL library, not >> any bug in OpenLDAP. > > That was exactly my suspect when you originally stated that the leak > only appeared after wrapping dynlist requests within a SASL bind/unbind. > The leak could still be related to an improper use of SASL library > calls by OpenLDAP, although unlikely. However, that valgrind output > does not help as leaks related to malloc are too hidden into SASL; you > should add --num-callers=<more than 12, the default; enough to see > something related to OpenLDAP's code>. Given that the memory issue is not seen with OpenLDAP 2.3 + dyngroup, I'd still have to agree there's something wrong with what OpenLDAP 2.4 + dynlist is doing. --Quanah -- Quanah Gibson-Mount Principal Software Engineer Zimbra, Inc -------------------- Zimbra :: the leader in open source messaging and collaboration

1 0

Re: (ITS#6330) slapd memory leak
by masarati＠aero.polimi.it 16 Oct '09

16 Oct '09

hyc(a)symas.com wrote: > whm(a)stanford.edu wrote: >> Here is the valgrind output. The complete log is at >> >> http://www.stanford.edu/~whm/files/slapd/valgrind-memcheck.txt > > All of this indicates memory leaks and errors in the SASL library, not any bug > in OpenLDAP. That was exactly my suspect when you originally stated that the leak only appeared after wrapping dynlist requests within a SASL bind/unbind. The leak could still be related to an improper use of SASL library calls by OpenLDAP, although unlikely. However, that valgrind output does not help as leaks related to malloc are too hidden into SASL; you should add --num-callers=<more than 12, the default; enough to see something related to OpenLDAP's code>. p.

1 0

Re: (ITS#6330) slapd memory leak
by whm＠stanford.edu 16 Oct '09

16 Oct '09

--On Friday, October 16, 2009 12:02:59 AM -0700 Howard Chu <hyc(a)symas.com> wrote: > whm(a)stanford.edu wrote: >> Here is the valgrind output. The complete log is at >> >> http://www.stanford.edu/~whm/files/slapd/valgrind-memcheck.txt > > All of this indicates memory leaks and errors in the SASL library, > not any bug in OpenLDAP. That is what I suspected when I looked at the output, but I wanted confirmation from someone that is more familar with valgrind output and the code than me. Of course, until we resolve the issue it effectively disables OpenLDAP 2.4 for us. Thanks for looking at it, Bill >> >> Bill >> >> # valgrind --leak-check=yes /usr/sbin/slapd -f /e tc/ldap/slapd.conf -d 256 >> ==25500== Memcheck, a memory error detector. >> ==25500== Copyright (C) 2002-2007, and GNU GPL'd, by Julian Seward et al. >> ==25500== Using LibVEX rev 1854, a library for dynamic binary translation. >> ==25500== Copyright (C) 2004-2007, and GNU GPL'd, by OpenWorks LLP. >> ==25500== Using valgrind-3.3.1-Debian, a dynamic binary instrumentation framework. >> ==25500== Copyright (C) 2000-2007, and GNU GPL'd, by Julian Seward et al. >> ==25500== For more details, rerun with: -v >> ==25500== >> @(#) $OpenLDAP: slapd 2.4.18 (Sep 29 2009 07:08:49) $ >> root@leviticus.stanford.edu:/tmp/buildd/openldap-2.4.18/debian/build/servers/slapd >> ==25500== Warning: set address range perms: large range 135020544 (defined) >> ==25500== Warning: set address range perms: large range 5368709120 (defined) >> ==25500== Warning: set address range perms: large range 160000008 (defined) >> slapd starting >> ==25500== Thread 3: >> ==25500== Invalid read of size 1 >> ==25500== at 0x4C22B72: strcat (mc_replace_strmem.c:186) >> ==25500== by 0x8A67DDE: (within /usr/lib/sasl2/libgssapiv2.so.2.0.22) >> ==25500== by 0x8A688DB: (within /usr/lib/sasl2/libgssapiv2.so.2.0.22) >> ==25500== by 0x5AF6D34: sasl_client_step (in /usr/lib/libsasl2.so.2.0.22) >> ==25500== by 0x5AF7262: sasl_client_start (in /usr/lib/libsasl2.so.2.0.22) >> ==25500== by 0x4E41CC7: ldap_int_sasl_bind (cyrus.c:509) >> ==25500== by 0x4E45ED6: ldap_sasl_interactive_bind_s (sasl.c:464) >> ==25500== by 0x4336B3: slap_client_connect (config.c:1803) >> ==25500== by 0x4B387C: do_syncrep1 (syncrepl.c:561) >> ==25500== by 0x4B63ED: do_syncrepl (syncrepl.c:1346) >> ==25500== by 0x4E3800C: ldap_int_thread_pool_wrapper (tpool.c:685) >> ==25500== by 0x6B56FC6: start_thread (in /lib/libpthread-2.7.so) >> ==25500== Address 0xb2581c1 is 0 bytes after a block of size 33 alloc'd >> ==25500== at 0x4C2260E: malloc (vg_replace_malloc.c:207) >> ==25500== by 0x8C848AC: (within /usr/lib/libgssapi.so.2.0.0) >> ==25500== by 0x8C85EA7: gss_display_status (in /usr/lib/libgssapi.so.2.0.0) >> ==25500== by 0x8A67D8E: (within /usr/lib/sasl2/libgssapiv2.so.2.0.22) >> ==25500== by 0x8A688DB: (within /usr/lib/sasl2/libgssapiv2.so.2.0.22) >> ==25500== by 0x5AF6D34: sasl_client_step (in /usr/lib/libsasl2.so.2.0.22) >> ==25500== by 0x5AF7262: sasl_client_start (in /usr/lib/libsasl2.so.2.0.22) >> ==25500== by 0x4E41CC7: ldap_int_sasl_bind (cyrus.c:509) >> ==25500== by 0x4E45ED6: ldap_sasl_interactive_bind_s (sasl.c:464) >> ==25500== by 0x4336B3: slap_client_connect (config.c:1803) >> ==25500== by 0x4B387C: do_syncrep1 (syncrepl.c:561) >> ==25500== by 0x4B63ED: do_syncrepl (syncrepl.c:1346) >> ==25500== >> ==25500== Invalid read of size 1 >> ==25500== at 0x4C22B72: strcat (mc_replace_strmem.c:186) >> ==25500== by 0x8A67EDA: (within /usr/lib/sasl2/libgssapiv2.so.2.0.22) >> ==25500== by 0x8A688DB: (within /usr/lib/sasl2/libgssapiv2.so.2.0.22) >> ==25500== by 0x5AF6D34: sasl_client_step (in /usr/lib/libsasl2.so.2.0.22) >> ==25500== by 0x5AF7262: sasl_client_start (in /usr/lib/libsasl2.so.2.0.22) >> ==25500== by 0x4E41CC7: ldap_int_sasl_bind (cyrus.c:509) >> ==25500== by 0x4E45ED6: ldap_sasl_interactive_bind_s (sasl.c:464) >> ==25500== by 0x4336B3: slap_client_connect (config.c:1803) >> ==25500== by 0x4B387C: do_syncrep1 (syncrepl.c:561) >> ==25500== by 0x4B63ED: do_syncrepl (syncrepl.c:1346) >> ==25500== by 0x4E3800C: ldap_int_thread_pool_wrapper (tpool.c:685) >> ==25500== by 0x6B56FC6: start_thread (in /lib/libpthread-2.7.so) >> ==25500== Address 0xb258227 is 0 bytes after a block of size 47 alloc'd >> ==25500== at 0x4C2260E: malloc (vg_replace_malloc.c:207) >> ==25500== by 0x8C848F4: (within /usr/lib/libgssapi.so.2.0.0) >> ==25500== by 0x8C85EA7: gss_display_status (in /usr/lib/libgssapi.so.2.0.0) >> ==25500== by 0x8A67E8A: (within /usr/lib/sasl2/libgssapiv2.so.2.0.22) >> ==25500== by 0x8A688DB: (within /usr/lib/sasl2/libgssapiv2.so.2.0.22) >> ==25500== by 0x5AF6D34: sasl_client_step (in /usr/lib/libsasl2.so.2.0.22) >> ==25500== by 0x5AF7262: sasl_client_start (in /usr/lib/libsasl2.so.2.0.22) >> ==25500== by 0x4E41CC7: ldap_int_sasl_bind (cyrus.c:509) >> ==25500== by 0x4E45ED6: ldap_sasl_interactive_bind_s (sasl.c:464) >> ==25500== by 0x4336B3: slap_client_connect (config.c:1803) >> ==25500== by 0x4B387C: do_syncrep1 (syncrepl.c:561) >> ==25500== by 0x4B63ED: do_syncrepl (syncrepl.c:1346) >> slap_client_connect: URI=ldap://ldap-uatmaster.stanford.edu:389 ldap_sasl_interactive_bind_s failed (-2) >> ==25500== Warning: invalid file descriptor -1 in syscall close() >> do_syncrepl: rid=000 rc -2 retrying >> conn=0 fd=12 ACCEPT from IP=172.20.196.4:48599 (IP=0.0.0.0:389) >> conn=0 op=0 BIND dn="" method=163 >> conn=0 op=0 RESULT tag=97 err=14 text=SASL(0): successful result: >> connection_input: conn=0 deferring operation: binding >> conn=0 op=1 BIND dn="" method=163 >> conn=0 op=1 RESULT tag=97 err=14 text=SASL(0): successful result: >> conn=0 op=2 BIND dn="" method=163 >> conn=0 op=2 BIND authcid="service/course-regis-test(a)stanford.edu" authzid="service/course-regis-test(a)stanford.edu" >> conn=0 op=2 BIND dn="cn=course-regis-test,cn=service,cn=applications,dc=stanford,dc=edu" mech=GSSAPI sasl_ssf=56 ssf=56 >> conn=0 op=2 RESULT tag=97 err=0 text= >> conn=0 op=3 UNBIND >> conn=0 fd=12 closed >> conn=1 fd=12 ACCEPT from IP=171.64.11.53:34814 (IP=0.0.0.0:389) >> conn=1 op=0 SRCH base="" scope=0 deref=0 filter="(objectClass=*)" >> conn=1 op=0 SRCH attr=supportedSASLMechanisms >> conn=1 op=0 SEARCH RESULT tag=101 err=0 nentries=1 text= >> conn=1 op=1 BIND dn="" method=163 >> conn=1 op=1 RESULT tag=97 err=14 text=SASL(0): successful result: >> conn=1 op=2 BIND dn="" method=163 >> conn=1 op=2 RESULT tag=97 err=14 text=SASL(0): successful result: >> conn=1 op=3 BIND dn="" method=163 >> conn=1 op=3 BIND authcid="whm(a)stanford.edu" authzid="whm(a)stanford.edu" >> conn=1 op=3 BIND dn="uid=whm,cn=accounts,dc=stanford,dc=edu" mech=GSSAPI sasl_ssf=56 ssf=56 >> conn=1 op=3 RESULT tag=97 err=0 text= >> conn=1 op=4 SRCH base="cn=groups,dc=stanford,dc=edu" scope=1 deref=0 filter="(objectClass=suWorkgroup)" >> conn=1 op=4 SRCH attr=cn >> conn=2 fd=16 ACCEPT from IP=127.0.0.1:56960 (IP=0.0.0.0:389) >> conn=2 op=0 BIND dn="" method=128 >> conn=2 op=0 RESULT tag=97 err=0 text= >> conn=2 op=1 SRCH base="dc=stanford,dc=edu" scope=2 deref=2 filter="(uid=johnjacobjingleheimerschmidt)" >> conn=2 op=1 SRCH attr=suPtsUid >> conn=2 op=1 SEARCH RESULT tag=101 err=0 nentries=0 text= >> conn=2 op=2 UNBIND >> conn=2 fd=16 closed >> conn=1 op=4 SEARCH RESULT tag=101 err=0 nentries=9287 text= >> conn=1 op=5 UNBIND >> conn=1 fd=12 closed >> conn=3 fd=12 ACCEPT from IP=171.64.11.53:34815 (IP=0.0.0.0:389) >> conn=3 op=0 SRCH base="" scope=0 deref=0 filter="(objectClass=*)" >> conn=3 op=0 SRCH attr=supportedSASLMechanisms >> conn=3 op=0 SEARCH RESULT tag=101 err=0 nentries=1 text= >> conn=3 op=1 BIND dn="" method=163 >> conn=3 op=1 RESULT tag=97 err=14 text=SASL(0): successful result: >> conn=3 op=2 BIND dn="" method=163 >> conn=3 op=2 RESULT tag=97 err=14 text=SASL(0): successful result: >> conn=3 op=3 BIND dn="" method=163 >> conn=3 op=3 BIND authcid="whm(a)stanford.edu" authzid="whm(a)stanford.edu" >> conn=3 op=3 BIND dn="uid=whm,cn=accounts,dc=stanford,dc=edu" mech=GSSAPI sasl_ssf=56 ssf=56 >> conn=3 op=3 RESULT tag=97 err=0 text= >> conn=3 op=4 SRCH base="cn=~tomhurl:cs106bgraders,cn=groups,dc=stanford,dc=edu" scope=0 deref=0 filter="(objectClass=suWorkgroup)" >> conn=3 op=4 SRCH attr=member >> conn=3 op=4 SEARCH RESULT tag=101 err=0 nentries=1 text= >> conn=3 op=5 UNBIND >> conn=3 fd=12 closed >> conn=4 fd=19 ACCEPT from IP=171.64.11.53:34816 (IP=0.0.0.0:389) >> conn=4 op=0 SRCH base="" scope=0 deref=0 filter="(objectClass=*)" >> conn=4 op=0 SRCH attr=supportedSASLMechanisms >> conn=4 op=0 SEARCH RESULT tag=101 err=0 nentries=1 text= >> conn=4 op=1 BIND dn="" method=163 >> conn=4 op=1 RESULT tag=97 err=14 text=SASL(0): successful result: >> conn=4 op=2 BIND dn="" method=163 >> conn=4 op=2 RESULT tag=97 err=14 text=SASL(0): successful result: >> conn=4 op=3 BIND dn="" method=163 >> conn=4 op=3 BIND authcid="whm(a)stanford.edu" authzid="whm(a)stanford.edu" >> conn=4 op=3 BIND dn="uid=whm,cn=accounts,dc=stanford,dc=edu" mech=GSSAPI sasl_ssf=56 ssf=56 >> conn=4 op=3 RESULT tag=97 err=0 text= >> conn=4 op=4 SRCH base="cn=postgrads:pgsample/administrator,cn=groups,dc=stanford,dc=edu" scope=0 deref=0 filter="(objectClass=suWorkgroup)" >> conn=4 op=4 SRCH attr=member >> conn=4 op=4 SEARCH RESULT tag=101 err=0 nentries=1 text= >> conn=4 op=5 UNBIND >> conn=4 fd=19 closed >> conn=5 fd=12 ACCEPT from IP=171.64.11.53:34817 (IP=0.0.0.0:389) >> conn=5 op=0 SRCH base="" scope=0 deref=0 filter="(objectClass=*)" >> conn=5 op=0 SRCH attr=supportedSASLMechanisms >> conn=5 op=0 SEARCH RESULT tag=101 err=0 nentries=1 text= >> conn=5 op=1 BIND dn="" method=163 >> conn=5 op=1 RESULT tag=97 err=14 text=SASL(0): successful result: >> conn=5 op=2 BIND dn="" method=163 >> conn=5 op=2 RESULT tag=97 err=14 text=SASL(0): successful result: >> conn=5 op=3 BIND dn="" method=163 >> conn=5 op=3 BIND authcid="whm(a)stanford.edu" authzid="whm(a)stanford.edu" >> conn=5 op=3 BIND dn="uid=whm,cn=accounts,dc=stanford,dc=edu" mech=GSSAPI sasl_ssf=56 ssf=56 >> conn=5 op=3 RESULT tag=97 err=0 text= >> conn=5 op=4 SRCH base="cn=med-emed:va,cn=groups,dc=stanford,dc=edu" scope=0 deref=0 filter="(objectClass=suWorkgroup)" >> conn=5 op=4 SRCH attr=member >> conn=5 op=4 SEARCH RESULT tag=101 err=0 nentries=1 text= >> conn=5 op=5 UNBIND >> conn=5 fd=12 closed >> >> ... lots of ldap stats output ... >> >> conn=238 op=4 SRCH base="cn=maps:contracts/administrator,cn=groups,dc=stanford,dc=edu" scope=0 deref=0 filter="(objectClass=suWorkgroup)" >> conn=238 op=4 SRCH attr=member >> conn=238 op=4 SEARCH RESULT tag=101 err=0 nentries=1 text= >> conn=238 op=5 UNBIND >> conn=238 fd=12 closed >> conn=239 fd=12 ACCEPT from IP=171.64.11.53:35040 (IP=0.0.0.0:389) >> conn=239 op=0 SRCH base="" scope=0 deref=0 filter="(objectClass=*)" >> conn=239 op=0 SRCH attr=supportedSASLMechanisms >> conn=239 op=0 SEARCH RESULT tag=101 err=0 nentries=1 text= >> conn=239 op=1 BIND dn="" method=163 >> conn=239 op=1 RESULT tag=97 err=14 text=SASL(0): successful result: >> conn=239 op=2 BIND dn="" method=163 >> conn=239 op=2 RESULT tag=97 err=14 text=SASL(0): successful result: >> conn=239 op=3 BIND dn="" method=163 >> conn=239 op=3 BIND authcid="whm(a)stanford.edu" authzid="whm(a)stanford.edu" >> conn=239 fd=12 closed (connection lost) >> ^Cdaemon: shutdown requested and initiated. >> slapd shutdown: waiting for 0 operations/tasks to finish >> ==25500== Warning: set address range perms: large range 5368709120 (noaccess) >> ==25500== Warning: set address range perms: large range 135020544 (noaccess) >> ==25500== Warning: set address range perms: large range 160000040 (noaccess) >> slapd stopped. >> ==25500== >> ==25500== ERROR SUMMARY: 4 errors from 2 contexts (suppressed: 233 from 4) >> ==25500== malloc/free: in use at exit: 6,055,651 bytes in 217,392 blocks. >> ==25500== malloc/free: 1,612,487 allocs, 1,395,095 frees, 499,560,609 bytes allocated. >> ==25500== For counts of detected errors, rerun with: -v >> ==25500== searching for pointers to 217,392 not-freed blocks. >> ==25500== checked 1,035,848 bytes. >> ==25500== >> ==25500== Thread 1: >> ==25500== >> ==25500== 20 bytes in 1 blocks are possibly lost in loss record 13 of 81 >> ==25500== at 0x4C2260E: malloc (vg_replace_malloc.c:207) >> ==25500== by 0x6DE6D91: strdup (in /lib/libc-2.7.so) >> ==25500== by 0x8EC70D4: ??? >> ==25500== by 0x8EC6F7B: ??? >> ==25500== by 0x8EC717D: ??? >> ==25500== by 0x8EC72E4: ??? >> ==25500== by 0x8EC73F9: ??? >> ==25500== by 0x8EC835C: ??? >> ==25500== by 0x8EC89EC: ??? >> ==25500== by 0x8C8D009: ??? >> ==25500== by 0x8C8ACBC: ??? >> ==25500== by 0x8C850CB: ??? >> ==25500== >> ==25500== >> ==25500== 31 bytes in 1 blocks are definitely lost in loss record 14 of 81 >> ==25500== at 0x4C2260E: malloc (vg_replace_malloc.c:207) >> ==25500== by 0x4A7997: slap_sasl_getconfpath (sasl.c:1110) >> ==25500== by 0x5AFFF71: sasl_server_init (in /usr/lib/libsasl2.so.2.0.22) >> ==25500== by 0x4A7B9D: slap_sasl_init (sasl.c:1176) >> ==25500== by 0x477F99: slap_init (init.c:151) >> ==25500== by 0x41A9C0: main (main.c:750) >> ==25500== >> ==25500== >> ==25500== 32 bytes in 1 blocks are possibly lost in loss record 15 of 81 >> ==25500== at 0x4C203E4: calloc (vg_replace_malloc.c:397) >> ==25500== by 0x8EC6D40: ??? >> ==25500== by 0x8EC715F: ??? >> ==25500== by 0x8EC72E4: ??? >> ==25500== by 0x8EC73F9: ??? >> ==25500== by 0x8EC835C: ??? >> ==25500== by 0x8EC89EC: ??? >> ==25500== by 0x8C8D009: ??? >> ==25500== by 0x8C8ACBC: ??? >> ==25500== by 0x8C850CB: ??? >> ==25500== by 0x8C903F0: ??? >> ==25500== by 0x8C850CB: ??? >> ==25500== >> ==25500== >> ==25500== 64 (16 direct, 48 indirect) bytes in 1 blocks are definitely lost in loss record 19 of 81 >> ==25500== at 0x4C2260E: malloc (vg_replace_malloc.c:207) >> ==25500== by 0x8C85B9A: ??? >> ==25500== by 0x8C88D1A: ??? >> ==25500== by 0x8C89B8D: ??? >> ==25500== by 0x8C86DE0: ??? >> ==25500== by 0x8A681E6: ??? >> ==25500== by 0x5AF6D34: sasl_client_step (in /usr/lib/libsasl2.so.2.0.22) >> ==25500== by 0x5AF7262: sasl_client_start (in /usr/lib/libsasl2.so.2.0.22) >> ==25500== by 0x4E41CC7: ldap_int_sasl_bind (cyrus.c:509) >> ==25500== by 0x4E45ED6: ldap_sasl_interactive_bind_s (sasl.c:464) >> ==25500== by 0x4336B3: slap_client_connect (config.c:1803) >> ==25500== by 0x4B387C: do_syncrep1 (syncrepl.c:561) >> ==25500== >> ==25500== >> ==25500== 128 bytes in 4 blocks are definitely lost in loss record 26 of 81 >> ==25500== at 0x4C2260E: malloc (vg_replace_malloc.c:207) >> ==25500== by 0x8ECF6E2: ??? >> ==25500== by 0x8ECF76E: ??? >> ==25500== by 0x8ED7E66: ??? >> ==25500== by 0x8ED4CFF: ??? >> ==25500== by 0x8ED4FBE: ??? >> ==25500== by 0x8ED55EE: ??? >> ==25500== by 0x8ED5B5E: ??? >> ==25500== by 0x8ED6053: ??? >> ==25500== by 0x8C7F194: ??? >> ==25500== by 0x8C7FAB1: ??? >> ==25500== by 0x8C86D56: ??? >> ==25500== >> ==25500== >> ==25500== 1,008 (336 direct, 672 indirect) bytes in 1 blocks are definitely lost in loss record 35 of 81 >> ==25500== at 0x4C2260E: malloc (vg_replace_malloc.c:207) >> ==25500== by 0x8C88C49: ??? >> ==25500== by 0x8C88D4A: ??? >> ==25500== by 0x8C89B8D: ??? >> ==25500== by 0x8C86DE0: ??? >> ==25500== by 0x8A681E6: ??? >> ==25500== by 0x5AF6D34: sasl_client_step (in /usr/lib/libsasl2.so.2.0.22) >> ==25500== by 0x5AF7262: sasl_client_start (in /usr/lib/libsasl2.so.2.0.22) >> ==25500== by 0x4E41CC7: ldap_int_sasl_bind (cyrus.c:509) >> ==25500== by 0x4E45ED6: ldap_sasl_interactive_bind_s (sasl.c:464) >> ==25500== by 0x4336B3: slap_client_connect (config.c:1803) >> ==25500== by 0x4B387C: do_syncrep1 (syncrepl.c:561) >> ==25500== >> ==25500== >> ==25500== 636 (256 direct, 380 indirect) bytes in 8 blocks are definitely lost in loss record 36 of 81 >> ==25500== at 0x4C2260E: malloc (vg_replace_malloc.c:207) >> ==25500== by 0x8EED07A: ??? >> ==25500== by 0x8ED4B96: ??? >> ==25500== by 0x8ED4FBE: ??? >> ==25500== by 0x8ED55EE: ??? >> ==25500== by 0x8ED5B5E: ??? >> ==25500== by 0x8ED6053: ??? >> ==25500== by 0x8C7F194: ??? >> ==25500== by 0x8C7FAB1: ??? >> ==25500== by 0x8C86D56: ??? >> ==25500== by 0x8A681E6: ??? >> ==25500== by 0x5AF6D34: sasl_client_step (in /usr/lib/libsasl2.so.2.0.22) >> ==25500== >> ==25500== >> ==25500== 632 bytes in 1 blocks are possibly lost in loss record 37 of 81 >> ==25500== at 0x4C203E4: calloc (vg_replace_malloc.c:397) >> ==25500== by 0x8C8A6C2: ??? >> ==25500== by 0x8C8ACBC: ??? >> ==25500== by 0x8C850CB: ??? >> ==25500== by 0x8C903F0: ??? >> ==25500== by 0x8C850CB: ??? >> ==25500== by 0x8A697EE: ??? >> ==25500== by 0x5AFDDBE: sasl_server_step (in /usr/lib/libsasl2.so.2.0.22) >> ==25500== by 0x5AFF10D: sasl_server_start (in /usr/lib/libsasl2.so.2.0.22) >> ==25500== by 0x4A88A0: slap_sasl_bind (sasl.c:1522) >> ==25500== by 0x46442D: fe_op_bind (bind.c:280) >> ==25500== by 0x464032: do_bind (bind.c:205) >> ==25500== >> ==25500== >> ==25500== 920 bytes in 1 blocks are possibly lost in loss record 38 of 81 >> ==25500== at 0x4C22741: realloc (vg_replace_malloc.c:429) >> ==25500== by 0x8EC474D: ??? >> ==25500== by 0x8EC8A77: ??? >> ==25500== by 0x8C8D009: ??? >> ==25500== by 0x8C8ACBC: ??? >> ==25500== by 0x8C850CB: ??? >> ==25500== by 0x8C903F0: ??? >> ==25500== by 0x8C850CB: ??? >> ==25500== by 0x8A697EE: ??? >> ==25500== by 0x5AFDDBE: sasl_server_step (in /usr/lib/libsasl2.so.2.0.22) >> ==25500== by 0x5AFF10D: sasl_server_start (in /usr/lib/libsasl2.so.2.0.22) >> ==25500== by 0x4A88A0: slap_sasl_bind (sasl.c:1522) >> ==25500== >> ==25500== >> ==25500== 40,584 (14,592 direct, 25,992 indirect) bytes in 456 blocks are definitely lost in loss record 68 of 81 >> ==25500== at 0x4C203E4: calloc (vg_replace_malloc.c:397) >> ==25500== by 0x8EED11F: ??? >> ==25500== by 0x8EED564: ??? >> ==25500== by 0x8EED65C: ??? >> ==25500== by 0x8C8D175: ??? >> ==25500== by 0x8C8ACBC: ??? >> ==25500== by 0x8C850CB: ??? >> ==25500== by 0x8C903F0: ??? >> ==25500== by 0x8C850CB: ??? >> ==25500== by 0x8A697EE: ??? >> ==25500== by 0x5AFDDBE: sasl_server_step (in /usr/lib/libsasl2.so.2.0.22) >> ==25500== by 0x5AFF10D: sasl_server_start (in /usr/lib/libsasl2.so.2.0.22) >> ==25500== >> ==25500== >> ==25500== 84,628 (34,656 direct, 49,972 indirect) bytes in 228 blocks are definitely lost in loss record 73 of 81 >> ==25500== at 0x4C203E4: calloc (vg_replace_malloc.c:397) >> ==25500== by 0x8EF028B: ??? >> ==25500== by 0x8EF0B2F: ??? >> ==25500== by 0x8C78439: ??? >> ==25500== by 0x8C84A7F: ??? >> ==25500== by 0x8A699F9: ??? >> ==25500== by 0x5AFDDBE: sasl_server_step (in /usr/lib/libsasl2.so.2.0.22) >> ==25500== by 0x5AFF10D: sasl_server_start (in /usr/lib/libsasl2.so.2.0.22) >> ==25500== by 0x4A88A0: slap_sasl_bind (sasl.c:1522) >> ==25500== by 0x46442D: fe_op_bind (bind.c:280) >> ==25500== by 0x464032: do_bind (bind.c:205) >> ==25500== by 0x43CEDD: connection_operation (connection.c:1123) >> ==25500== >> ==25500== >> ==25500== 5,871,600 (287,560 direct, 5,584,040 indirect) bytes in 455 blocks are definitely lost in loss record 81 of 81 >> ==25500== at 0x4C203E4: calloc (vg_replace_malloc.c:397) >> ==25500== by 0x8C8A6C2: ??? >> ==25500== by 0x8C8ACBC: ??? >> ==25500== by 0x8C850CB: ??? >> ==25500== by 0x8C903F0: ??? >> ==25500== by 0x8C850CB: ??? >> ==25500== by 0x8A697EE: ??? >> ==25500== by 0x5AFDDBE: sasl_server_step (in /usr/lib/libsasl2.so.2.0.22) >> ==25500== by 0x5AFF10D: sasl_server_start (in /usr/lib/libsasl2.so.2.0.22) >> ==25500== by 0x4A88A0: slap_sasl_bind (sasl.c:1522) >> ==25500== by 0x46442D: fe_op_bind (bind.c:280) >> ==25500== by 0x464032: do_bind (bind.c:205) >> ==25500== >> ==25500== LEAK SUMMARY: >> ==25500== definitely lost: 337,575 bytes in 1,154 blocks. >> ==25500== indirectly lost: 5,661,104 bytes in 214,509 blocks. >> ==25500== possibly lost: 1,604 bytes in 4 blocks. >> ==25500== still reachable: 55,368 bytes in 1,725 blocks. >> ==25500== suppressed: 0 bytes in 0 blocks. >> ==25500== Reachable blocks (those to which a pointer was found) are not shown. >> ==25500== To see them, rerun with: --leak-check=full --show-reachable=yes -- Bill MacAllister, System Software Programmer Unix Systems Group, Stanford University

1 0

Re: (ITS#6330) slapd memory leak
by hyc＠symas.com 16 Oct '09

16 Oct '09

whm(a)stanford.edu wrote: > Here is the valgrind output. The complete log is at > > http://www.stanford.edu/~whm/files/slapd/valgrind-memcheck.txt All of this indicates memory leaks and errors in the SASL library, not any bug in OpenLDAP. > > Bill > > # valgrind --leak-check=yes /usr/sbin/slapd -f /e tc/ldap/slapd.conf -d 256 > ==25500== Memcheck, a memory error detector. > ==25500== Copyright (C) 2002-2007, and GNU GPL'd, by Julian Seward et al. > ==25500== Using LibVEX rev 1854, a library for dynamic binary translation. > ==25500== Copyright (C) 2004-2007, and GNU GPL'd, by OpenWorks LLP. > ==25500== Using valgrind-3.3.1-Debian, a dynamic binary instrumentation framework. > ==25500== Copyright (C) 2000-2007, and GNU GPL'd, by Julian Seward et al. > ==25500== For more details, rerun with: -v > ==25500== > @(#) $OpenLDAP: slapd 2.4.18 (Sep 29 2009 07:08:49) $ > root@leviticus.stanford.edu:/tmp/buildd/openldap-2.4.18/debian/build/servers/slapd > ==25500== Warning: set address range perms: large range 135020544 (defined) > ==25500== Warning: set address range perms: large range 5368709120 (defined) > ==25500== Warning: set address range perms: large range 160000008 (defined) > slapd starting > ==25500== Thread 3: > ==25500== Invalid read of size 1 > ==25500== at 0x4C22B72: strcat (mc_replace_strmem.c:186) > ==25500== by 0x8A67DDE: (within /usr/lib/sasl2/libgssapiv2.so.2.0.22) > ==25500== by 0x8A688DB: (within /usr/lib/sasl2/libgssapiv2.so.2.0.22) > ==25500== by 0x5AF6D34: sasl_client_step (in /usr/lib/libsasl2.so.2.0.22) > ==25500== by 0x5AF7262: sasl_client_start (in /usr/lib/libsasl2.so.2.0.22) > ==25500== by 0x4E41CC7: ldap_int_sasl_bind (cyrus.c:509) > ==25500== by 0x4E45ED6: ldap_sasl_interactive_bind_s (sasl.c:464) > ==25500== by 0x4336B3: slap_client_connect (config.c:1803) > ==25500== by 0x4B387C: do_syncrep1 (syncrepl.c:561) > ==25500== by 0x4B63ED: do_syncrepl (syncrepl.c:1346) > ==25500== by 0x4E3800C: ldap_int_thread_pool_wrapper (tpool.c:685) > ==25500== by 0x6B56FC6: start_thread (in /lib/libpthread-2.7.so) > ==25500== Address 0xb2581c1 is 0 bytes after a block of size 33 alloc'd > ==25500== at 0x4C2260E: malloc (vg_replace_malloc.c:207) > ==25500== by 0x8C848AC: (within /usr/lib/libgssapi.so.2.0.0) > ==25500== by 0x8C85EA7: gss_display_status (in /usr/lib/libgssapi.so.2.0.0) > ==25500== by 0x8A67D8E: (within /usr/lib/sasl2/libgssapiv2.so.2.0.22) > ==25500== by 0x8A688DB: (within /usr/lib/sasl2/libgssapiv2.so.2.0.22) > ==25500== by 0x5AF6D34: sasl_client_step (in /usr/lib/libsasl2.so.2.0.22) > ==25500== by 0x5AF7262: sasl_client_start (in /usr/lib/libsasl2.so.2.0.22) > ==25500== by 0x4E41CC7: ldap_int_sasl_bind (cyrus.c:509) > ==25500== by 0x4E45ED6: ldap_sasl_interactive_bind_s (sasl.c:464) > ==25500== by 0x4336B3: slap_client_connect (config.c:1803) > ==25500== by 0x4B387C: do_syncrep1 (syncrepl.c:561) > ==25500== by 0x4B63ED: do_syncrepl (syncrepl.c:1346) > ==25500== > ==25500== Invalid read of size 1 > ==25500== at 0x4C22B72: strcat (mc_replace_strmem.c:186) > ==25500== by 0x8A67EDA: (within /usr/lib/sasl2/libgssapiv2.so.2.0.22) > ==25500== by 0x8A688DB: (within /usr/lib/sasl2/libgssapiv2.so.2.0.22) > ==25500== by 0x5AF6D34: sasl_client_step (in /usr/lib/libsasl2.so.2.0.22) > ==25500== by 0x5AF7262: sasl_client_start (in /usr/lib/libsasl2.so.2.0.22) > ==25500== by 0x4E41CC7: ldap_int_sasl_bind (cyrus.c:509) > ==25500== by 0x4E45ED6: ldap_sasl_interactive_bind_s (sasl.c:464) > ==25500== by 0x4336B3: slap_client_connect (config.c:1803) > ==25500== by 0x4B387C: do_syncrep1 (syncrepl.c:561) > ==25500== by 0x4B63ED: do_syncrepl (syncrepl.c:1346) > ==25500== by 0x4E3800C: ldap_int_thread_pool_wrapper (tpool.c:685) > ==25500== by 0x6B56FC6: start_thread (in /lib/libpthread-2.7.so) > ==25500== Address 0xb258227 is 0 bytes after a block of size 47 alloc'd > ==25500== at 0x4C2260E: malloc (vg_replace_malloc.c:207) > ==25500== by 0x8C848F4: (within /usr/lib/libgssapi.so.2.0.0) > ==25500== by 0x8C85EA7: gss_display_status (in /usr/lib/libgssapi.so.2.0.0) > ==25500== by 0x8A67E8A: (within /usr/lib/sasl2/libgssapiv2.so.2.0.22) > ==25500== by 0x8A688DB: (within /usr/lib/sasl2/libgssapiv2.so.2.0.22) > ==25500== by 0x5AF6D34: sasl_client_step (in /usr/lib/libsasl2.so.2.0.22) > ==25500== by 0x5AF7262: sasl_client_start (in /usr/lib/libsasl2.so.2.0.22) > ==25500== by 0x4E41CC7: ldap_int_sasl_bind (cyrus.c:509) > ==25500== by 0x4E45ED6: ldap_sasl_interactive_bind_s (sasl.c:464) > ==25500== by 0x4336B3: slap_client_connect (config.c:1803) > ==25500== by 0x4B387C: do_syncrep1 (syncrepl.c:561) > ==25500== by 0x4B63ED: do_syncrepl (syncrepl.c:1346) > slap_client_connect: URI=ldap://ldap-uatmaster.stanford.edu:389 ldap_sasl_interactive_bind_s failed (-2) > ==25500== Warning: invalid file descriptor -1 in syscall close() > do_syncrepl: rid=000 rc -2 retrying > conn=0 fd=12 ACCEPT from IP=172.20.196.4:48599 (IP=0.0.0.0:389) > conn=0 op=0 BIND dn="" method=163 > conn=0 op=0 RESULT tag=97 err=14 text=SASL(0): successful result: > connection_input: conn=0 deferring operation: binding > conn=0 op=1 BIND dn="" method=163 > conn=0 op=1 RESULT tag=97 err=14 text=SASL(0): successful result: > conn=0 op=2 BIND dn="" method=163 > conn=0 op=2 BIND authcid="service/course-regis-test(a)stanford.edu" authzid="service/course-regis-test(a)stanford.edu" > conn=0 op=2 BIND dn="cn=course-regis-test,cn=service,cn=applications,dc=stanford,dc=edu" mech=GSSAPI sasl_ssf=56 ssf=56 > conn=0 op=2 RESULT tag=97 err=0 text= > conn=0 op=3 UNBIND > conn=0 fd=12 closed > conn=1 fd=12 ACCEPT from IP=171.64.11.53:34814 (IP=0.0.0.0:389) > conn=1 op=0 SRCH base="" scope=0 deref=0 filter="(objectClass=*)" > conn=1 op=0 SRCH attr=supportedSASLMechanisms > conn=1 op=0 SEARCH RESULT tag=101 err=0 nentries=1 text= > conn=1 op=1 BIND dn="" method=163 > conn=1 op=1 RESULT tag=97 err=14 text=SASL(0): successful result: > conn=1 op=2 BIND dn="" method=163 > conn=1 op=2 RESULT tag=97 err=14 text=SASL(0): successful result: > conn=1 op=3 BIND dn="" method=163 > conn=1 op=3 BIND authcid="whm(a)stanford.edu" authzid="whm(a)stanford.edu" > conn=1 op=3 BIND dn="uid=whm,cn=accounts,dc=stanford,dc=edu" mech=GSSAPI sasl_ssf=56 ssf=56 > conn=1 op=3 RESULT tag=97 err=0 text= > conn=1 op=4 SRCH base="cn=groups,dc=stanford,dc=edu" scope=1 deref=0 filter="(objectClass=suWorkgroup)" > conn=1 op=4 SRCH attr=cn > conn=2 fd=16 ACCEPT from IP=127.0.0.1:56960 (IP=0.0.0.0:389) > conn=2 op=0 BIND dn="" method=128 > conn=2 op=0 RESULT tag=97 err=0 text= > conn=2 op=1 SRCH base="dc=stanford,dc=edu" scope=2 deref=2 filter="(uid=johnjacobjingleheimerschmidt)" > conn=2 op=1 SRCH attr=suPtsUid > conn=2 op=1 SEARCH RESULT tag=101 err=0 nentries=0 text= > conn=2 op=2 UNBIND > conn=2 fd=16 closed > conn=1 op=4 SEARCH RESULT tag=101 err=0 nentries=9287 text= > conn=1 op=5 UNBIND > conn=1 fd=12 closed > conn=3 fd=12 ACCEPT from IP=171.64.11.53:34815 (IP=0.0.0.0:389) > conn=3 op=0 SRCH base="" scope=0 deref=0 filter="(objectClass=*)" > conn=3 op=0 SRCH attr=supportedSASLMechanisms > conn=3 op=0 SEARCH RESULT tag=101 err=0 nentries=1 text= > conn=3 op=1 BIND dn="" method=163 > conn=3 op=1 RESULT tag=97 err=14 text=SASL(0): successful result: > conn=3 op=2 BIND dn="" method=163 > conn=3 op=2 RESULT tag=97 err=14 text=SASL(0): successful result: > conn=3 op=3 BIND dn="" method=163 > conn=3 op=3 BIND authcid="whm(a)stanford.edu" authzid="whm(a)stanford.edu" > conn=3 op=3 BIND dn="uid=whm,cn=accounts,dc=stanford,dc=edu" mech=GSSAPI sasl_ssf=56 ssf=56 > conn=3 op=3 RESULT tag=97 err=0 text= > conn=3 op=4 SRCH base="cn=~tomhurl:cs106bgraders,cn=groups,dc=stanford,dc=edu" scope=0 deref=0 filter="(objectClass=suWorkgroup)" > conn=3 op=4 SRCH attr=member > conn=3 op=4 SEARCH RESULT tag=101 err=0 nentries=1 text= > conn=3 op=5 UNBIND > conn=3 fd=12 closed > conn=4 fd=19 ACCEPT from IP=171.64.11.53:34816 (IP=0.0.0.0:389) > conn=4 op=0 SRCH base="" scope=0 deref=0 filter="(objectClass=*)" > conn=4 op=0 SRCH attr=supportedSASLMechanisms > conn=4 op=0 SEARCH RESULT tag=101 err=0 nentries=1 text= > conn=4 op=1 BIND dn="" method=163 > conn=4 op=1 RESULT tag=97 err=14 text=SASL(0): successful result: > conn=4 op=2 BIND dn="" method=163 > conn=4 op=2 RESULT tag=97 err=14 text=SASL(0): successful result: > conn=4 op=3 BIND dn="" method=163 > conn=4 op=3 BIND authcid="whm(a)stanford.edu" authzid="whm(a)stanford.edu" > conn=4 op=3 BIND dn="uid=whm,cn=accounts,dc=stanford,dc=edu" mech=GSSAPI sasl_ssf=56 ssf=56 > conn=4 op=3 RESULT tag=97 err=0 text= > conn=4 op=4 SRCH base="cn=postgrads:pgsample/administrator,cn=groups,dc=stanford,dc=edu" scope=0 deref=0 filter="(objectClass=suWorkgroup)" > conn=4 op=4 SRCH attr=member > conn=4 op=4 SEARCH RESULT tag=101 err=0 nentries=1 text= > conn=4 op=5 UNBIND > conn=4 fd=19 closed > conn=5 fd=12 ACCEPT from IP=171.64.11.53:34817 (IP=0.0.0.0:389) > conn=5 op=0 SRCH base="" scope=0 deref=0 filter="(objectClass=*)" > conn=5 op=0 SRCH attr=supportedSASLMechanisms > conn=5 op=0 SEARCH RESULT tag=101 err=0 nentries=1 text= > conn=5 op=1 BIND dn="" method=163 > conn=5 op=1 RESULT tag=97 err=14 text=SASL(0): successful result: > conn=5 op=2 BIND dn="" method=163 > conn=5 op=2 RESULT tag=97 err=14 text=SASL(0): successful result: > conn=5 op=3 BIND dn="" method=163 > conn=5 op=3 BIND authcid="whm(a)stanford.edu" authzid="whm(a)stanford.edu" > conn=5 op=3 BIND dn="uid=whm,cn=accounts,dc=stanford,dc=edu" mech=GSSAPI sasl_ssf=56 ssf=56 > conn=5 op=3 RESULT tag=97 err=0 text= > conn=5 op=4 SRCH base="cn=med-emed:va,cn=groups,dc=stanford,dc=edu" scope=0 deref=0 filter="(objectClass=suWorkgroup)" > conn=5 op=4 SRCH attr=member > conn=5 op=4 SEARCH RESULT tag=101 err=0 nentries=1 text= > conn=5 op=5 UNBIND > conn=5 fd=12 closed > > ... lots of ldap stats output ... > > conn=238 op=4 SRCH base="cn=maps:contracts/administrator,cn=groups,dc=stanford,dc=edu" scope=0 deref=0 filter="(objectClass=suWorkgroup)" > conn=238 op=4 SRCH attr=member > conn=238 op=4 SEARCH RESULT tag=101 err=0 nentries=1 text= > conn=238 op=5 UNBIND > conn=238 fd=12 closed > conn=239 fd=12 ACCEPT from IP=171.64.11.53:35040 (IP=0.0.0.0:389) > conn=239 op=0 SRCH base="" scope=0 deref=0 filter="(objectClass=*)" > conn=239 op=0 SRCH attr=supportedSASLMechanisms > conn=239 op=0 SEARCH RESULT tag=101 err=0 nentries=1 text= > conn=239 op=1 BIND dn="" method=163 > conn=239 op=1 RESULT tag=97 err=14 text=SASL(0): successful result: > conn=239 op=2 BIND dn="" method=163 > conn=239 op=2 RESULT tag=97 err=14 text=SASL(0): successful result: > conn=239 op=3 BIND dn="" method=163 > conn=239 op=3 BIND authcid="whm(a)stanford.edu" authzid="whm(a)stanford.edu" > conn=239 fd=12 closed (connection lost) > ^Cdaemon: shutdown requested and initiated. > slapd shutdown: waiting for 0 operations/tasks to finish > ==25500== Warning: set address range perms: large range 5368709120 (noaccess) > ==25500== Warning: set address range perms: large range 135020544 (noaccess) > ==25500== Warning: set address range perms: large range 160000040 (noaccess) > slapd stopped. > ==25500== > ==25500== ERROR SUMMARY: 4 errors from 2 contexts (suppressed: 233 from 4) > ==25500== malloc/free: in use at exit: 6,055,651 bytes in 217,392 blocks. > ==25500== malloc/free: 1,612,487 allocs, 1,395,095 frees, 499,560,609 bytes allocated. > ==25500== For counts of detected errors, rerun with: -v > ==25500== searching for pointers to 217,392 not-freed blocks. > ==25500== checked 1,035,848 bytes. > ==25500== > ==25500== Thread 1: > ==25500== > ==25500== 20 bytes in 1 blocks are possibly lost in loss record 13 of 81 > ==25500== at 0x4C2260E: malloc (vg_replace_malloc.c:207) > ==25500== by 0x6DE6D91: strdup (in /lib/libc-2.7.so) > ==25500== by 0x8EC70D4: ??? > ==25500== by 0x8EC6F7B: ??? > ==25500== by 0x8EC717D: ??? > ==25500== by 0x8EC72E4: ??? > ==25500== by 0x8EC73F9: ??? > ==25500== by 0x8EC835C: ??? > ==25500== by 0x8EC89EC: ??? > ==25500== by 0x8C8D009: ??? > ==25500== by 0x8C8ACBC: ??? > ==25500== by 0x8C850CB: ??? > ==25500== > ==25500== > ==25500== 31 bytes in 1 blocks are definitely lost in loss record 14 of 81 > ==25500== at 0x4C2260E: malloc (vg_replace_malloc.c:207) > ==25500== by 0x4A7997: slap_sasl_getconfpath (sasl.c:1110) > ==25500== by 0x5AFFF71: sasl_server_init (in /usr/lib/libsasl2.so.2.0.22) > ==25500== by 0x4A7B9D: slap_sasl_init (sasl.c:1176) > ==25500== by 0x477F99: slap_init (init.c:151) > ==25500== by 0x41A9C0: main (main.c:750) > ==25500== > ==25500== > ==25500== 32 bytes in 1 blocks are possibly lost in loss record 15 of 81 > ==25500== at 0x4C203E4: calloc (vg_replace_malloc.c:397) > ==25500== by 0x8EC6D40: ??? > ==25500== by 0x8EC715F: ??? > ==25500== by 0x8EC72E4: ??? > ==25500== by 0x8EC73F9: ??? > ==25500== by 0x8EC835C: ??? > ==25500== by 0x8EC89EC: ??? > ==25500== by 0x8C8D009: ??? > ==25500== by 0x8C8ACBC: ??? > ==25500== by 0x8C850CB: ??? > ==25500== by 0x8C903F0: ??? > ==25500== by 0x8C850CB: ??? > ==25500== > ==25500== > ==25500== 64 (16 direct, 48 indirect) bytes in 1 blocks are definitely lost in loss record 19 of 81 > ==25500== at 0x4C2260E: malloc (vg_replace_malloc.c:207) > ==25500== by 0x8C85B9A: ??? > ==25500== by 0x8C88D1A: ??? > ==25500== by 0x8C89B8D: ??? > ==25500== by 0x8C86DE0: ??? > ==25500== by 0x8A681E6: ??? > ==25500== by 0x5AF6D34: sasl_client_step (in /usr/lib/libsasl2.so.2.0.22) > ==25500== by 0x5AF7262: sasl_client_start (in /usr/lib/libsasl2.so.2.0.22) > ==25500== by 0x4E41CC7: ldap_int_sasl_bind (cyrus.c:509) > ==25500== by 0x4E45ED6: ldap_sasl_interactive_bind_s (sasl.c:464) > ==25500== by 0x4336B3: slap_client_connect (config.c:1803) > ==25500== by 0x4B387C: do_syncrep1 (syncrepl.c:561) > ==25500== > ==25500== > ==25500== 128 bytes in 4 blocks are definitely lost in loss record 26 of 81 > ==25500== at 0x4C2260E: malloc (vg_replace_malloc.c:207) > ==25500== by 0x8ECF6E2: ??? > ==25500== by 0x8ECF76E: ??? > ==25500== by 0x8ED7E66: ??? > ==25500== by 0x8ED4CFF: ??? > ==25500== by 0x8ED4FBE: ??? > ==25500== by 0x8ED55EE: ??? > ==25500== by 0x8ED5B5E: ??? > ==25500== by 0x8ED6053: ??? > ==25500== by 0x8C7F194: ??? > ==25500== by 0x8C7FAB1: ??? > ==25500== by 0x8C86D56: ??? > ==25500== > ==25500== > ==25500== 1,008 (336 direct, 672 indirect) bytes in 1 blocks are definitely lost in loss record 35 of 81 > ==25500== at 0x4C2260E: malloc (vg_replace_malloc.c:207) > ==25500== by 0x8C88C49: ??? > ==25500== by 0x8C88D4A: ??? > ==25500== by 0x8C89B8D: ??? > ==25500== by 0x8C86DE0: ??? > ==25500== by 0x8A681E6: ??? > ==25500== by 0x5AF6D34: sasl_client_step (in /usr/lib/libsasl2.so.2.0.22) > ==25500== by 0x5AF7262: sasl_client_start (in /usr/lib/libsasl2.so.2.0.22) > ==25500== by 0x4E41CC7: ldap_int_sasl_bind (cyrus.c:509) > ==25500== by 0x4E45ED6: ldap_sasl_interactive_bind_s (sasl.c:464) > ==25500== by 0x4336B3: slap_client_connect (config.c:1803) > ==25500== by 0x4B387C: do_syncrep1 (syncrepl.c:561) > ==25500== > ==25500== > ==25500== 636 (256 direct, 380 indirect) bytes in 8 blocks are definitely lost in loss record 36 of 81 > ==25500== at 0x4C2260E: malloc (vg_replace_malloc.c:207) > ==25500== by 0x8EED07A: ??? > ==25500== by 0x8ED4B96: ??? > ==25500== by 0x8ED4FBE: ??? > ==25500== by 0x8ED55EE: ??? > ==25500== by 0x8ED5B5E: ??? > ==25500== by 0x8ED6053: ??? > ==25500== by 0x8C7F194: ??? > ==25500== by 0x8C7FAB1: ??? > ==25500== by 0x8C86D56: ??? > ==25500== by 0x8A681E6: ??? > ==25500== by 0x5AF6D34: sasl_client_step (in /usr/lib/libsasl2.so.2.0.22) > ==25500== > ==25500== > ==25500== 632 bytes in 1 blocks are possibly lost in loss record 37 of 81 > ==25500== at 0x4C203E4: calloc (vg_replace_malloc.c:397) > ==25500== by 0x8C8A6C2: ??? > ==25500== by 0x8C8ACBC: ??? > ==25500== by 0x8C850CB: ??? > ==25500== by 0x8C903F0: ??? > ==25500== by 0x8C850CB: ??? > ==25500== by 0x8A697EE: ??? > ==25500== by 0x5AFDDBE: sasl_server_step (in /usr/lib/libsasl2.so.2.0.22) > ==25500== by 0x5AFF10D: sasl_server_start (in /usr/lib/libsasl2.so.2.0.22) > ==25500== by 0x4A88A0: slap_sasl_bind (sasl.c:1522) > ==25500== by 0x46442D: fe_op_bind (bind.c:280) > ==25500== by 0x464032: do_bind (bind.c:205) > ==25500== > ==25500== > ==25500== 920 bytes in 1 blocks are possibly lost in loss record 38 of 81 > ==25500== at 0x4C22741: realloc (vg_replace_malloc.c:429) > ==25500== by 0x8EC474D: ??? > ==25500== by 0x8EC8A77: ??? > ==25500== by 0x8C8D009: ??? > ==25500== by 0x8C8ACBC: ??? > ==25500== by 0x8C850CB: ??? > ==25500== by 0x8C903F0: ??? > ==25500== by 0x8C850CB: ??? > ==25500== by 0x8A697EE: ??? > ==25500== by 0x5AFDDBE: sasl_server_step (in /usr/lib/libsasl2.so.2.0.22) > ==25500== by 0x5AFF10D: sasl_server_start (in /usr/lib/libsasl2.so.2.0.22) > ==25500== by 0x4A88A0: slap_sasl_bind (sasl.c:1522) > ==25500== > ==25500== > ==25500== 40,584 (14,592 direct, 25,992 indirect) bytes in 456 blocks are definitely lost in loss record 68 of 81 > ==25500== at 0x4C203E4: calloc (vg_replace_malloc.c:397) > ==25500== by 0x8EED11F: ??? > ==25500== by 0x8EED564: ??? > ==25500== by 0x8EED65C: ??? > ==25500== by 0x8C8D175: ??? > ==25500== by 0x8C8ACBC: ??? > ==25500== by 0x8C850CB: ??? > ==25500== by 0x8C903F0: ??? > ==25500== by 0x8C850CB: ??? > ==25500== by 0x8A697EE: ??? > ==25500== by 0x5AFDDBE: sasl_server_step (in /usr/lib/libsasl2.so.2.0.22) > ==25500== by 0x5AFF10D: sasl_server_start (in /usr/lib/libsasl2.so.2.0.22) > ==25500== > ==25500== > ==25500== 84,628 (34,656 direct, 49,972 indirect) bytes in 228 blocks are definitely lost in loss record 73 of 81 > ==25500== at 0x4C203E4: calloc (vg_replace_malloc.c:397) > ==25500== by 0x8EF028B: ??? > ==25500== by 0x8EF0B2F: ??? > ==25500== by 0x8C78439: ??? > ==25500== by 0x8C84A7F: ??? > ==25500== by 0x8A699F9: ??? > ==25500== by 0x5AFDDBE: sasl_server_step (in /usr/lib/libsasl2.so.2.0.22) > ==25500== by 0x5AFF10D: sasl_server_start (in /usr/lib/libsasl2.so.2.0.22) > ==25500== by 0x4A88A0: slap_sasl_bind (sasl.c:1522) > ==25500== by 0x46442D: fe_op_bind (bind.c:280) > ==25500== by 0x464032: do_bind (bind.c:205) > ==25500== by 0x43CEDD: connection_operation (connection.c:1123) > ==25500== > ==25500== > ==25500== 5,871,600 (287,560 direct, 5,584,040 indirect) bytes in 455 blocks are definitely lost in loss record 81 of 81 > ==25500== at 0x4C203E4: calloc (vg_replace_malloc.c:397) > ==25500== by 0x8C8A6C2: ??? > ==25500== by 0x8C8ACBC: ??? > ==25500== by 0x8C850CB: ??? > ==25500== by 0x8C903F0: ??? > ==25500== by 0x8C850CB: ??? > ==25500== by 0x8A697EE: ??? > ==25500== by 0x5AFDDBE: sasl_server_step (in /usr/lib/libsasl2.so.2.0.22) > ==25500== by 0x5AFF10D: sasl_server_start (in /usr/lib/libsasl2.so.2.0.22) > ==25500== by 0x4A88A0: slap_sasl_bind (sasl.c:1522) > ==25500== by 0x46442D: fe_op_bind (bind.c:280) > ==25500== by 0x464032: do_bind (bind.c:205) > ==25500== > ==25500== LEAK SUMMARY: > ==25500== definitely lost: 337,575 bytes in 1,154 blocks. > ==25500== indirectly lost: 5,661,104 bytes in 214,509 blocks. > ==25500== possibly lost: 1,604 bytes in 4 blocks. > ==25500== still reachable: 55,368 bytes in 1,725 blocks. > ==25500== suppressed: 0 bytes in 0 blocks. > ==25500== Reachable blocks (those to which a pointer was found) are not shown. > ==25500== To see them, rerun with: --leak-check=full --show-reachable=yes > -- -- Howard Chu CTO, 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#6330) slapd memory leak
by whm＠stanford.edu 15 Oct '09

15 Oct '09

Here is the valgrind output. The complete log is at http://www.stanford.edu/~whm/files/slapd/valgrind-memcheck.txt Bill # valgrind --leak-check=yes /usr/sbin/slapd -f /e tc/ldap/slapd.conf -d 256 ==25500== Memcheck, a memory error detector. ==25500== Copyright (C) 2002-2007, and GNU GPL'd, by Julian Seward et al. ==25500== Using LibVEX rev 1854, a library for dynamic binary translation. ==25500== Copyright (C) 2004-2007, and GNU GPL'd, by OpenWorks LLP. ==25500== Using valgrind-3.3.1-Debian, a dynamic binary instrumentation framework. ==25500== Copyright (C) 2000-2007, and GNU GPL'd, by Julian Seward et al. ==25500== For more details, rerun with: -v ==25500== @(#) $OpenLDAP: slapd 2.4.18 (Sep 29 2009 07:08:49) $ root@leviticus.stanford.edu:/tmp/buildd/openldap-2.4.18/debian/build/servers/slapd ==25500== Warning: set address range perms: large range 135020544 (defined) ==25500== Warning: set address range perms: large range 5368709120 (defined) ==25500== Warning: set address range perms: large range 160000008 (defined) slapd starting ==25500== Thread 3: ==25500== Invalid read of size 1 ==25500== at 0x4C22B72: strcat (mc_replace_strmem.c:186) ==25500== by 0x8A67DDE: (within /usr/lib/sasl2/libgssapiv2.so.2.0.22) ==25500== by 0x8A688DB: (within /usr/lib/sasl2/libgssapiv2.so.2.0.22) ==25500== by 0x5AF6D34: sasl_client_step (in /usr/lib/libsasl2.so.2.0.22) ==25500== by 0x5AF7262: sasl_client_start (in /usr/lib/libsasl2.so.2.0.22) ==25500== by 0x4E41CC7: ldap_int_sasl_bind (cyrus.c:509) ==25500== by 0x4E45ED6: ldap_sasl_interactive_bind_s (sasl.c:464) ==25500== by 0x4336B3: slap_client_connect (config.c:1803) ==25500== by 0x4B387C: do_syncrep1 (syncrepl.c:561) ==25500== by 0x4B63ED: do_syncrepl (syncrepl.c:1346) ==25500== by 0x4E3800C: ldap_int_thread_pool_wrapper (tpool.c:685) ==25500== by 0x6B56FC6: start_thread (in /lib/libpthread-2.7.so) ==25500== Address 0xb2581c1 is 0 bytes after a block of size 33 alloc'd ==25500== at 0x4C2260E: malloc (vg_replace_malloc.c:207) ==25500== by 0x8C848AC: (within /usr/lib/libgssapi.so.2.0.0) ==25500== by 0x8C85EA7: gss_display_status (in /usr/lib/libgssapi.so.2.0.0) ==25500== by 0x8A67D8E: (within /usr/lib/sasl2/libgssapiv2.so.2.0.22) ==25500== by 0x8A688DB: (within /usr/lib/sasl2/libgssapiv2.so.2.0.22) ==25500== by 0x5AF6D34: sasl_client_step (in /usr/lib/libsasl2.so.2.0.22) ==25500== by 0x5AF7262: sasl_client_start (in /usr/lib/libsasl2.so.2.0.22) ==25500== by 0x4E41CC7: ldap_int_sasl_bind (cyrus.c:509) ==25500== by 0x4E45ED6: ldap_sasl_interactive_bind_s (sasl.c:464) ==25500== by 0x4336B3: slap_client_connect (config.c:1803) ==25500== by 0x4B387C: do_syncrep1 (syncrepl.c:561) ==25500== by 0x4B63ED: do_syncrepl (syncrepl.c:1346) ==25500== ==25500== Invalid read of size 1 ==25500== at 0x4C22B72: strcat (mc_replace_strmem.c:186) ==25500== by 0x8A67EDA: (within /usr/lib/sasl2/libgssapiv2.so.2.0.22) ==25500== by 0x8A688DB: (within /usr/lib/sasl2/libgssapiv2.so.2.0.22) ==25500== by 0x5AF6D34: sasl_client_step (in /usr/lib/libsasl2.so.2.0.22) ==25500== by 0x5AF7262: sasl_client_start (in /usr/lib/libsasl2.so.2.0.22) ==25500== by 0x4E41CC7: ldap_int_sasl_bind (cyrus.c:509) ==25500== by 0x4E45ED6: ldap_sasl_interactive_bind_s (sasl.c:464) ==25500== by 0x4336B3: slap_client_connect (config.c:1803) ==25500== by 0x4B387C: do_syncrep1 (syncrepl.c:561) ==25500== by 0x4B63ED: do_syncrepl (syncrepl.c:1346) ==25500== by 0x4E3800C: ldap_int_thread_pool_wrapper (tpool.c:685) ==25500== by 0x6B56FC6: start_thread (in /lib/libpthread-2.7.so) ==25500== Address 0xb258227 is 0 bytes after a block of size 47 alloc'd ==25500== at 0x4C2260E: malloc (vg_replace_malloc.c:207) ==25500== by 0x8C848F4: (within /usr/lib/libgssapi.so.2.0.0) ==25500== by 0x8C85EA7: gss_display_status (in /usr/lib/libgssapi.so.2.0.0) ==25500== by 0x8A67E8A: (within /usr/lib/sasl2/libgssapiv2.so.2.0.22) ==25500== by 0x8A688DB: (within /usr/lib/sasl2/libgssapiv2.so.2.0.22) ==25500== by 0x5AF6D34: sasl_client_step (in /usr/lib/libsasl2.so.2.0.22) ==25500== by 0x5AF7262: sasl_client_start (in /usr/lib/libsasl2.so.2.0.22) ==25500== by 0x4E41CC7: ldap_int_sasl_bind (cyrus.c:509) ==25500== by 0x4E45ED6: ldap_sasl_interactive_bind_s (sasl.c:464) ==25500== by 0x4336B3: slap_client_connect (config.c:1803) ==25500== by 0x4B387C: do_syncrep1 (syncrepl.c:561) ==25500== by 0x4B63ED: do_syncrepl (syncrepl.c:1346) slap_client_connect: URI=ldap://ldap-uatmaster.stanford.edu:389 ldap_sasl_interactive_bind_s failed (-2) ==25500== Warning: invalid file descriptor -1 in syscall close() do_syncrepl: rid=000 rc -2 retrying conn=0 fd=12 ACCEPT from IP=172.20.196.4:48599 (IP=0.0.0.0:389) conn=0 op=0 BIND dn="" method=163 conn=0 op=0 RESULT tag=97 err=14 text=SASL(0): successful result: connection_input: conn=0 deferring operation: binding conn=0 op=1 BIND dn="" method=163 conn=0 op=1 RESULT tag=97 err=14 text=SASL(0): successful result: conn=0 op=2 BIND dn="" method=163 conn=0 op=2 BIND authcid="service/course-regis-test(a)stanford.edu" authzid="service/course-regis-test(a)stanford.edu" conn=0 op=2 BIND dn="cn=course-regis-test,cn=service,cn=applications,dc=stanford,dc=edu" mech=GSSAPI sasl_ssf=56 ssf=56 conn=0 op=2 RESULT tag=97 err=0 text= conn=0 op=3 UNBIND conn=0 fd=12 closed conn=1 fd=12 ACCEPT from IP=171.64.11.53:34814 (IP=0.0.0.0:389) conn=1 op=0 SRCH base="" scope=0 deref=0 filter="(objectClass=*)" conn=1 op=0 SRCH attr=supportedSASLMechanisms conn=1 op=0 SEARCH RESULT tag=101 err=0 nentries=1 text= conn=1 op=1 BIND dn="" method=163 conn=1 op=1 RESULT tag=97 err=14 text=SASL(0): successful result: conn=1 op=2 BIND dn="" method=163 conn=1 op=2 RESULT tag=97 err=14 text=SASL(0): successful result: conn=1 op=3 BIND dn="" method=163 conn=1 op=3 BIND authcid="whm(a)stanford.edu" authzid="whm(a)stanford.edu" conn=1 op=3 BIND dn="uid=whm,cn=accounts,dc=stanford,dc=edu" mech=GSSAPI sasl_ssf=56 ssf=56 conn=1 op=3 RESULT tag=97 err=0 text= conn=1 op=4 SRCH base="cn=groups,dc=stanford,dc=edu" scope=1 deref=0 filter="(objectClass=suWorkgroup)" conn=1 op=4 SRCH attr=cn conn=2 fd=16 ACCEPT from IP=127.0.0.1:56960 (IP=0.0.0.0:389) conn=2 op=0 BIND dn="" method=128 conn=2 op=0 RESULT tag=97 err=0 text= conn=2 op=1 SRCH base="dc=stanford,dc=edu" scope=2 deref=2 filter="(uid=johnjacobjingleheimerschmidt)" conn=2 op=1 SRCH attr=suPtsUid conn=2 op=1 SEARCH RESULT tag=101 err=0 nentries=0 text= conn=2 op=2 UNBIND conn=2 fd=16 closed conn=1 op=4 SEARCH RESULT tag=101 err=0 nentries=9287 text= conn=1 op=5 UNBIND conn=1 fd=12 closed conn=3 fd=12 ACCEPT from IP=171.64.11.53:34815 (IP=0.0.0.0:389) conn=3 op=0 SRCH base="" scope=0 deref=0 filter="(objectClass=*)" conn=3 op=0 SRCH attr=supportedSASLMechanisms conn=3 op=0 SEARCH RESULT tag=101 err=0 nentries=1 text= conn=3 op=1 BIND dn="" method=163 conn=3 op=1 RESULT tag=97 err=14 text=SASL(0): successful result: conn=3 op=2 BIND dn="" method=163 conn=3 op=2 RESULT tag=97 err=14 text=SASL(0): successful result: conn=3 op=3 BIND dn="" method=163 conn=3 op=3 BIND authcid="whm(a)stanford.edu" authzid="whm(a)stanford.edu" conn=3 op=3 BIND dn="uid=whm,cn=accounts,dc=stanford,dc=edu" mech=GSSAPI sasl_ssf=56 ssf=56 conn=3 op=3 RESULT tag=97 err=0 text= conn=3 op=4 SRCH base="cn=~tomhurl:cs106bgraders,cn=groups,dc=stanford,dc=edu" scope=0 deref=0 filter="(objectClass=suWorkgroup)" conn=3 op=4 SRCH attr=member conn=3 op=4 SEARCH RESULT tag=101 err=0 nentries=1 text= conn=3 op=5 UNBIND conn=3 fd=12 closed conn=4 fd=19 ACCEPT from IP=171.64.11.53:34816 (IP=0.0.0.0:389) conn=4 op=0 SRCH base="" scope=0 deref=0 filter="(objectClass=*)" conn=4 op=0 SRCH attr=supportedSASLMechanisms conn=4 op=0 SEARCH RESULT tag=101 err=0 nentries=1 text= conn=4 op=1 BIND dn="" method=163 conn=4 op=1 RESULT tag=97 err=14 text=SASL(0): successful result: conn=4 op=2 BIND dn="" method=163 conn=4 op=2 RESULT tag=97 err=14 text=SASL(0): successful result: conn=4 op=3 BIND dn="" method=163 conn=4 op=3 BIND authcid="whm(a)stanford.edu" authzid="whm(a)stanford.edu" conn=4 op=3 BIND dn="uid=whm,cn=accounts,dc=stanford,dc=edu" mech=GSSAPI sasl_ssf=56 ssf=56 conn=4 op=3 RESULT tag=97 err=0 text= conn=4 op=4 SRCH base="cn=postgrads:pgsample/administrator,cn=groups,dc=stanford,dc=edu" scope=0 deref=0 filter="(objectClass=suWorkgroup)" conn=4 op=4 SRCH attr=member conn=4 op=4 SEARCH RESULT tag=101 err=0 nentries=1 text= conn=4 op=5 UNBIND conn=4 fd=19 closed conn=5 fd=12 ACCEPT from IP=171.64.11.53:34817 (IP=0.0.0.0:389) conn=5 op=0 SRCH base="" scope=0 deref=0 filter="(objectClass=*)" conn=5 op=0 SRCH attr=supportedSASLMechanisms conn=5 op=0 SEARCH RESULT tag=101 err=0 nentries=1 text= conn=5 op=1 BIND dn="" method=163 conn=5 op=1 RESULT tag=97 err=14 text=SASL(0): successful result: conn=5 op=2 BIND dn="" method=163 conn=5 op=2 RESULT tag=97 err=14 text=SASL(0): successful result: conn=5 op=3 BIND dn="" method=163 conn=5 op=3 BIND authcid="whm(a)stanford.edu" authzid="whm(a)stanford.edu" conn=5 op=3 BIND dn="uid=whm,cn=accounts,dc=stanford,dc=edu" mech=GSSAPI sasl_ssf=56 ssf=56 conn=5 op=3 RESULT tag=97 err=0 text= conn=5 op=4 SRCH base="cn=med-emed:va,cn=groups,dc=stanford,dc=edu" scope=0 deref=0 filter="(objectClass=suWorkgroup)" conn=5 op=4 SRCH attr=member conn=5 op=4 SEARCH RESULT tag=101 err=0 nentries=1 text= conn=5 op=5 UNBIND conn=5 fd=12 closed ... lots of ldap stats output ... conn=238 op=4 SRCH base="cn=maps:contracts/administrator,cn=groups,dc=stanford,dc=edu" scope=0 deref=0 filter="(objectClass=suWorkgroup)" conn=238 op=4 SRCH attr=member conn=238 op=4 SEARCH RESULT tag=101 err=0 nentries=1 text= conn=238 op=5 UNBIND conn=238 fd=12 closed conn=239 fd=12 ACCEPT from IP=171.64.11.53:35040 (IP=0.0.0.0:389) conn=239 op=0 SRCH base="" scope=0 deref=0 filter="(objectClass=*)" conn=239 op=0 SRCH attr=supportedSASLMechanisms conn=239 op=0 SEARCH RESULT tag=101 err=0 nentries=1 text= conn=239 op=1 BIND dn="" method=163 conn=239 op=1 RESULT tag=97 err=14 text=SASL(0): successful result: conn=239 op=2 BIND dn="" method=163 conn=239 op=2 RESULT tag=97 err=14 text=SASL(0): successful result: conn=239 op=3 BIND dn="" method=163 conn=239 op=3 BIND authcid="whm(a)stanford.edu" authzid="whm(a)stanford.edu" conn=239 fd=12 closed (connection lost) ^Cdaemon: shutdown requested and initiated. slapd shutdown: waiting for 0 operations/tasks to finish ==25500== Warning: set address range perms: large range 5368709120 (noaccess) ==25500== Warning: set address range perms: large range 135020544 (noaccess) ==25500== Warning: set address range perms: large range 160000040 (noaccess) slapd stopped. ==25500== ==25500== ERROR SUMMARY: 4 errors from 2 contexts (suppressed: 233 from 4) ==25500== malloc/free: in use at exit: 6,055,651 bytes in 217,392 blocks. ==25500== malloc/free: 1,612,487 allocs, 1,395,095 frees, 499,560,609 bytes allocated. ==25500== For counts of detected errors, rerun with: -v ==25500== searching for pointers to 217,392 not-freed blocks. ==25500== checked 1,035,848 bytes. ==25500== ==25500== Thread 1: ==25500== ==25500== 20 bytes in 1 blocks are possibly lost in loss record 13 of 81 ==25500== at 0x4C2260E: malloc (vg_replace_malloc.c:207) ==25500== by 0x6DE6D91: strdup (in /lib/libc-2.7.so) ==25500== by 0x8EC70D4: ??? ==25500== by 0x8EC6F7B: ??? ==25500== by 0x8EC717D: ??? ==25500== by 0x8EC72E4: ??? ==25500== by 0x8EC73F9: ??? ==25500== by 0x8EC835C: ??? ==25500== by 0x8EC89EC: ??? ==25500== by 0x8C8D009: ??? ==25500== by 0x8C8ACBC: ??? ==25500== by 0x8C850CB: ??? ==25500== ==25500== ==25500== 31 bytes in 1 blocks are definitely lost in loss record 14 of 81 ==25500== at 0x4C2260E: malloc (vg_replace_malloc.c:207) ==25500== by 0x4A7997: slap_sasl_getconfpath (sasl.c:1110) ==25500== by 0x5AFFF71: sasl_server_init (in /usr/lib/libsasl2.so.2.0.22) ==25500== by 0x4A7B9D: slap_sasl_init (sasl.c:1176) ==25500== by 0x477F99: slap_init (init.c:151) ==25500== by 0x41A9C0: main (main.c:750) ==25500== ==25500== ==25500== 32 bytes in 1 blocks are possibly lost in loss record 15 of 81 ==25500== at 0x4C203E4: calloc (vg_replace_malloc.c:397) ==25500== by 0x8EC6D40: ??? ==25500== by 0x8EC715F: ??? ==25500== by 0x8EC72E4: ??? ==25500== by 0x8EC73F9: ??? ==25500== by 0x8EC835C: ??? ==25500== by 0x8EC89EC: ??? ==25500== by 0x8C8D009: ??? ==25500== by 0x8C8ACBC: ??? ==25500== by 0x8C850CB: ??? ==25500== by 0x8C903F0: ??? ==25500== by 0x8C850CB: ??? ==25500== ==25500== ==25500== 64 (16 direct, 48 indirect) bytes in 1 blocks are definitely lost in loss record 19 of 81 ==25500== at 0x4C2260E: malloc (vg_replace_malloc.c:207) ==25500== by 0x8C85B9A: ??? ==25500== by 0x8C88D1A: ??? ==25500== by 0x8C89B8D: ??? ==25500== by 0x8C86DE0: ??? ==25500== by 0x8A681E6: ??? ==25500== by 0x5AF6D34: sasl_client_step (in /usr/lib/libsasl2.so.2.0.22) ==25500== by 0x5AF7262: sasl_client_start (in /usr/lib/libsasl2.so.2.0.22) ==25500== by 0x4E41CC7: ldap_int_sasl_bind (cyrus.c:509) ==25500== by 0x4E45ED6: ldap_sasl_interactive_bind_s (sasl.c:464) ==25500== by 0x4336B3: slap_client_connect (config.c:1803) ==25500== by 0x4B387C: do_syncrep1 (syncrepl.c:561) ==25500== ==25500== ==25500== 128 bytes in 4 blocks are definitely lost in loss record 26 of 81 ==25500== at 0x4C2260E: malloc (vg_replace_malloc.c:207) ==25500== by 0x8ECF6E2: ??? ==25500== by 0x8ECF76E: ??? ==25500== by 0x8ED7E66: ??? ==25500== by 0x8ED4CFF: ??? ==25500== by 0x8ED4FBE: ??? ==25500== by 0x8ED55EE: ??? ==25500== by 0x8ED5B5E: ??? ==25500== by 0x8ED6053: ??? ==25500== by 0x8C7F194: ??? ==25500== by 0x8C7FAB1: ??? ==25500== by 0x8C86D56: ??? ==25500== ==25500== ==25500== 1,008 (336 direct, 672 indirect) bytes in 1 blocks are definitely lost in loss record 35 of 81 ==25500== at 0x4C2260E: malloc (vg_replace_malloc.c:207) ==25500== by 0x8C88C49: ??? ==25500== by 0x8C88D4A: ??? ==25500== by 0x8C89B8D: ??? ==25500== by 0x8C86DE0: ??? ==25500== by 0x8A681E6: ??? ==25500== by 0x5AF6D34: sasl_client_step (in /usr/lib/libsasl2.so.2.0.22) ==25500== by 0x5AF7262: sasl_client_start (in /usr/lib/libsasl2.so.2.0.22) ==25500== by 0x4E41CC7: ldap_int_sasl_bind (cyrus.c:509) ==25500== by 0x4E45ED6: ldap_sasl_interactive_bind_s (sasl.c:464) ==25500== by 0x4336B3: slap_client_connect (config.c:1803) ==25500== by 0x4B387C: do_syncrep1 (syncrepl.c:561) ==25500== ==25500== ==25500== 636 (256 direct, 380 indirect) bytes in 8 blocks are definitely lost in loss record 36 of 81 ==25500== at 0x4C2260E: malloc (vg_replace_malloc.c:207) ==25500== by 0x8EED07A: ??? ==25500== by 0x8ED4B96: ??? ==25500== by 0x8ED4FBE: ??? ==25500== by 0x8ED55EE: ??? ==25500== by 0x8ED5B5E: ??? ==25500== by 0x8ED6053: ??? ==25500== by 0x8C7F194: ??? ==25500== by 0x8C7FAB1: ??? ==25500== by 0x8C86D56: ??? ==25500== by 0x8A681E6: ??? ==25500== by 0x5AF6D34: sasl_client_step (in /usr/lib/libsasl2.so.2.0.22) ==25500== ==25500== ==25500== 632 bytes in 1 blocks are possibly lost in loss record 37 of 81 ==25500== at 0x4C203E4: calloc (vg_replace_malloc.c:397) ==25500== by 0x8C8A6C2: ??? ==25500== by 0x8C8ACBC: ??? ==25500== by 0x8C850CB: ??? ==25500== by 0x8C903F0: ??? ==25500== by 0x8C850CB: ??? ==25500== by 0x8A697EE: ??? ==25500== by 0x5AFDDBE: sasl_server_step (in /usr/lib/libsasl2.so.2.0.22) ==25500== by 0x5AFF10D: sasl_server_start (in /usr/lib/libsasl2.so.2.0.22) ==25500== by 0x4A88A0: slap_sasl_bind (sasl.c:1522) ==25500== by 0x46442D: fe_op_bind (bind.c:280) ==25500== by 0x464032: do_bind (bind.c:205) ==25500== ==25500== ==25500== 920 bytes in 1 blocks are possibly lost in loss record 38 of 81 ==25500== at 0x4C22741: realloc (vg_replace_malloc.c:429) ==25500== by 0x8EC474D: ??? ==25500== by 0x8EC8A77: ??? ==25500== by 0x8C8D009: ??? ==25500== by 0x8C8ACBC: ??? ==25500== by 0x8C850CB: ??? ==25500== by 0x8C903F0: ??? ==25500== by 0x8C850CB: ??? ==25500== by 0x8A697EE: ??? ==25500== by 0x5AFDDBE: sasl_server_step (in /usr/lib/libsasl2.so.2.0.22) ==25500== by 0x5AFF10D: sasl_server_start (in /usr/lib/libsasl2.so.2.0.22) ==25500== by 0x4A88A0: slap_sasl_bind (sasl.c:1522) ==25500== ==25500== ==25500== 40,584 (14,592 direct, 25,992 indirect) bytes in 456 blocks are definitely lost in loss record 68 of 81 ==25500== at 0x4C203E4: calloc (vg_replace_malloc.c:397) ==25500== by 0x8EED11F: ??? ==25500== by 0x8EED564: ??? ==25500== by 0x8EED65C: ??? ==25500== by 0x8C8D175: ??? ==25500== by 0x8C8ACBC: ??? ==25500== by 0x8C850CB: ??? ==25500== by 0x8C903F0: ??? ==25500== by 0x8C850CB: ??? ==25500== by 0x8A697EE: ??? ==25500== by 0x5AFDDBE: sasl_server_step (in /usr/lib/libsasl2.so.2.0.22) ==25500== by 0x5AFF10D: sasl_server_start (in /usr/lib/libsasl2.so.2.0.22) ==25500== ==25500== ==25500== 84,628 (34,656 direct, 49,972 indirect) bytes in 228 blocks are definitely lost in loss record 73 of 81 ==25500== at 0x4C203E4: calloc (vg_replace_malloc.c:397) ==25500== by 0x8EF028B: ??? ==25500== by 0x8EF0B2F: ??? ==25500== by 0x8C78439: ??? ==25500== by 0x8C84A7F: ??? ==25500== by 0x8A699F9: ??? ==25500== by 0x5AFDDBE: sasl_server_step (in /usr/lib/libsasl2.so.2.0.22) ==25500== by 0x5AFF10D: sasl_server_start (in /usr/lib/libsasl2.so.2.0.22) ==25500== by 0x4A88A0: slap_sasl_bind (sasl.c:1522) ==25500== by 0x46442D: fe_op_bind (bind.c:280) ==25500== by 0x464032: do_bind (bind.c:205) ==25500== by 0x43CEDD: connection_operation (connection.c:1123) ==25500== ==25500== ==25500== 5,871,600 (287,560 direct, 5,584,040 indirect) bytes in 455 blocks are definitely lost in loss record 81 of 81 ==25500== at 0x4C203E4: calloc (vg_replace_malloc.c:397) ==25500== by 0x8C8A6C2: ??? ==25500== by 0x8C8ACBC: ??? ==25500== by 0x8C850CB: ??? ==25500== by 0x8C903F0: ??? ==25500== by 0x8C850CB: ??? ==25500== by 0x8A697EE: ??? ==25500== by 0x5AFDDBE: sasl_server_step (in /usr/lib/libsasl2.so.2.0.22) ==25500== by 0x5AFF10D: sasl_server_start (in /usr/lib/libsasl2.so.2.0.22) ==25500== by 0x4A88A0: slap_sasl_bind (sasl.c:1522) ==25500== by 0x46442D: fe_op_bind (bind.c:280) ==25500== by 0x464032: do_bind (bind.c:205) ==25500== ==25500== LEAK SUMMARY: ==25500== definitely lost: 337,575 bytes in 1,154 blocks. ==25500== indirectly lost: 5,661,104 bytes in 214,509 blocks. ==25500== possibly lost: 1,604 bytes in 4 blocks. ==25500== still reachable: 55,368 bytes in 1,725 blocks. ==25500== suppressed: 0 bytes in 0 blocks. ==25500== Reachable blocks (those to which a pointer was found) are not shown. ==25500== To see them, rerun with: --leak-check=full --show-reachable=yes -- Bill MacAllister, System Software Programmer Unix Systems Group, Stanford University

1 0

Re: (ITS#6331) slapd freezing, not accepting further 'write' operations while 'read' operations are unaffected
by j＠telepaths.org 15 Oct '09

15 Oct '09

That is exactly what I will do, thanks again. Jeff

1 0

Re: (ITS#6331) slapd freezing, not accepting further 'write' operations while 'read' operations are unaffected
by quanah＠zimbra.com 15 Oct '09

15 Oct '09

--On Thursday, October 15, 2009 6:48 PM +0000 j(a)telepaths.org wrote: > Quanah, > > I wasn't sure what you meant, but I figured out gdb (never used it > before): > > This is what I did (on both servers), so I'm putting it here so people > aren't left in the dark: > > dpkg -i slapd-dbg (whatever version applicable) > apt-get install gdb > gdb (enter gdb console) > gdb> file /usr/sbin/slapd > gdb> set args -d -1 -u openldap -g openldap -h ldap:/// ldaps:/// > ldapi:/// -f /etc/ldap/slapd.conf > gdb> run > > Running on both servers now .... Great! After one crashes, run "thr apply all bt" and send that output to the ITS. --Quanah -- Quanah Gibson-Mount Principal Software Engineer Zimbra, Inc -------------------- Zimbra :: the leader in open source messaging and collaboration

1 0

Re: (ITS#6331) slapd freezing, not accepting further 'write' operations while 'read' operations are unaffected
by j＠telepaths.org 15 Oct '09

15 Oct '09

Quanah, I wasn't sure what you meant, but I figured out gdb (never used it before): This is what I did (on both servers), so I'm putting it here so people aren't left in the dark: dpkg -i slapd-dbg (whatever version applicable) apt-get install gdb gdb (enter gdb console) gdb> file /usr/sbin/slapd gdb> set args -d -1 -u openldap -g openldap -h ldap:/// ldaps:/// ldapi:/// -f /etc/ldap/slapd.conf gdb> run Running on both servers now .... Jeff

1 0

Re: (ITS#6331) slapd freezing, not accepting further 'write' operations while 'read' operations are unaffected
by quanah＠zimbra.com 15 Oct '09

15 Oct '09

--On Thursday, October 15, 2009 6:06 PM +0000 j(a)telepaths.org wrote: > We are in luck. I started fresh with my two servers (deleted the data > and repopulated). > > During the INITIAL sync-up on "server1" (receiving data from server2): > > <= index_entry_add( 225, > "krb5PrincipalName=host/seven.relay.example.com(a)RELAY.EXAMPLE.COM > ,cn=RELAY.EXAMPLE.COM,cn=gssapi,cn=auth,dc=real,dc=example,dc=com" ) > success > => entry_encode(0x000000e1): > <= entry_encode(0x000000e1): > => acl_get: [2] matched > => acl_get: [2] attr userPassword > => match[dn0]: 0 60 > uid=plainproxy,cn=plain,cn=auth,dc=real,dc=example,dc=com > => match[dn1]: 0 3 uid > => match[dn2]: 4 14 plainproxy > => acl_mask: access to entry > "uid=plainproxy,cn=plain,cn=auth,dc=real,dc=example,dc=com", attr > "userPassword" requested > => acl_mask: to value by "", (=0) > <= check a_dn_pat: self > <= check a_dn_pat: > uid=plainchange,cn=plain,cn=auth,dc=real,dc=example,dc=com > <= check a_dn_pat: > uid=plainmodify,cn=plain,cn=auth,dc=real,dc=example,dc=com > <= check a_dn_pat: anonymous > <= acl_mask: [4] applying auth(=xd) (stop) > <= acl_mask: [4] mask: auth(=xd) > => slap_access_allowed: auth access granted by auth(=xd) > => access_allowed: auth access granted by auth(=xd) > conn=1 op=1 BIND > dn="uid=plainproxy,cn=plain,cn=auth,dc=real,dc=example,dc=com" > mech=SIMPLE ssf=0 > do_bind: v3 bind: > "uid=plainproxy,cn=plain,cn=auth,dc=real,dc=example,dc=com" to > "uid=plainproxy,cn=plain,cn=auth,dc=real,dc=example,dc=com" > send_ldap_result: conn=1 op=1 p=3 > send_ldap_result: err=0 matched="" text="" > send_ldap_response: msgid=2 tag=97 err=0 > ber_flush2: 22 bytes to sd 33 > 0000: 30 84 00 00 00 10 02 01 02 61 84 00 00 00 07 0a > 0........a...... > 0010: 01 00 04 00 04 00 ...... > tls_write: want=101, written=101 > 0000: 17 03 02 00 60 3e 98 2a 48 b2 d9 ae 12 70 ab > db ....`>.*H....p.. > 0010: 5e 46 c2 ef 7f c3 32 72 d4 41 ef 4d 58 07 d0 50 ^F.... > 2r.A.MX..P > 0020: 53 a2 da 54 69 d7 1c 61 ed a7 ce 53 14 16 46 73 > S..Ti..a...S..Fs > 0030: 91 74 c4 92 9e 35 24 84 ce 8c 6f 18 18 6a 68 0a .t... > 5$...o..jh. > 0040: b0 69 70 75 0d 6a 5d fa 02 38 89 e9 d7 99 c9 99 .ipu.j].. > 8...... > 0050: bb 7b be 62 5d 50 91 2f a9 a2 6e d5 88 47 f8 ed .{.b] > P./..n..G.. > 0060: 5e 3c a7 dd 17 ^<... > ldap_write: want=22, written=22 > 0000: 30 84 00 00 00 10 02 01 02 61 84 00 00 00 07 0a > 0........a...... > 0010: 01 00 04 00 04 00 ...... > daemon: activity on 1 descriptor > daemon: activity on: 33r > daemon: read active on 33 > daemon: epoll: listen=7 active_threads=0 tvp=zero > daemon: epoll: listen=8 active_threads=0 tvp=zero > daemon: epoll: listen=9 active_threads=0 tvp=zero > daemon: epoll: listen=10 active_threads=0 tvp=zero > daemon: epoll: listen=11 active_threads=0 tvp=zero > connection_get(33) > connection_get(33): got connid=1 > connection_read(33): checking for input on id=1 > ber_get_next > tls_read: want=5, got=5 > 0000: 17 03 02 00 c0 ..... > tls_read: want=192, got=192 > 0000: 60 a2 1b 5e 6f 13 18 52 f1 86 c7 b5 ff ae ec bf > `..^o..R........ > 0010: 7e 7f 65 19 30 c0 4a 3a 7d de 76 77 5b bf 0b dc ~.e. > 0.J:}.vw[... > 0020: 22 15 34 f9 5b dd 2d 8f f5 19 e3 25 0d 25 a8 b6 ".4. > [.-....%.%.. > 0030: 07 34 75 a5 08 c6 3e c2 8e 18 58 11 ee 5d 25 7c . > 4u...>...X..]%| > 0040: 00 9b fb 14 a4 9c 7d c1 37 bf 92 f7 ee ef 04 94 ......}. > 7....... > 0050: 81 a8 98 d8 eb 5b 80 0f ce 7d 21 3c 24 fa ba ca ..... > [...}!<$... > 0060: 3f 9a 94 ef dd 7f 47 17 e0 f2 cb 08 04 a5 25 > a3 ?.....G.......%. > 0070: f0 3e 92 a4 75 a2 6e d3 34 1a 82 29 7b 9f b0 07 .>..u.n. > 4..){... > 0080: fd 4e 5f 1e 8f f2 55 33 c5 eb 5f 34 a1 f6 3d > 0a .N_...U3.._4..=. > 0090: c3 e7 4f 4a 77 85 a5 1e 40 f8 d4 60 8e bd 08 > 8c ..OJw...@..`.... > 00a0: 8e 87 7d 93 50 11 da c1 ea b0 e1 74 60 34 ad > b8 ..}.P......t`4.. > 00b0: c0 9a f3 66 44 3c e5 bf 6e b1 4f 4f f8 51 18 > df ...fD<..n.OO.Q.. > ldap_read: want=8, got=8 > 0000: 30 53 02 01 03 63 4e 04 0S...cN. > ldap_read: want=77, got=77 > 0000: 2e 63 6e 3d 70 6c 61 69 6e 2c 63 6e 3d 61 75 > 74 .cn=plain,cn=aut > 0010: 68 2c 64 63 3d 76 65 72 69 6f 2c 64 63 3d 61 6e > h,dc=relay,dc=ex > 0020: 6f 6e 79 6d 69 7a 65 72 2c 64 63 3d 63 6f 6d 0a > ample ,dc=com. > 0030: 01 01 0a 01 00 02 01 01 02 01 00 01 01 00 a3 > 0b ................ > 0040: 04 03 75 69 64 04 04 72 6f 6f 74 30 > 00 ..uid..root0. > ber_get_next: tag 0x30 len 83 contents: > ber_dump: buf=0x2a0d1d0 ptr=0x2a0d1d0 end=0x2a0d223 len=83 > 0000: 02 01 03 63 4e 04 2e 63 6e 3d 70 6c 61 69 6e > 2c ...cN..cn=plain, > 0010: 63 6e 3d 61 75 74 68 2c 64 63 3d 76 65 72 69 6f > cn=auth,dc=relay > 0020: 2c 64 63 3d 61 6e 6f 6e 79 6d 69 7a 65 72 2c > 64 ,dc=example,dc=com > 0030: 63 3d 63 6f 6d 0a 01 01 0a 01 00 02 01 01 02 01 ........... > 0040: 00 01 01 00 a3 0b 04 03 75 69 64 04 04 72 6f > 6f ........uid..roo > 0050: 74 30 00 t0. > op tag 0x63, time 1255629604 > connection_input: conn=1 deferring operation: binding > ber_get_next > tls_read: want=5 error=Resource temporarily unavailable > ldap_read: want=8, got=0 > > daemon: activity on 1 descriptor > daemon: activity on: > daemon: epoll: listen=7 active_threads=0 tvp=zero > daemon: epoll: listen=8 active_threads=0 tvp=zero > daemon: epoll: listen=9 active_threads=0 tvp=zero > daemon: epoll: listen=10 active_threads=0 tvp=zero > daemon: epoll: listen=11 active_threads=0 tvp=zero > Segmentation fault <--------- HERE IT IS > > Again, this was just the initial sync-up. This is not a gdb backtrace from a core file, where slapd has debugging symbols. This information is not really useful. --Quanah -- Quanah Gibson-Mount Principal Software Engineer Zimbra, Inc -------------------- Zimbra :: the leader in open source messaging and collaboration

1 0

Re: (ITS#6331) slapd freezing, not accepting further 'write' operations while 'read' operations are unaffected
by j＠telepaths.org 15 Oct '09

15 Oct '09

We are in luck. I started fresh with my two servers (deleted the data and repopulated). During the INITIAL sync-up on "server1" (receiving data from server2): <= index_entry_add( 225, "krb5PrincipalName=host/seven.relay.example.com(a)RELAY.EXAMPLE.COM ,cn=RELAY.EXAMPLE.COM,cn=gssapi,cn=auth,dc=real,dc=example,dc=com" ) success => entry_encode(0x000000e1): <= entry_encode(0x000000e1): => acl_get: [2] matched => acl_get: [2] attr userPassword => match[dn0]: 0 60 uid=plainproxy,cn=plain,cn=auth,dc=real,dc=example,dc=com => match[dn1]: 0 3 uid => match[dn2]: 4 14 plainproxy => acl_mask: access to entry "uid=plainproxy,cn=plain,cn=auth,dc=real,dc=example,dc=com", attr "userPassword" requested => acl_mask: to value by "", (=0) <= check a_dn_pat: self <= check a_dn_pat: uid=plainchange,cn=plain,cn=auth,dc=real,dc=example,dc=com <= check a_dn_pat: uid=plainmodify,cn=plain,cn=auth,dc=real,dc=example,dc=com <= check a_dn_pat: anonymous <= acl_mask: [4] applying auth(=xd) (stop) <= acl_mask: [4] mask: auth(=xd) => slap_access_allowed: auth access granted by auth(=xd) => access_allowed: auth access granted by auth(=xd) conn=1 op=1 BIND dn="uid=plainproxy,cn=plain,cn=auth,dc=real,dc=example,dc=com" mech=SIMPLE ssf=0 do_bind: v3 bind: "uid=plainproxy,cn=plain,cn=auth,dc=real,dc=example,dc=com" to "uid=plainproxy,cn=plain,cn=auth,dc=real,dc=example,dc=com" send_ldap_result: conn=1 op=1 p=3 send_ldap_result: err=0 matched="" text="" send_ldap_response: msgid=2 tag=97 err=0 ber_flush2: 22 bytes to sd 33 0000: 30 84 00 00 00 10 02 01 02 61 84 00 00 00 07 0a 0........a...... 0010: 01 00 04 00 04 00 ...... tls_write: want=101, written=101 0000: 17 03 02 00 60 3e 98 2a 48 b2 d9 ae 12 70 ab db ....`>.*H....p.. 0010: 5e 46 c2 ef 7f c3 32 72 d4 41 ef 4d 58 07 d0 50 ^F.... 2r.A.MX..P 0020: 53 a2 da 54 69 d7 1c 61 ed a7 ce 53 14 16 46 73 S..Ti..a...S..Fs 0030: 91 74 c4 92 9e 35 24 84 ce 8c 6f 18 18 6a 68 0a .t... 5$...o..jh. 0040: b0 69 70 75 0d 6a 5d fa 02 38 89 e9 d7 99 c9 99 .ipu.j].. 8...... 0050: bb 7b be 62 5d 50 91 2f a9 a2 6e d5 88 47 f8 ed .{.b] P./..n..G.. 0060: 5e 3c a7 dd 17 ^<... ldap_write: want=22, written=22 0000: 30 84 00 00 00 10 02 01 02 61 84 00 00 00 07 0a 0........a...... 0010: 01 00 04 00 04 00 ...... daemon: activity on 1 descriptor daemon: activity on: 33r daemon: read active on 33 daemon: epoll: listen=7 active_threads=0 tvp=zero daemon: epoll: listen=8 active_threads=0 tvp=zero daemon: epoll: listen=9 active_threads=0 tvp=zero daemon: epoll: listen=10 active_threads=0 tvp=zero daemon: epoll: listen=11 active_threads=0 tvp=zero connection_get(33) connection_get(33): got connid=1 connection_read(33): checking for input on id=1 ber_get_next tls_read: want=5, got=5 0000: 17 03 02 00 c0 ..... tls_read: want=192, got=192 0000: 60 a2 1b 5e 6f 13 18 52 f1 86 c7 b5 ff ae ec bf `..^o..R........ 0010: 7e 7f 65 19 30 c0 4a 3a 7d de 76 77 5b bf 0b dc ~.e. 0.J:}.vw[... 0020: 22 15 34 f9 5b dd 2d 8f f5 19 e3 25 0d 25 a8 b6 ".4. [.-....%.%.. 0030: 07 34 75 a5 08 c6 3e c2 8e 18 58 11 ee 5d 25 7c . 4u...>...X..]%| 0040: 00 9b fb 14 a4 9c 7d c1 37 bf 92 f7 ee ef 04 94 ......}. 7....... 0050: 81 a8 98 d8 eb 5b 80 0f ce 7d 21 3c 24 fa ba ca ..... [...}!<$... 0060: 3f 9a 94 ef dd 7f 47 17 e0 f2 cb 08 04 a5 25 a3 ?.....G.......%. 0070: f0 3e 92 a4 75 a2 6e d3 34 1a 82 29 7b 9f b0 07 .>..u.n. 4..){... 0080: fd 4e 5f 1e 8f f2 55 33 c5 eb 5f 34 a1 f6 3d 0a .N_...U3.._4..=. 0090: c3 e7 4f 4a 77 85 a5 1e 40 f8 d4 60 8e bd 08 8c ..OJw...@..`.... 00a0: 8e 87 7d 93 50 11 da c1 ea b0 e1 74 60 34 ad b8 ..}.P......t`4.. 00b0: c0 9a f3 66 44 3c e5 bf 6e b1 4f 4f f8 51 18 df ...fD<..n.OO.Q.. ldap_read: want=8, got=8 0000: 30 53 02 01 03 63 4e 04 0S...cN. ldap_read: want=77, got=77 0000: 2e 63 6e 3d 70 6c 61 69 6e 2c 63 6e 3d 61 75 74 .cn=plain,cn=aut 0010: 68 2c 64 63 3d 76 65 72 69 6f 2c 64 63 3d 61 6e h,dc=relay,dc=ex 0020: 6f 6e 79 6d 69 7a 65 72 2c 64 63 3d 63 6f 6d 0a ample ,dc=com. 0030: 01 01 0a 01 00 02 01 01 02 01 00 01 01 00 a3 0b ................ 0040: 04 03 75 69 64 04 04 72 6f 6f 74 30 00 ..uid..root0. ber_get_next: tag 0x30 len 83 contents: ber_dump: buf=0x2a0d1d0 ptr=0x2a0d1d0 end=0x2a0d223 len=83 0000: 02 01 03 63 4e 04 2e 63 6e 3d 70 6c 61 69 6e 2c ...cN..cn=plain, 0010: 63 6e 3d 61 75 74 68 2c 64 63 3d 76 65 72 69 6f cn=auth,dc=relay 0020: 2c 64 63 3d 61 6e 6f 6e 79 6d 69 7a 65 72 2c 64 ,dc=example,dc=com 0030: 63 3d 63 6f 6d 0a 01 01 0a 01 00 02 01 01 02 01 ........... 0040: 00 01 01 00 a3 0b 04 03 75 69 64 04 04 72 6f 6f ........uid..roo 0050: 74 30 00 t0. op tag 0x63, time 1255629604 connection_input: conn=1 deferring operation: binding ber_get_next tls_read: want=5 error=Resource temporarily unavailable ldap_read: want=8, got=0 daemon: activity on 1 descriptor daemon: activity on: daemon: epoll: listen=7 active_threads=0 tvp=zero daemon: epoll: listen=8 active_threads=0 tvp=zero daemon: epoll: listen=9 active_threads=0 tvp=zero daemon: epoll: listen=10 active_threads=0 tvp=zero daemon: epoll: listen=11 active_threads=0 tvp=zero Segmentation fault <--------- HERE IT IS Again, this was just the initial sync-up. Jeff

1 0

Re: (ITS#6331) slapd freezing, not accepting further 'write' operations while 'read' operations are unaffected
by j＠telepaths.org 15 Oct '09

15 Oct '09

I can - I just wish it wasn't a segfault for no reason. I was not doing any "write testing" at the time of the crash, so I have no idea what will trigger it. Nevertheless, I'll put slapd into trace mode and watch the logs, and will post anything of importance. Thanks again, Jeff On Oct 15, 2009, at 10:49 , Quanah Gibson-Mount wrote: > --On Thursday, October 15, 2009 5:43 PM +0000 j(a)telepaths.org wrote: > >> OK, problems: >> >> slapd just crashed for no apparent reason. >> >> slapd[8131]: segfault at 433e8a00 ip 433e8a00 sp 433e89a8 error 15 >> >> Not good. What version of slapd should I be using to guarantee: >> >> * No deadlocks >> * No replication errors >> * No SEGFAULTS >> >> It just seems like one buggy slapd release after another. Never >> happened with 2.3 releases ..... > > I assume you have core dumps enabled, and built OpenLDAP with > debugging symbols, and can provide the full backtrace of the > generated core? > > --Quanah > > > > -- > > Quanah Gibson-Mount > Principal Software Engineer > Zimbra, Inc > -------------------- > Zimbra :: the leader in open source messaging and collaboration

1 0

hang during ldapmodify?
by Mark Dieterich 15 Oct '09

15 Oct '09

Hi all, I'm not sure if this is a bug or we are doing something wrong. For quite some time now, we have been using ldap to provide group information for our linux/unix desktop machines. I believer there are multiple methods of providing group access, this is the format we are using: # foobar, group, cs.brown.edu dn: cn=foobar,ou=group,dc=cs,dc=brown,dc=edu objectClass: posixGroup objectClass: top cn: ugrad gidNumber: 1200 memberUid: t1 memberUid: t2 memberUid: t3 memberUid: t4 memberUid: t5 . . . Up until recently, this had been working great. We are now experiencing hangs whenever we try to update the records with one particular group. I think the hangs are occur when we try to feed too much data to ldapmodify at a time. For instance, if I have the above group and try to apply the following ldif file: dn: cn=foobar,ou=group,dc=cs,dc=brown,dc=edu changetype: modify replace: memberUid memberUid: t1 memberUid: t2 memberUid: t3 memberUid: t4 memberUid: t5 memberUid: t6 memberUid: t7 memberUid: t8 memberUid: t9 . . . memberUid: t2477 memberUid: t2478 memberUid: t2479 The update simply hangs. Tossing a "-d 65535" shows that the process is sitting in loop spitting out messages similar to: ldap_int_select ldap_result ld 0x1e72bf0 msgid 5 wait4msg ld 0x1e72bf0 msgid 5 (timeout 100000 usec) wait4msg continue ld 0x1e72bf0 msgid 5 all 1 ** ld 0x1e72bf0 Connections: * host: ldapmaster.cs.brown.edu port: 6360 (default) refcnt: 2 status: Connected last used: Thu Oct 15 10:27:45 2009 ** ld 0x1e72bf0 Outstanding Requests: * msgid 5, origid 5, status InProgress outstanding referrals 0, parent count 0 ld 0x1e72bf0 request count 1 (abandoned 0) ** ld 0x1e72bf0 Response Queue: Empty ld 0x1e72bf0 response count 0 ldap_chkResponseList ld 0x1e72bf0 msgid 5 all 1 ldap_chkResponseList returns ld 0x1e72bf0 NULL ldap_int_select Hopefully, this means something more to someone on this list than it does to me;) Interestingly, if I drop the last entry and change the ldif file to be: dn: cn=foobar,ou=group,dc=cs,dc=brown,dc=edu changetype: modify replace: memberUid memberUid: t1 memberUid: t2 memberUid: t3 memberUid: t4 memberUid: t5 memberUid: t6 memberUid: t7 memberUid: t8 memberUid: t9 . . . memberUid: t2476 memberUid: t2477 memberUid: t2478 Then the update proceeds. However, if I change the last entry to read: memberUid: t2478000 Then it hangs again. Whereas with the last entry of memberUid: t247800 it updates just fine. This smells of some buffer filling or something else similar. We are running with debian's lenny version of openldap, version 2.4.11-1 (not sure what's different about the "-1" version). Other details which may be pertinent: - we are running back_bdb - syncprov - GSSAPI authentication I have not tried setting up a test server running 2.4.16/19, but did spend time looking through the chnage logs and bug system and didn't see anything that appeared to apply. However, I certainly could have missed something. Any help would be most appreciated, as we currently have one group which we are no longer able to add any entries to. Thanks! Mark

2 1

Re: (ITS#6331) slapd freezing, not accepting further 'write' operations while 'read' operations are unaffected
by quanah＠zimbra.com 15 Oct '09

15 Oct '09

--On Thursday, October 15, 2009 5:43 PM +0000 j(a)telepaths.org wrote: > OK, problems: > > slapd just crashed for no apparent reason. > > slapd[8131]: segfault at 433e8a00 ip 433e8a00 sp 433e89a8 error 15 > > Not good. What version of slapd should I be using to guarantee: > > * No deadlocks > * No replication errors > * No SEGFAULTS > > It just seems like one buggy slapd release after another. Never > happened with 2.3 releases ..... I assume you have core dumps enabled, and built OpenLDAP with debugging symbols, and can provide the full backtrace of the generated core? --Quanah -- Quanah Gibson-Mount Principal Software Engineer Zimbra, Inc -------------------- Zimbra :: the leader in open source messaging and collaboration

1 0

Re: (ITS#6331) slapd freezing, not accepting further 'write' operations while 'read' operations are unaffected
by j＠telepaths.org 15 Oct '09

15 Oct '09

OK, problems: slapd just crashed for no apparent reason. slapd[8131]: segfault at 433e8a00 ip 433e8a00 sp 433e89a8 error 15 Not good. What version of slapd should I be using to guarantee: * No deadlocks * No replication errors * No SEGFAULTS It just seems like one buggy slapd release after another. Never happened with 2.3 releases ..... Jeff

1 0

Re: (ITS#6331) slapd freezing, not accepting further 'write' operations while 'read' operations are unaffected
by j＠telepaths.org 15 Oct '09

15 Oct '09

My apologies On Oct 15, 2009, at 10:26 , Quanah Gibson-Mount wrote: > --On Thursday, October 15, 2009 10:19 AM -0700 Jeff Doyle <j(a)telepaths.org > > wrote: > >> Thank you Gibson, my checkpoints (both definitions) have not changed >> since you last asked, but the fact that it can help with shutdown >> times >> is a very useful tip, thanks! >> >> Jeff > > Just to note, my first name is "Quanah", not "Gibson". "Gibson- > Mount" is my last name. > > Which is why I sign my emails thusly: > > --Quanah > > -- > > Quanah Gibson-Mount > Principal Software Engineer > Zimbra, Inc > -------------------- > Zimbra :: the leader in open source messaging and collaboration

1 0

Re: (ITS#6331) slapd freezing, not accepting further 'write' operations while 'read' operations are unaffected
by quanah＠zimbra.com 15 Oct '09

15 Oct '09

--On Thursday, October 15, 2009 10:19 AM -0700 Jeff Doyle <j(a)telepaths.org> wrote: > Thank you Gibson, my checkpoints (both definitions) have not changed > since you last asked, but the fact that it can help with shutdown times > is a very useful tip, thanks! > > Jeff Just to note, my first name is "Quanah", not "Gibson". "Gibson-Mount" is my last name. Which is why I sign my emails thusly: --Quanah -- Quanah Gibson-Mount Principal Software Engineer Zimbra, Inc -------------------- Zimbra :: the leader in open source messaging and collaboration

1 0

Re: (ITS#6331) slapd freezing, not accepting further 'write' operations while 'read' operations are unaffected
by j＠telepaths.org 15 Oct '09

15 Oct '09

Thank you Gibson, my checkpoints (both definitions) have not changed since you last asked, but the fact that it can help with shutdown times is a very useful tip, thanks! Jeff

1 0

Re: (ITS#6331) slapd freezing, not accepting further 'write' operations while 'read' operations are unaffected
by quanah＠zimbra.com 15 Oct '09

15 Oct '09

--On Thursday, October 15, 2009 4:50 PM +0000 j(a)telepaths.org wrote: > OK, I believe the dead-lock issue is solved, however OCCASIONALLY when > attempting a restart or stop of the slapd process, it throws an error > saying 'slapd stop failed', however the slapd process does quit as > expected, so its a "false failure". > > The one possibility for the reason this is happening, aside from > blaming slapd, is that my two test boxes are VMs ... so I kind of > expect sluggish responses, especially on a VMware server as busy as > ours. I will note that our production LDAP servers are NOT VMs and > will never be ;-) > > I believe you were correct, Pierangelo. I will post my findings over > the next fews days to keep everyone in the loop. Probably the issue. Make sure you have checkpoints defined for all bdb/hdb databases as well, which will help with shutdown times. --Quanah -- Quanah Gibson-Mount Principal Software Engineer Zimbra, Inc -------------------- Zimbra :: the leader in open source messaging and collaboration

1 0

Re: (ITS#6331) slapd freezing, not accepting further 'write' operations while 'read' operations are unaffected
by j＠telepaths.org 15 Oct '09

15 Oct '09

OK, I believe the dead-lock issue is solved, however OCCASIONALLY when attempting a restart or stop of the slapd process, it throws an error saying 'slapd stop failed', however the slapd process does quit as expected, so its a "false failure". The one possibility for the reason this is happening, aside from blaming slapd, is that my two test boxes are VMs ... so I kind of expect sluggish responses, especially on a VMware server as busy as ours. I will note that our production LDAP servers are NOT VMs and will never be ;-) I believe you were correct, Pierangelo. I will post my findings over the next fews days to keep everyone in the loop. Thanks, Jeff

1 0

Re: (ITS#6330) slapd memory leak
by whm＠stanford.edu 15 Oct '09

15 Oct '09

> Apparently, accessing that URL requires a valid account. In any case, you > should run slapd under valgrind for a while, in order to locate the leak. Sorry about that. The URL should be accessible now. I will start the valgrind work a bit later this morning on the left coast. Bill -- Bill MacAllister, System Software Programmer Unix Systems Group, Stanford University

1 0

Re: (ITS#6329) memberof overlay doesn't update entryCSN
by msmith＠cbnco.com 14 Oct '09

14 Oct '09

On Wed, 14 Oct 2009, masarati(a)aero.polimi.it wrote: > Should be fixed in HEAD (one-line fix, see overlays/memberof.c 1.25 -> 1.26). > > Please test. Thanks, p. Thanks - I applied this to openldap 2.4.19 and the entryCSNs now match on all nodes, as long as they're all up when a group is modified. I still get something strange if one node is down: if I remove a user from a group on the working node, then bring the failed node back, the failed node doesn't sync the modified group and user objects. For example, if I remove testuser3 from testgroup2 while node 2 is down, then bring node 2 back, I get this on node 1: dn: uid=testuser3,ou=people,dc=dom memberOf: cn=testgroup1,ou=group,dc=dom entryCSN: 20091015040419.455869Z#000000#001#000000 dn: cn=testgroup2,ou=group,dc=dom member: uid=testuser2,ou=people,dc=dom entryCSN: 20091015040419.455869Z#000000#001#000000 And this on node 2: dn: uid=testuser3,ou=people,dc=dom memberOf: cn=testgroup2,ou=group,dc=dom memberOf: cn=testgroup1,ou=group,dc=dom entryCSN: 20091015033445.046089Z#000000#002#000000 dn: cn=testgroup2,ou=group,dc=dom member: uid=testuser2,ou=people,dc=dom member: uid=testuser3,ou=people,dc=dom entryCSN: 20091015033233.354687Z#000000#001#000000 I don't have this problem with changes that don't involve member/memberOf attributes. For example, I can add a description attr to the group object while node 2 is down, and when I bring it back up, it picks up the change. On both nodes I've got the memberof and syncprov overlays turned on, in that order. dn: olcOverlay={0}memberof,olcDatabase={1}hdb,cn=config objectClass: olcOverlayConfig olcOverlay: {0}memberof dn: olcOverlay={1}syncprov,olcDatabase={1}hdb,cn=config objectClass: olcSyncProvConfig olcSpCheckpoint: 100 10 olcSpSessionlog: 1000 olcOverlay: {1}syncprov Thanks, Mike

1 0

Re: (ITS#6320)
by j＠telepaths.org 14 Oct '09

14 Oct '09

OK, for anyone following this thread, please refer to ITS #6331, as I believe this issue may not be a "replication issue" at all, rather a deadlock PREVENTING replication. Might as well close this ticket, thanks for everyone's help. Jeff

1 0

Re: (ITS#6331) slapd freezing, not accepting further 'write' operations while 'read' operations are unaffected
by j＠telepaths.org 14 Oct '09

14 Oct '09

OK, I was able to compile a set of Debian packages for version 2.4.19 using the source obtained from openldap.org. I have set up a mirror of our production environment (less a few servers). I have two provider servers in mirrormode, and configured for multimaster syncrepl. So far, no locks, no replication issues, everything seems peachy. Though, in real-life, the problem has a tendency to reappear sometimes a week after a slapd-restart. We'll see what happens. I will continue to update this ticket, detailing any further developments. Thanks again Pierangelo and Gibson, I appreciate your help. Jeff

1 0

Re: (ITS#6331) slapd freezing, not accepting further 'write' operations while 'read' operations are unaffected
by j＠telepaths.org 14 Oct '09

14 Oct '09

Thanks for responding, Pierangelo. I am asking (begging) my chief engineer to entertain this idea. Will report back ASAP. Thanks, Jeff On Oct 14, 2009, at 11:52 AM, masarati(a)aero.polimi.it wrote: >> Version: 2.4.17 > >> Occasionally, I will find one of my servers (running Debian/Lenny >> with >> back-ported slapd version 2.4.17) in a state where the following >> occurs: >> >> * Write operations will 'freeze' - leaving the requester at a frozen >> prompt or >> frozen LDAP-client of some kind (from wherever the write-operation >> originated). >> * slapd refuses to 'stop', even though it indicates that its >> waiting for >> "0" >> processes to complete. >> * Logs do not indicate a segfault nor any poorly terminated >> processes. >> * Read operations on same server continue to function normally. >> Any data >> that >> existed before the "freeze" is returned as it should be. > > You probably hit ITS#6276, which was fixed in 2.4.18. Can you > upgrade and > test? > > p. >

1 0

Re: (ITS#6331) slapd freezing, not accepting further 'write' operations while 'read' operations are unaffected
by masarati＠aero.polimi.it 14 Oct '09

14 Oct '09

> Version: 2.4.17 > Occasionally, I will find one of my servers (running Debian/Lenny with > back-ported slapd version 2.4.17) in a state where the following occurs: > > * Write operations will 'freeze' - leaving the requester at a frozen > prompt or > frozen LDAP-client of some kind (from wherever the write-operation > originated). > * slapd refuses to 'stop', even though it indicates that its waiting for > "0" > processes to complete. > * Logs do not indicate a segfault nor any poorly terminated processes. > * Read operations on same server continue to function normally. Any data > that > existed before the "freeze" is returned as it should be. You probably hit ITS#6276, which was fixed in 2.4.18. Can you upgrade and test? p.

1 0

Re: (ITS#6331) slapd freezing, not accepting further 'write' operations while 'read' operations are unaffected
by j＠telepaths.org 14 Oct '09

14 Oct '09

Quanah, Thanks for responding. Here are the answers to your questions: ldd /usr/sbin/slapd linux-vdso.so.1 => (0x00007fff4f1ff000) libldap_r-2.4.so.2 => /usr/lib/libldap_r-2.4.so.2 (0x00007f2646c5e000) liblber-2.4.so.2 => /usr/lib/liblber-2.4.so.2 (0x00007f2646a4f000) libdb-4.6.so => /usr/lib/libdb-4.6.so (0x00007f2646705000) libodbc.so.1 => /usr/lib/libodbc.so.1 (0x00007f26464a9000) libslp.so.1 => /usr/lib/libslp.so.1 (0x00007f2646297000) libsasl2.so.2 => /usr/lib/libsasl2.so.2 (0x00007f264607d000) libgnutls.so.26 => /usr/lib/libgnutls.so.26 (0x00007f2645dcb000) libcrypt.so.1 => /lib/libcrypt.so.1 (0x00007f2645b93000) libresolv.so.2 => /lib/libresolv.so.2 (0x00007f264597f000) libltdl.so.3 => /usr/lib/libltdl.so.3 (0x00007f2645778000) libwrap.so.0 => /lib/libwrap.so.0 (0x00007f264556f000) libpthread.so.0 => /lib/libpthread.so.0 (0x00007f2645353000) libc.so.6 => /lib/libc.so.6 (0x00007f2645000000) libnsl.so.1 => /lib/libnsl.so.1 (0x00007f2644de8000) libdl.so.2 => /lib/libdl.so.2 (0x00007f2644be4000) libtasn1.so.3 => /usr/lib/libtasn1.so.3 (0x00007f26449d4000) libgpg-error.so.0 => /usr/lib/libgpg-error.so.0 (0x00007f2646fb5000) libz.so.1 => /usr/lib/libz.so.1 (0x00007f26447bd000) libgcrypt.so.11 => /usr/lib/libgcrypt.so.11 (0x00007f2644556000) /lib64/ld-linux-x86-64.so.2 (0x00007f2646ea9000) From slapd.conf: tool-threads 4 # this has varied between 1 and 4 syncprov-checkpoint 1 5 # we've tried using the default settings, very lax settings, etc - never made a difference. checkpoint 10 1 # checkpointing for Berkeley And the rest of the Berkeley settings in our DIT suffix area: database hdb cachesize 10000 idlcachesize 30000 checksum cachefree 20 dncachesize 100000 dbconfig set_cachesize 1 0 2 dbconfig set_lg_max 10485760 dbconfig set_flags db_log_autoremove dbconfig set_lg_bsize 2097152 dbconfig set_lk_max_objects 5500 dbconfig set_lk_max_locks 5500 dbconfig set_lk_max_lockers 5500 The version of BDB is as fully-patched as Debian keeps up with it. We (as a company) stay on top of updates, while Debian only tends to fix security bugs and pretty much will ignore feature issues and lack- luster functionality in their packages. They do this religiously, which is shameful. Thanks again, Jeff

1 0

Re: (ITS#6329) memberof overlay doesn't update entryCSN
by masarati＠aero.polimi.it 14 Oct '09

14 Oct '09

> It looks like the memberof overlay doesn't update a user object's entryCSN > when > a group object is changed. I believe this causes trouble with syncrepl, at > least > in a multi-master configuration: if one node is down when the group object > is > changed, it won't know it needs to update the user object when it comes > back. Should be fixed in HEAD (one-line fix, see overlays/memberof.c 1.25 -> 1.26). Please test. Thanks, p.

1 0

Re: (ITS#6330) slapd memory leak
by masarati＠aero.polimi.it 14 Oct '09

14 Oct '09

> We have observed what we believe to be a memory leak in OpenLDAP 2.4.18 in > testing > while dynlist support. We have a script that randomly expands the member > lists > > of groups defined using dynlist. Running this script for a period of > about 24 > hours forces the slapd process to swap. > > It is not clear at all that dynlist is the problem because we were not > able to > see the problem with our test script until we surrounded each query with a > bind/unbind. (At least we didn't wait long enough to see it.) All > queries > perform GSSAPI binds to the directory. The problem is unaffected by using > either the MIT or Heimdal GSSAPI libraries. > > Our build of OpenLDAP 2.4.18 follows the debian configuration with the > exceptions: > * Patch for ITS6287 > * Patch for ITS6308 > * Patch to the index slots > * disable support for tcp_wrappers and disable rlookups > > The details of software versions, build options, slapd configuration, > scripts, > db_stat output and testing procedures are at > http://www.stanford.edu/~whm/files/slapd/readme.html. Apparently, accessing that URL requires a valid account. In any case, you should run slapd under valgrind for a while, in order to locate the leak. p.

1 0

Re: (ITS#6331) slapd freezing, not accepting further 'write' operations while 'read' operations are unaffected
by quanah＠zimbra.com 14 Oct '09

14 Oct '09

--On Wednesday, October 14, 2009 1:11 AM +0000 j(a)telepaths.org wrote: > Full_Name: Jeff Doyle > Version: 2.4.17 > OS: Debian/Lenny > URL: ftp://ftp.openldap.org/incoming/ > Submission from: (NULL) (130.94.106.251) > > > Greetings, > > Occasionally, I will find one of my servers (running Debian/Lenny with > back-ported slapd version 2.4.17) in a state where the following occurs: > > * Write operations will 'freeze' - leaving the requester at a frozen > prompt or frozen LDAP-client of some kind (from wherever the > write-operation originated). * slapd refuses to 'stop', even though it > indicates that its waiting for "0" processes to complete. > * Logs do not indicate a segfault nor any poorly terminated processes. > * Read operations on same server continue to function normally. Any > data that existed before the "freeze" is returned as it should be. > > Modules used: > > * accesslog > * back_hdb > * back_monitor > * back_relay > * back_rwm > * syncprov > > Servers are all fairly new, and reasonably beefy for their purposes: > > * 6GB RAM > * 2+ GHz CPU, all QuadCore Xeon and all running amd64 kernel (current > with Lenny) > * Plenty of Disk Space (gigs and gigs) > * Servers are SLEEPING (0.00 avg load) > > slapd is making use of 'tool-threads' with a value of '4' - however > changing this value has had no effect - Just a side note. tool threads only affects offline operations (slapadd). How many threads do you have configured? What version of BDB is slapd linked against? Is the bdb version fully patched? What is your checkpoint directive set to in both the accesslog and hdb databases? --Quanah -- Quanah Gibson-Mount Principal Software Engineer Zimbra, Inc -------------------- Zimbra :: the leader in open source messaging and collaboration

1 0

(ITS#6332)
by l.mierzwa＠gmail.com 14 Oct '09

14 Oct '09

--0016e6d7df78582bd90475e3ecd0 Content-Type: text/plain; charset=ISO-8859-1 > but when I add member attribute I mean: when I add it to ldif, so it looks like: dn: cn=shell,ou=access,<basedn> changetype: modify replace: objectClass objectClass: groupOfNames objectClass: top - replace: cn cn: shell - replace: description description: blablabla - replace: member member: uid=user1[...] member: uid=user2[...] member: uid=user3[...] --0016e6d7df78582bd90475e3ecd0 Content-Type: text/html; charset=ISO-8859-1 > but when I add member attribute<br><br>I mean: when I add it to ldif, so it looks like:<br><br>dn: cn=shell,ou=access,<basedn><br>changetype: modify<br>replace: objectClass<br>objectClass: groupOfNames<br>objectClass: top<br> -<br>replace: cn<br>cn: shell<br>-<br>replace: description<br>description: blablabla<br>-<br>replace: member<br>member: uid=user1[...]<br>member: uid=user2[...]<br>member: uid=user3[...]<br> --0016e6d7df78582bd90475e3ecd0--

1 0

(ITS#6332) replication issues
by lmierzwa＠gmail.com 14 Oct '09

14 Oct '09

Full_Name: £ukasz Mierzwa Version: 2.4.18/19 OS: Linux / Freebsd URL: ftp://ftp.openldap.org/incoming/ Submission from: (NULL) (85.232.239.146) I'm using syncrepl with this config on master overlay syncprov syncprov-checkpoint 100 10 syncprov-sessionlog 100 and on slaves syncrepl rid=100 provider=ldap://ldap-master type=refreshOnly interval=00:00:01:00 retry="60 +" searchbase="<base>" filter="(objectClass=*)" scope=sub schemachecking=off bindmethod=sasl saslmech=DIGEST-MD5 authcid="<replicator login>" credentials="<pass>" starttls=yes I modify data on master using ldapmodify with this ldif: dn: cn=shell,ou=access,<basedn> changetype: modify replace: objectClass objectClass: groupOfNames objectClass: top - replace: cn cn: shell - replace: description description: blablabla note that only description is getting new value, cn and objectClass are being set to the same value as before modification and everything works, slaves are getting changed data, but when I add member attribute (which also is set to the same value as it was) slaves are not seeing any change, logs on slaves are only showing "do_syncrep2: rid=100 LDAP_RES_SEARCH_RESULT" Master is ubuntu 9.04 with openldap 2.4.15 + I tested 2.4.18 from 9.10, same result. Slaves are ubuntu 9.04 (2.4.15 and 2.4.18) and Freebsd 7.0 (2.4.19)

1 0

Re: (ITS#6251) GnuTLS cipher suite failure
by kent＠cpttm.org.mo 13 Oct '09

13 Oct '09

Hi, I am having this issue, but setting the cipher suite to +RSA:+AES-256-CBC:+SHA1 doesn't fix the problem. slapd.conf: TLSCipherSuite +RSA:+AES-256-CBC:+SHA1 TLSCACertificateFile /etc/ldap/ssl/cacert.pem TLSCertificateFile /etc/ldap/ssl/cert.pem TLSCertificateKeyFile /etc/ldap/ssl/key.pem Debug log of slapd: tchingRuleUse: ... supportedFeatures $ supportedApplicationContext ) ) TLS: could not set cipher list +RSA:+AES-256-CBC:+SHA1. main: TLS init def ctx failed: -1 slapd destroy: freeing system resources. slapd stopped. Output of "gnutls-cli -l": ... TLS_RSA_EXPORT_ARCFOUR_40_MD5 0x00, 0x03 SSL 3.0 TLS_RSA_ARCFOUR_SHA1 0x00, 0x05 SSL 3.0 TLS_RSA_ARCFOUR_MD5 0x00, 0x04 SSL 3.0 TLS_RSA_3DES_EDE_CBC_SHA1 0x00, 0x0a SSL 3.0 TLS_RSA_AES_128_CBC_SHA1 0x00, 0x2f SSL 3.0 TLS_RSA_AES_256_CBC_SHA1 0x00, 0x35 SSL 3.0 Certificate types: X.509, OPENPGP Protocols: SSL 3.0, TLS 1.0, TLS 1.1, TLS 1.2 Ciphers: AES 256 CBC, AES 128 CBC, 3DES 168 CBC, DES CBC, ARCFOUR 128, ARCFOUR 4 0, RC2 40, NULL MACs: SHA, MD5, SHA256, SHA384, SHA512, MD2, RIPEMD160, NULL Key exchange algorithms: Anon DH, RSA, RSA EXPORT, DHE RSA, DHE DSS, SRP DSS, SR P RSA, SRP, PSK, DHE PSK Compression: LZO, DEFLATE, NULL -- Kent Tong SME accounting software package for just MOP30. See http://www.cpttm.org.mo/index_c.php?pg=cpttm/department/is/ispu/accsys/inde… for more.

1 0

(ITS#6331) slapd freezing, not accepting further 'write' operations while 'read' operations are unaffected
by j＠telepaths.org 13 Oct '09

13 Oct '09

Full_Name: Jeff Doyle Version: 2.4.17 OS: Debian/Lenny URL: ftp://ftp.openldap.org/incoming/ Submission from: (NULL) (130.94.106.251) Greetings, Occasionally, I will find one of my servers (running Debian/Lenny with back-ported slapd version 2.4.17) in a state where the following occurs: * Write operations will 'freeze' - leaving the requester at a frozen prompt or frozen LDAP-client of some kind (from wherever the write-operation originated). * slapd refuses to 'stop', even though it indicates that its waiting for "0" processes to complete. * Logs do not indicate a segfault nor any poorly terminated processes. * Read operations on same server continue to function normally. Any data that existed before the "freeze" is returned as it should be. Modules used: * accesslog * back_hdb * back_monitor * back_relay * back_rwm * syncprov Servers are all fairly new, and reasonably beefy for their purposes: * 6GB RAM * 2+ GHz CPU, all QuadCore Xeon and all running amd64 kernel (current with Lenny) * Plenty of Disk Space (gigs and gigs) * Servers are SLEEPING (0.00 avg load) slapd is making use of 'tool-threads' with a value of '4' - however changing this value has had no effect - Just a side note. Inform me of any further configs and/or information that you need, and I will provide it promptly. Thanks, Jeff

1 0

(ITS#6330) slapd memory leak
by whm＠stanford.edu 13 Oct '09

13 Oct '09

Full_Name: Bill MacAllister Version: 2.4.18 OS: Debian 5.0 URL: http://www.stanford.edu/~whm/files/slapd/readme.html Submission from: (NULL) (75.26.167.150) We have observed what we believe to be a memory leak in OpenLDAP 2.4.18 in testing while dynlist support. We have a script that randomly expands the member lists of groups defined using dynlist. Running this script for a period of about 24 hours forces the slapd process to swap. It is not clear at all that dynlist is the problem because we were not able to see the problem with our test script until we surrounded each query with a bind/unbind. (At least we didn't wait long enough to see it.) All queries perform GSSAPI binds to the directory. The problem is unaffected by using either the MIT or Heimdal GSSAPI libraries. Our build of OpenLDAP 2.4.18 follows the debian configuration with the exceptions: * Patch for ITS6287 * Patch for ITS6308 * Patch to the index slots * disable support for tcp_wrappers and disable rlookups The details of software versions, build options, slapd configuration, scripts, db_stat output and testing procedures are at http://www.stanford.edu/~whm/files/slapd/readme.html.

1 0

(ITS#6329) memberof overlay doesn't update entryCSN
by msmith＠cbnco.com 13 Oct '09

13 Oct '09

Full_Name: Michael Smith Version: 2.4.18-55.1 OS: SLES11 (SUSE) URL: Submission from: (NULL) (207.164.182.8) Hi, It looks like the memberof overlay doesn't update a user object's entryCSN when a group object is changed. I believe this causes trouble with syncrepl, at least in a multi-master configuration: if one node is down when the group object is changed, it won't know it needs to update the user object when it comes back. I'm a little confused because while the entryCSNs don't change on the server where the group is updated, they do change on the other servers in the replication group. For example, if I add a user to a group on node 2, the user's entryCSN on node 2 might be "20091008032402.932100Z#000000#002#000000": old timestamp, correct server ID. On node 1 the entryCSN might be "20091008032142.915412Z#000000#002#000000": current timestamp, correct server ID. I'm using syncrepl with refreshAndPersist and syncprov. The memberof overlay is using its default configuration. In the stacking order, memberof comes before syncprov, but it behaved the same way in both orders. All nodes are configured with memberof and syncprov. The servers' clocks are in sync (NTP). There was a thread on openldap-software here: http://thread.gmane.org/gmane.network.openldap.general/45790/focus=45808 This is what my configuration looks like on node 1: dn: cn=config # ... olcServerID: 1 dn: olcDatabase={1}hdb,cn=config # ... olcAccess: {0}to attrs=userPassword by self write by dn.subtree="ou=service,dc=dom" read by * auth olcAccess: {1}to attrs=shadowLastChange by self write by * read olcAccess: {2}to attrs=userPKCS12 by self read by * none olcAccess: {3}to * by * read olcDbIndex: objectclass eq olcDbIndex: entryUUID eq olcDbIndex: entryCSN eq olcLimits: {0}dn.subtree="ou=service,dc=dom" time.soft=unlimited time.hard=unlimited size.soft=unlimited size.hard=unlimited olcSyncrepl: {0}rid=002 provider=ldap://ldap2.dom binddn="cn=repluser,ou=service,dc=dom" bindmethod=simple credentials=xxxxxx searchbase="dc=dom" attrs="*,+" type=refreshAndPersist schemachecking=off tls_cacert=/etc/openldap/ssl/ca.crt tls_reqcert=demand interval=00:00:05:00 retry="60 +" olcMirrorMode: TRUE dn: olcOverlay={0}memberof,olcDatabase={1}hdb,cn=config objectClass: olcOverlayConfig olcOverlay: {1}memberof dn: olcOverlay={1}syncprov,olcDatabase={1}hdb,cn=config objectClass: olcSyncProvConfig olcSpCheckpoint: 100 10 olcSpSessionlog: 1000 olcOverlay: {0}syncprov Node 2 looks the same, but with olcServerID: 2 and provider=ldap://ldap1.dom. Thanks, Mike

1 0

Re: (ITS#6320)
by j＠telepaths.org 12 Oct '09

12 Oct '09

Just to clear up any confusion: * Issue is not resolved * Waiting for a response from you guys Please advise. Jeff

1 0

Re: (ITS#6328) Configure OpenLDAP with BO
by quanah＠zimbra.com 12 Oct '09

12 Oct '09

--On Monday, October 12, 2009 9:04 AM +0000 hervelam(a)hotmail.com wrote: > Full_Name: HervE > Version: 2.2.29 Usage questions need to go to openldap-software(a)openldap.org or openldap-technical(a)openldap.org. I would note you are using an ancient unsupported release as well. I'd advise moving to something newer. --Quanah -- Quanah Gibson-Mount Principal Software Engineer Zimbra, Inc -------------------- Zimbra :: the leader in open source messaging and collaboration

1 0

(ITS#6328) Configure OpenLDAP with BO
by hervelam＠hotmail.com 12 Oct '09

12 Oct '09

Full_Name: HervE Version: 2.2.29 OS: Windows XP URL: ftp://ftp.openldap.org/incoming/ Submission from: (NULL) (213.41.232.181) I am trying to configure BusinessObjects in order to use OpenLDAP with it. In the LDAP authentification menu in BO, I have to map all the following attributes with the appropriate tags: Mappings of LDAP server attributes Object class: Static Group: Member of static group: Dynamic Group: Dynamic Group Filter: Group description: User object Class: Username: Full name of the user: Email User: User Description: Default LDAP search attributes Default group research attribute: Default user research attribute: Can anyone help me please? Regards, HervE

1 0

Re: (ITS#6320)
by j＠telepaths.org 11 Oct '09

11 Oct '09

OpenLDAP ITS: OK the issue is looking more and more like buggy slapd behavior. I have now narrowed down the issue to an instance where slapd is partially "hung" and will not stop nor restart. This directly correlates to replication breaking because SLAPD is breaking: Oct 11 18:22:08 server1 slapd[10771]: <= bdb_equality_candidates: (uidNumber) not indexed Oct 11 18:22:08 server1 slapd[10771]: <= bdb_equality_candidates: (gidNumber) not indexed Oct 11 18:22:08 server1 slapd[10771]: <= bdb_equality_candidates: (uidNumber) not indexed Oct 11 18:46:41 server1 slapd[10771]: <= bdb_equality_candidates: (uidNumber) not indexed Oct 11 18:48:37 server1 slapd[10771]: <= bdb_equality_candidates: (uidNumber) not indexed Oct 11 18:49:05 server1 slapd[10771]: daemon: shutdown requested and initiated. Oct 11 18:49:05 server1 slapd[10771]: slapd shutdown: waiting for 0 operations/tasks to finish As you can see, the exact time when this occurs doesn't bring anything interesting to the logs. You can see the repeated string of index warnings (not an issue, just haven't indexed this attribute yet) followed by my attempt to restart slapd when I receive a notification indicating there is a replication discrepancy. I have grepped through all of my logs (dmesg, debug, syslog) for anything related to slapd. What you see above is the more interesting of the hits returned. PLEASE help -- the issue is getting more serious now, and by the evidence I've presented, is looking more and more out of my control. You've seen my config - can anyone think of why this would happen? It seems vaguely like a locking issue .... Thanks Jeff

1 0

Re: (ITS#6320)
by j＠telepaths.org 11 Oct '09

11 Oct '09

> FYI .... > > Before going to sleep last night, I left a persistent connection > open to an LDAP server: > > > SyncInfo Received > > SyncInfo Received > > SyncInfo Received > > SyncInfo Received > ldap_result: Can't contact LDAP server (-1) <-- > sometime during the night, the connection breaks. > This turned out to be the Kerberos credentials acquired for this test command had expired. Last night, I ran the same command via Simple Bind before going to sleep. The connection is still alive several hours later. This disproves the theory of firewall-induced timeouts for replication that is achieved outside the current local zone. Jeff

1 0

Re: (ITS#6320)
by j＠telepaths.org 10 Oct '09

10 Oct '09

FYI .... Before going to sleep last night, I left a persistent connection open to an LDAP server: SyncInfo Received SyncInfo Received SyncInfo Received SyncInfo Received ldap_result: Can't contact LDAP server (-1) <-- sometime during the night, the connection breaks.

1 0

Re: (ITS#6320)
by j＠telepaths.org 09 Oct '09

09 Oct '09

OK, since my last correspondence, things seemed to be going OK. All changes had been replicated perfectly until last night, I deleted one record, and it only deleted on 4 of 6 of my servers. I removed it manually from one of the other two 'offending' servers. The last one then deleted the record on its own. So it seems as though SyncRepl is highly flaky. I looked into the firewall timeout issue and determined that it is not the cause (if it were, this issue would be happening every 30 minutes (default firewall timeout for the LDAP service)). We're still using the accesslog DB for write-transactions. Jeff

1 0

Re: (ITS#6325) test054: test failed - producer and consumer databases differ
by michael＠stroeder.com 08 Oct '09

08 Oct '09

A syncrepl-related error also happened in test050. I also can not reproduce easily. test failed - server 1 and server 4 configs differ >>>>> ./scripts/test050-syncrepl-multimaster failed for bdb (exit 1) make[2]: *** [bdb-mod] Error 1 make[2]: Leaving directory `/usr/src/michael/openldap/HEAD/openldap/tests' make[1]: *** [test] Error 2 make[1]: Leaving directory `/usr/src/michael/openldap/HEAD/openldap/tests' make: *** [test] Error 2

1 0

Re: (ITS#6310) Slapd with pcache crashes under load
by masarati＠aero.polimi.it 07 Oct '09

07 Oct '09

> masarati(a)aero.polimi.it wrote: >> I didn't make any progress in debugging your issue, as I can't reproduce >> your issue using your configuration. What you see, namely some >> cacheability/answerability messages without a request could be related >> to >> pcache intercepting some internal operation, e.g. related to ACL >> checking? >> This could be intended or a mistake, but I can't tell so far. >> >> As a side note, your configuration seems to be triggering some issues in >> back-ldap. In detail, you set a rootdn, which is probably needed by >> slapo-pcache, but no rootpw. This is sort of confusing back-ldap. I'm >> investigating this a little bit further, although it might not be >> related >> to your issue. >> >> p. > Yes, I have set up rootdn because pcache overlay wanted it. I will set > also some rootpw to see if this makes difference. mmmh, sounds like a red herring, sorry for the noise. p.

1 0

Re: (ITS#6310) Slapd with pcache crashes under load
by karavelov＠spnet.net 07 Oct '09

07 Oct '09

masarati(a)aero.polimi.it wrote: > I didn't make any progress in debugging your issue, as I can't reproduce > your issue using your configuration. What you see, namely some > cacheability/answerability messages without a request could be related to > pcache intercepting some internal operation, e.g. related to ACL checking? > This could be intended or a mistake, but I can't tell so far. > > As a side note, your configuration seems to be triggering some issues in > back-ldap. In detail, you set a rootdn, which is probably needed by > slapo-pcache, but no rootpw. This is sort of confusing back-ldap. I'm > investigating this a little bit further, although it might not be related > to your issue. > > p. Yes, I have set up rootdn because pcache overlay wanted it. I will set also some rootpw to see if this makes difference. Luben

1 0

Re: (ITS#6310) Slapd with pcache crashes under load
by masarati＠aero.polimi.it 07 Oct '09

07 Oct '09

I didn't make any progress in debugging your issue, as I can't reproduce your issue using your configuration. What you see, namely some cacheability/answerability messages without a request could be related to pcache intercepting some internal operation, e.g. related to ACL checking? This could be intended or a mistake, but I can't tell so far. As a side note, your configuration seems to be triggering some issues in back-ldap. In detail, you set a rootdn, which is probably needed by slapo-pcache, but no rootpw. This is sort of confusing back-ldap. I'm investigating this a little bit further, although it might not be related to your issue. p.

1 0

(ITS#6326) back-ldap may leak when building entry with undef objectClass
by masarati＠aero.polimi.it 07 Oct '09

07 Oct '09

Full_Name: Pierangelo Masarati Version: HEAD/re24 OS: irrelevant URL: ftp://ftp.openldap.org/incoming/ Submission from: (NULL) (93.149.38.251) Submitted by: ando The name of the undef objectClass is copied, but never used, and the pointer is lost. A fix is coming... p.

1 0

Re: (ITS#6324) slapd -d ? emits incorrect value for LDAP_DEBUG_ANY on x86_64
by jwm＠horde.net 07 Oct '09

07 Oct '09

On Wed, Oct 07, 2009 at 08:02:53PM +0200, masarati(a)aero.polimi.it wrote: > Should be fixed now. Thanks. john -- John Morrissey _o /\ ---- __o jwm(a)horde.net _-< \_ / \ ---- < \, www.horde.net/ __(_)/_(_)________/ \_______(_) /_(_)__

1 0

Re: (ITS#6324) slapd -d ? emits incorrect value for LDAP_DEBUG_ANY on x86_64
by masarati＠aero.polimi.it 07 Oct '09

07 Oct '09

>> Please check the fix in HEAD. I can't check right now on x86_64, but >> I'll >> probably do it tomorrow. Apparently, I didn't break anything on 32 bit. > > 'slapd -d ?' still lists the 64-bit value for LDAP_DEBUG_ANY on x86_64: > > -- > Installed log subsystems: > > Any (18446744073709551615) > [...] > -- > > As I mentioned, this is due to the unsigned long format specifier (%lu) in > loglevel_print(). Changing the format specifier to %u emits the correct > value (4294967295) on this architecture. > > With your fix, slapd accepts the numeric value 4294967295 for > LDAP_DEBUG_ANY on x86_64. Should be fixed now. Also, please note the slightly changed behavior: the decimal *and* the hexadecimal value are both printed. This can be reversed if anyone fears it breaks anything. Thanks, p.

1 0

Re: (ITS#6310) Slapd with pcache crashes under load
by karavelov＠spnet.net 07 Oct '09

07 Oct '09

masarati(a)aero.polimi.it wrote: > No. Some overlay along the lines apparently mucks with e_private in the > entry that back-ldap is sending. It's probably slapo-pcache. I need to > debug this. You say it happens seldom. Can you recognize anything > special in the operation that triggers the assertion failure? I mean: > either in terms of special data, or in terms of special state of the > cache? This could help narrow down some means to reproduce the issue. > > Thanks, p. I have enabled full debugging info in the logs. So here are the last 1000 lines from the last abort: http://purgatory.spnet.net/~karavelov/abort/slapd.log.9004 I looked closely the generated core. Here is the gdb session: http://purgatory.spnet.net/~karavelov/abort/gdb.9004 Tell me if I could check some other variables that could help you identify the problem. Luben

1 0

Re: (ITS#6324) slapd -d ? emits incorrect value for LDAP_DEBUG_ANY on x86_64
by masarati＠aero.polimi.it 07 Oct '09

07 Oct '09

jwm(a)horde.net wrote: > On Tue, Oct 06, 2009 at 10:04:45PM +0200, masarati(a)aero.polimi.it wrote: >>> The 32-bit value 4294967295 for LDAP_DEBUG_ANY is also rejected. >>> lutil_atoix() declares i as type long and tries to check for overflow(?) >>> with this cast: >>> >>> if ( (long)(int)i != i ) { >>> >>> which always fails in this case on x86_64. lutil_atoux() might be the more >>> appropriate choice here. >>> >>> str2loglevel() seems to behave correctly by virtue of verb_to_mask() >>> returning an index into loglevel_ops, but I haven't checked extensively. >>> loglevel_init(), however, does specify a hardcoded -1 for the Any level >>> instead of LDAP_DEBUG_ANY. >> Please check the fix in HEAD. I can't check right now on x86_64, but I'll >> probably do it tomorrow. Apparently, I didn't break anything on 32 bit. > > 'slapd -d ?' still lists the 64-bit value for LDAP_DEBUG_ANY on x86_64: > > -- > Installed log subsystems: > > Any (18446744073709551615) > [...] > -- > > As I mentioned, this is due to the unsigned long format specifier (%lu) in > loglevel_print(). Changing the format specifier to %u emits the correct > value (4294967295) on this architecture. > > With your fix, slapd accepts the numeric value 4294967295 for > LDAP_DEBUG_ANY on x86_64. OK, I overlooked that. My point was to make sure unsigned values are correctly cast into (unsigned)-1 by routines intended to deal with integers. I'll fix that again. Thanks, p.

1 0

Re: (ITS#6324) slapd -d ? emits incorrect value for LDAP_DEBUG_ANY on x86_64
by jwm＠horde.net 07 Oct '09

07 Oct '09

On Tue, Oct 06, 2009 at 10:04:45PM +0200, masarati(a)aero.polimi.it wrote: > > The 32-bit value 4294967295 for LDAP_DEBUG_ANY is also rejected. > > lutil_atoix() declares i as type long and tries to check for overflow(?) > > with this cast: > > > > if ( (long)(int)i != i ) { > > > > which always fails in this case on x86_64. lutil_atoux() might be the more > > appropriate choice here. > > > > str2loglevel() seems to behave correctly by virtue of verb_to_mask() > > returning an index into loglevel_ops, but I haven't checked extensively. > > loglevel_init(), however, does specify a hardcoded -1 for the Any level > > instead of LDAP_DEBUG_ANY. > > Please check the fix in HEAD. I can't check right now on x86_64, but I'll > probably do it tomorrow. Apparently, I didn't break anything on 32 bit. 'slapd -d ?' still lists the 64-bit value for LDAP_DEBUG_ANY on x86_64: -- Installed log subsystems: Any (18446744073709551615) [...] -- As I mentioned, this is due to the unsigned long format specifier (%lu) in loglevel_print(). Changing the format specifier to %u emits the correct value (4294967295) on this architecture. With your fix, slapd accepts the numeric value 4294967295 for LDAP_DEBUG_ANY on x86_64. john -- John Morrissey _o /\ ---- __o jwm(a)horde.net _-< \_ / \ ---- < \, www.horde.net/ __(_)/_(_)________/ \_______(_) /_(_)__

1 0

Re: (ITS#6325) test054: test failed - producer and consumer databases differ
by michael＠stroeder.com 07 Oct '09

07 Oct '09

Download testrun/ here: http://www.stroeder.com/temp/openldap/its6325-test054-testrun.tar.gz

1 0

(ITS#6325) test054: test failed - producer and consumer databases differ
by michael＠stroeder.com 07 Oct '09

07 Oct '09

Full_Name: Michael Ströder Version: 2.4.19 OS: SLES 10 URL: Submission from: (NULL) (84.163.54.11) slapd built with BDB 4.8.24 and cyrus-sasl 2.4RC1 >>>>> Starting test054-syncreplication-parallel-load for hdb... running defines.sh Starting producer slapd on TCP/IP port 9011... Using ldapsearch to check that producer slapd is running... Using ldapadd to create the context prefix entry in the producer... Starting consumer slapd on TCP/IP port 9014... Using ldapsearch to check that consumer slapd is running... Using ldapadd to populate the producer directory... Waiting 7 seconds for syncrepl to receive changes... Stopping the provider, sleeping 10 seconds and restarting it... Using ldapsearch to check that producer slapd is running... Waiting 10 seconds to let the system catch up Using ldapmodify to modify producer directory... Using ldappasswd to change some passwords... Waiting 7 seconds for syncrepl to receive changes... Stopping consumer to test recovery... Modifying more entries on the producer... Restarting consumer... Waiting 7 seconds for syncrepl to receive changes... Try updating the consumer slapd... Trying to change some passwords on the consumer... Waiting 7 seconds for syncrepl to receive changes... Using ldapsearch to read all the entries from the producer... Using ldapsearch to read all the entries from the consumer... Filtering producer results... Filtering consumer results... Comparing retrieved entries from producer and consumer... test failed - producer and consumer databases differ >>>>> ./scripts/test054-syncreplication-parallel-load failed for hdb (exit 1) make[2]: *** [hdb-mod] Error 1 make[2]: Leaving directory `/source/openldap-2.4.19/tests' make[1]: *** [test] Error 2 make[1]: Leaving directory `/source/openldap-2.4.19/tests' make: *** [test] Error 2

1 0

slapd crash on load
by Ключников А.С. 07 Oct '09

07 Oct '09

Good day. Openldap 2.4.18 with bdb backend used for pam_ldap and nss_ldap on freebsd7.2 amd64 Crashed every 10 - 30 minutes on serches. Load isnt heavy, about 10 req/sec in peak and 20req/min average. Crash probability is higher when over program use the disk. how to mo debug to resolve problem? Some details: #uname -a FreeBSD bazar 7.2-RELEASE FreeBSD 7.2-RELEASE #3: Tue Jun 9 16:46:20 MSD 2009 root@bazar:/usr/obj/usr/src/sys/GENERIC amd64 #/usr/local/libexec/slapd -V @(#) $OpenLDAP: slapd 2.4.18 (Oct 7 2009 13:29:25) tuning in slapd.conf cachesize 150000 idlcachesize 450000 #checkpoint 64 10 threads 8 concurrency 5 tuning in /var/db/openldap-data/DB_CONFIG set_cachesize 0 62428800 0 set_lg_regionmax 1048576 set_lg_max 10485760 set_lg_bsize 2097152 set_lg_dir /var/db/openldap-data crash debug whith truss /usr/local/libexec/slapd -d -1 _umtx_op(0x8022020b0,0x11,0x0,0x0,0x0,0x0) = 0 (0x0) gidNumber_umtx_op(0x8022020b0,0x11,0x0,0x0,0x0,0x7ffffda79308) = 10 (0xa) getpid(0x80180bf68,0x7fffffffed70,0x0,0x0,0xffff80080f10aaaa,0x0) = 81516 (0x13e6c) sendto(3,"<167>Oct 7 11:59:33 slapd[81516"...,91,0x0,NULL,0x0) = 91 (0x5b) _umtx_op(0x8022020b0,0x12,0x0,0x0,0x0,0x7ffffebfba28) = 0 (0x0) ber_scanf fmt ({im}) ber: write(2,"ber_scanf fmt ({im}) ber:\n",26) = 0 (0x0) ber_dump: buf=0x81141b408 ptr=0x81141b408 end=0x81141b414 len=12 gettimeofday({1254902373.820741 },0x0) = 65 (0x41) 0000: 30 84 00 00 00 06 02 02 03 e8 04 00 0........... write(2," 0000: 30 84 00 00 00 06 02 02"...,79) = 0 (0x0) <= get_ctrls: n=1 rc=0 err="" write(2,"<= get_ctrls: n=1 rc=0 err=""\n",30) = 30 (0x1e) getpid(0x80180bf68,0x7fffffffed70,0x0,0x0,0xffff80080f10aaaa,0x0) = 81516 (0x13e6c) sendto(3,"<167>Oct 7 11:59:33 slapd[81516"...,106,0x0,NULL,0x0) = 106 (0x6a) _umtx_op(0x8022020b0,0x12,0x0,0x0,0x0,0x7fffff3fcaa8) = 0 (0x0) gettimeofday({1254902373.821208 },0x0) = 0 (0x0) ==> limits_get: conn=92 op=1 self="cn=bind,ou=staff,dc=ulgsm,dc=ru" this="ou=staff,dc=ulgsm,dc=ru" getpid(0x80180bf68,0x7fffffffed70,0x0,0x0,0xffff80080f10aaaa,0x0) = 81516 (0x13e6c) _umtx_op(0x8022020b0,0x11,0x0,0x0,0x0,0x7fffff3fc648) = 105 (0x69) _umtx_op(0x8022020b0,0x12,0x0,0x0,0x0,0x7ffffda79658) = 0 (0x0) gettimeofday({1254902373.821644 },0x0) = 34669068288 (0x812700000) getpid(0x80180bf68,0x7fffffffed70,0x0,0x0,0xffff80080f10aaaa,0x0) = 81516 (0x13e6c) => bdb_dn2idl("ou=staff,dc=ulgsm,dc=ru") sendto(3,"<167>Oct 7 11:59:33 slapd[81516"...,45,0x0,NULL,0x0) = 41 (0x29) _umtx_op(0x8022020b0,0x11,0x0,0x0,0x0,0x7ffffda79208) = 45 (0x2d) _umtx_op(0x8022020b0,0x12,0x0,0x0,0x0,0x7ffffe3faaa8) = 0 (0x0) write(2,"\n",1) = 0 (0x0) _umtx_op(0x8022020b0,0x11,0x0,0x0,0x0,0x7ffffe3fa6e8) = 0 (0x0) getpid(0x80180bf68,0x7fffffffed70,0x0,0x0,0xffff80080f10aaaa,0x0) = 81516 (0x13e6c) sendto(3,"<167>Oct 7 11:59:33 slapd[81516"...,64,0x0,NULL,0x0) = 64 (0x40) _umtx_op(0x8022020b0,0x12,0x0,0x0,0x0,0x7ffffebfba28) = 0 (0x0) attrs:write(2," attrs:",10) = 0 (0x0) gettimeofday({1254902373.822603 },0x0) = 0 (0x0) getpid(0x80180bf68,0x7fffffffed70,0x0,0x0,0xffff80080f10aaaa,0x0) = 81516 (0x13e6c) sendto(3,"<167>Oct 7 11:59:33 slapd[81516"...,45,0x0,NULL,0x0) = 45 (0x2d) _umtx_op(0x8022020b0,0x12,0x0,0x0,0x0,0x7ffffebfbaa8) = 0 (0x0) cngettimeofday({1254902373.822938 },0x0) = 3 (0x3) getpid(0x80180bf68,0x7fffffffed70,0x0,0x0,0xffff80080f10aaaa,0x0) = 81516 (0x13e6c) sendto(3,"<167>Oct 7 11:59:33 slapd[81516"...,75,0x0,NULL,0x0) = 75 (0x4b) _umtx_op(0x8022020b0,0x12,0x0,0x0,0x0,0x7ffffda795c8) = 0 (0x0) SIGNAL 11 (SIGSEGV) -- alexs

1 0

Re: (ITS#6310) Slapd with pcache crashes under load
by karavelov＠spnet.net 06 Oct '09

06 Oct '09

masarati(a)aero.polimi.it wrote: > No. Some overlay along the lines apparently mucks with e_private in the > entry that back-ldap is sending. It's probably slapo-pcache. I need to > debug this. You say it happens seldom. Can you recognize anything > special in the operation that triggers the assertion failure? I mean: > either in terms of special data, or in terms of special state of the > cache? This could help narrow down some means to reproduce the issue. > > Thanks, p. > > > What is interesting is that most of the logs are something like this one: conn=6891 op=1 SRCH attr=spamassassin query template of incoming query = (&(objectClass=)(cn=)) Entering QC, querystr = (&(objectClass=mailUser)(cn=nobody)) Lock QC index = 0x7e0a7b8 QUERY ANSWERABLE (answered 3267 times) conn=6891 op=1 SEARCH RESULT tag=101 err=0 nentries=0 text= conn=6891 fd=32 closed (connection lost) query template of incoming query = (&(objectClass=)(uid=)) QUERY NOT ANSWERABLE QUERY NOT CACHEABLE query template of incoming query = (&(objectClass=)(uid=)) QUERY NOT ANSWERABLE QUERY NOT CACHEABLE query template of incoming query = (&(objectClass=)(uid=)) QUERY NOT ANSWERABLE QUERY NOT CACHEABLE query template of incoming query = (&(objectClass=)(uid=)) QUERY NOT ANSWERABLE QUERY NOT CACHEABLE query template of incoming query = (&(objectClass=)(uid=)) QUERY NOT ANSWERABLE QUERY NOT CACHEABLE conn=3573 op=812 SRCH base="dc=ciela.net,dc=hosting,dc=spnet,dc=net" scope=1 deref=0 filter="(&(objectClass=mailUser)(uid=diana))" conn=3573 op=812 SRCH attr=uid userPassword mailMessageStore uidNumber gidNumber query template of incoming query = (&(objectClass=)(uid=)) Entering QC, querystr = (&(objectClass=mailUser)(uid=diana)) Lock QC index = 0x7ee9fe8 Base of added query = dc=ciela.net,dc=hosting,dc=spnet,dc=net QUERY ANSWERABLE (answered 63 times) conn=3573 op=812 SEARCH RESULT tag=101 err=0 nentries=1 text= slapd: /home/luben/openldap-2.4.18-h/servers/slapd/entry.c:483: entry_clean: Assertion `e->e_private == ((void *)0)' failed. This sequence of : query template of incoming query = (&(objectClass=)(uid=)) QUERY NOT ANSWERABLE QUERY NOT CACHEABLE is something I could not explain. There is not a log entry for incomming search. I have restarted the cache with more logging (stats+trace+pcache) to see from where they come. I have some core dumps and if you tell me for what to look for, tomorrow I will debug them and see if there is a common pattern. Luben

1 0

Re: (ITS#6310) Slapd with pcache crashes under load
by masarati＠aero.polimi.it 06 Oct '09

06 Oct '09

> Hello, > I have somehow changed the setup: > > The first process is a ldap to sql server withpout pcache > the config file is here: > http://purgatory.spnet.net/~karavelov/abort/slapd.conf > > The second process is a pure cache that reads from the first process > using unix domain socket. The config file is here: > http://purgatory.spnet.net/~karavelov/abort/slapd-proxy.conf > > The sql backend runs without problems. But the proxy process crashes > once or twice a day on assertion: > > The output of the process is here: > http://purgatory.spnet.net/~karavelov/abort/log > > It was running in valgrind, so here is its output: > http://purgatory.spnet.net/~karavelov/abort/vg > > The process has dumped a core. I have made a debugging session with it. > Here it is: > http://purgatory.spnet.net/~karavelov/abort/gdb > > I am not sure what to look for. The process aborts on the same > asserrtion even it is not run in valgrind. No. Some overlay along the lines apparently mucks with e_private in the entry that back-ldap is sending. It's probably slapo-pcache. I need to debug this. You say it happens seldom. Can you recognize anything special in the operation that triggers the assertion failure? I mean: either in terms of special data, or in terms of special state of the cache? This could help narrow down some means to reproduce the issue. Thanks, p.

1 0

Re: (ITS#6324) slapd -d ? emits incorrect value for LDAP_DEBUG_ANY on x86_64
by masarati＠aero.polimi.it 06 Oct '09

06 Oct '09

> The 32-bit value 4294967295 for LDAP_DEBUG_ANY is also rejected. > lutil_atoix() declares i as type long and tries to check for overflow(?) > with this cast: > > if ( (long)(int)i != i ) { > > which always fails in this case on x86_64. lutil_atoux() might be the more > appropriate choice here. > > str2loglevel() seems to behave correctly by virtue of verb_to_mask() > returning an index into loglevel_ops, but I haven't checked extensively. > loglevel_init(), however, does specify a hardcoded -1 for the Any level > instead of LDAP_DEBUG_ANY. Please check the fix in HEAD. I can't check right now on x86_64, but I'll probably do it tomorrow. Apparently, I didn't break anything on 32 bit. Thanks, p.

1 0

Re: (ITS#6324) slapd -d ? emits incorrect value for LDAP_DEBUG_ANY on x86_64
by jwm＠horde.net 06 Oct '09

06 Oct '09

The 32-bit value 4294967295 for LDAP_DEBUG_ANY is also rejected. lutil_atoix() declares i as type long and tries to check for overflow(?) with this cast: if ( (long)(int)i != i ) { which always fails in this case on x86_64. lutil_atoux() might be the more appropriate choice here. str2loglevel() seems to behave correctly by virtue of verb_to_mask() returning an index into loglevel_ops, but I haven't checked extensively. loglevel_init(), however, does specify a hardcoded -1 for the Any level instead of LDAP_DEBUG_ANY. john -- John Morrissey _o /\ ---- __o jwm(a)horde.net _-< \_ / \ ---- < \, www.horde.net/ __(_)/_(_)________/ \_______(_) /_(_)__

1 0

(ITS#6324) slapd -d ? emits incorrect value for LDAP_DEBUG_ANY on x86_64
by jwm＠horde.net 06 Oct '09

06 Oct '09

Full_Name: John Morrissey Version: HEAD OS: Linux x86_64 URL: ftp://ftp.openldap.org/incoming/ Submission from: (NULL) (2001:4978:194:0:21f:5bff:fee9:da92) slapd -d ? emits the incorrect numeric value for LDAP_DEBUG_ANY on x86_64: $ slapd -d \? Installed log subsystems: Any (18446744073709551615) [...] $ slapd -d 18446744073709551615 unrecognized log level "18446744073709551615" Debug levels are always treated as type int, which is four bytes on Linux x86_64. loglevel_print() in servers/slapd/bconfig.c seems to blame, since it's using a long-typed format (%lu) instead of an unsigned int-typed one (%u).

1 0

Re: (ITS#6310) Slapd with pcache crashes under load
by karavelov＠spnet.net 06 Oct '09

06 Oct '09

Hello, I have somehow changed the setup: The first process is a ldap to sql server withpout pcache the config file is here: http://purgatory.spnet.net/~karavelov/abort/slapd.conf The second process is a pure cache that reads from the first process using unix domain socket. The config file is here: http://purgatory.spnet.net/~karavelov/abort/slapd-proxy.conf The sql backend runs without problems. But the proxy process crashes once or twice a day on assertion: The output of the process is here: http://purgatory.spnet.net/~karavelov/abort/log It was running in valgrind, so here is its output: http://purgatory.spnet.net/~karavelov/abort/vg The process has dumped a core. I have made a debugging session with it. Here it is: http://purgatory.spnet.net/~karavelov/abort/gdb I am not sure what to look for. The process aborts on the same asserrtion even it is not run in valgrind. May be I should try with libdb-4.8? Thanks in advance Luben

1 0

Re: (ITS#6310) Slapd with pcache crashes under load
by masarati＠aero.polimi.it 05 Oct '09

05 Oct '09

masarati(a)aero.polimi.it wrote: > Another quick check you could probably do relatively quickly is zero out > that "e" pointer before calling be_entry_get_rw() within refresh_merge(). Forget about it: it's already done from within be_entry_get_rw() itself. The fact you get a corrupted "e" sounds odd, though. It would be interesting to track how and where it is set. This should appear from valgrind's inspection when *e is dereferenced. p.

1 0

Re: (ITS#6310) Slapd with pcache crashes under load
by masarati＠aero.polimi.it 05 Oct '09

05 Oct '09

luben karavelov wrote: > masarati(a)aero.polimi.it wrote: >> >> Thanks for collecting this info. The valgrind output could be of some >> use, but unfortunately I don't have time right now to set up a working >> RDBMS and extensively debug things. I'll keep this on my todo list. >> >> You should please re-run valgrind with --num-callers=30 or more, because >> in some cases errors are in too nested functions to get a clear idea of >> whether the issue is caused by garbage fed by slapd/back-sql or by errors >> inside the RDBMS/ODBC layers. The fact that valgrind systematically >> complains about internals of the RDBMS/ODBC reading past the end of >> memory >> chunks malloc'ed by slapd could be related to passing some non-nul >> terminated bervals that are dealt with as strings. Having a longer call >> stack could help tracking those occurrences. However, those issues >> should >> not be critical, since there's no invalid writes. >> >> Also, you should walk through the list of attributes being returned, to >> provide a hint about whether back-sql is computing a screwed attrlist or >> so. Along the lines of your current gdb session, you should get to frame >> #5, refresh_merge() in pcache.c, and print *e->e_attrs, >> *e->e_attrs->a_desc, *e->e_attrs->a_vals[0]; then move to >> e->e_attrs->a_next and repeat the prints to the end of the list. The >> fact >> you get a value of "a" equal to 0x500000000 looks definitely odd to >> me, as >> that attr list should result from be_entry_get_rw(), which in turn should >> collect it from the local database. Unless valgrind reveals some oddity >> in back-sql, the behavior you notice should not depend on the specific >> remote database you're using, but rather from the local one. >> >> p. > > Hello, > Tomorrow I will make a setup with pure sql process and a pure pcache > daemon that reads from the first over unix domain socket. In this manner > it will be clear if the crashing part is related to back-sql and the > database drivers/ODBC manager or not. > > Meanwhile, you could find the requested debugging session here: > http://purgatory.spnet.net/~karavelov/attr_list/gdb-1 > > It seems that the "e" pointer is corrupted. Good catch. > Tomorrow I will start it > through valgrind with more back-frames as requested Another quick check you could probably do relatively quickly is zero out that "e" pointer before calling be_entry_get_rw() within refresh_merge(). Thanks, p.

1 0

Re: (ITS#6320)
by j＠telepaths.org 04 Oct '09

04 Oct '09

Michael, Yes, that has been a theory of mine - I am investigating the =20 possibility, however I should point out that we recently =20 decommissioned our old LDAP system, which used slapd on Etch - it uses =20= the same firewalls for out-of-zone-access, and was not affected by =20 this problem. However, I should also point out that since my last update, the =20 problem has not returned. Using a six-member multimaster mesh has =20 proven fruitful so far, but we'll see how it plays out over the next =20 couple of days. Thanks for your help ... On Oct 4, 2009, at 06:00 , Michael Str=F6der wrote: > j(a)telepaths.org wrote: >> On Oct 2, 2009, at 23:00 , Howard Chu wrote: >> >>> j(a)telepaths.org wrote: >>>> My last email was likely indecipherable, so re-sending as plain =20 >>>> text: >>>> >>>> ##### >>>> >>>> This may sound like a strange question, but couldn't seem to find =20= >>>> the >>>> answer in the docs: >>>> >>>> Would the global "idletimeout" parameter interfere with >>>> 'refreshAndPersist' operations in any way? >>> No, that would be stupid. >>> >> Yes Howard -- that would be incredibly stupid. But I had to ask. >> [..] >> SOME of the servers receiving updates are separated by firewalls, >> yes ... HOWEVER (a) there are special policies in place, allowing >> these hosts to communicate via LDAP[S]; this can be confirmed by >> running ldapsearch routines from every possible vantage point TO =20 >> every >> possible provider, etc., > > Note that firewalls are doing connection tracking enforcing their =20 > own timeouts > for idle connections. So please check whether the firewall =20 > configuration > really matches your slapd idle timeout requirements. > > Ciao, Michael.

1 0

Re: (ITS#6310) Slapd with pcache crashes under load
by karavelov＠spnet.net 04 Oct '09

04 Oct '09

masarati(a)aero.polimi.it wrote: > > Thanks for collecting this info. The valgrind output could be of some > use, but unfortunately I don't have time right now to set up a working > RDBMS and extensively debug things. I'll keep this on my todo list. > > You should please re-run valgrind with --num-callers=30 or more, because > in some cases errors are in too nested functions to get a clear idea of > whether the issue is caused by garbage fed by slapd/back-sql or by errors > inside the RDBMS/ODBC layers. The fact that valgrind systematically > complains about internals of the RDBMS/ODBC reading past the end of memory > chunks malloc'ed by slapd could be related to passing some non-nul > terminated bervals that are dealt with as strings. Having a longer call > stack could help tracking those occurrences. However, those issues should > not be critical, since there's no invalid writes. > > Also, you should walk through the list of attributes being returned, to > provide a hint about whether back-sql is computing a screwed attrlist or > so. Along the lines of your current gdb session, you should get to frame > #5, refresh_merge() in pcache.c, and print *e->e_attrs, > *e->e_attrs->a_desc, *e->e_attrs->a_vals[0]; then move to > e->e_attrs->a_next and repeat the prints to the end of the list. The fact > you get a value of "a" equal to 0x500000000 looks definitely odd to me, as > that attr list should result from be_entry_get_rw(), which in turn should > collect it from the local database. Unless valgrind reveals some oddity > in back-sql, the behavior you notice should not depend on the specific > remote database you're using, but rather from the local one. > > p. Hello, Tomorrow I will make a setup with pure sql process and a pure pcache daemon that reads from the first over unix domain socket. In this manner it will be clear if the crashing part is related to back-sql and the database drivers/ODBC manager or not. Meanwhile, you could find the requested debugging session here: http://purgatory.spnet.net/~karavelov/attr_list/gdb-1 It seems that the "e" pointer is corrupted. Tomorrow I will start it through valgrind with more back-frames as requested Best regards Luben

1 0

Re: (ITS#6310) Slapd with pcache crashes under load
by masarati＠aero.polimi.it 04 Oct '09

04 Oct '09

> hyc(a)symas.com wrote: >> I haven't touched back-sql in quite a while, and don't have a suitable >> config >> for testing this. I suggest you run under valgrind and see what errors >> it reports. > > Hello, > > I have run the server through valgrind. It crashed on the same structure > on different location. The gdb session could be found here: > http://purgatory.spnet.net/~karavelov/attr_list/gdb > > The output from valgrind could be found here: > http://purgatory.spnet.net/~karavelov/attr_list/vg > > In it the lines up to 2833 are output on server start. You could find > the address 0x500000000 (found from gdb session) around line 3180. > > I could see nothing interesting in the log file. > > I hope this info will help you. If I could gather more information, just > say. Thanks for collecting this info. The valgrind output could be of some use, but unfortunately I don't have time right now to set up a working RDBMS and extensively debug things. I'll keep this on my todo list. You should please re-run valgrind with --num-callers=30 or more, because in some cases errors are in too nested functions to get a clear idea of whether the issue is caused by garbage fed by slapd/back-sql or by errors inside the RDBMS/ODBC layers. The fact that valgrind systematically complains about internals of the RDBMS/ODBC reading past the end of memory chunks malloc'ed by slapd could be related to passing some non-nul terminated bervals that are dealt with as strings. Having a longer call stack could help tracking those occurrences. However, those issues should not be critical, since there's no invalid writes. Also, you should walk through the list of attributes being returned, to provide a hint about whether back-sql is computing a screwed attrlist or so. Along the lines of your current gdb session, you should get to frame #5, refresh_merge() in pcache.c, and print *e->e_attrs, *e->e_attrs->a_desc, *e->e_attrs->a_vals[0]; then move to e->e_attrs->a_next and repeat the prints to the end of the list. The fact you get a value of "a" equal to 0x500000000 looks definitely odd to me, as that attr list should result from be_entry_get_rw(), which in turn should collect it from the local database. Unless valgrind reveals some oddity in back-sql, the behavior you notice should not depend on the specific remote database you're using, but rather from the local one. p.

1 0

Re: (ITS#6320)
by michael＠stroeder.com 04 Oct '09

04 Oct '09

j(a)telepaths.org wrote: > On Oct 2, 2009, at 23:00 , Howard Chu wrote: > >> j(a)telepaths.org wrote: >>> My last email was likely indecipherable, so re-sending as plain text: >>> >>> ##### >>> >>> This may sound like a strange question, but couldn't seem to find the >>> answer in the docs: >>> >>> Would the global "idletimeout" parameter interfere with >>> 'refreshAndPersist' operations in any way? >> No, that would be stupid. >> > Yes Howard -- that would be incredibly stupid. But I had to ask. > [..] > SOME of the servers receiving updates are separated by firewalls, > yes ... HOWEVER (a) there are special policies in place, allowing > these hosts to communicate via LDAP[S]; this can be confirmed by > running ldapsearch routines from every possible vantage point TO every > possible provider, etc., Note that firewalls are doing connection tracking enforcing their own timeouts for idle connections. So please check whether the firewall configuration really matches your slapd idle timeout requirements. Ciao, Michael.

1 0

Re: (ITS#6320)
by j＠telepaths.org 04 Oct '09

04 Oct '09

Pierangelo, I offered to do post my configuration in my initial post. No one accepted my offer. Since you are now asking for it, I will gladly post it below. Two, thanks for the hint about editing passwords, I can assure you that all confidential data posted below will have been tainted *somehow*. I should also point out that today I made a change to my infrastructure that I hope will help the situation. Since I've noticed that most of the DIT discrepancies were limited to the standard Consumer boxes, and not the Providers, I have decided to do away entirely with the the standard Consumers. We now have six (6) virtually-identically configured Providers whom all replicate with the other five (5) respective hybrid Consumer/Providers. Essentially a six member multimaster mesh, all of whom can contact all of the other members perfectly via both LDAP and LDAPS. Here is a slapd.conf from ONE of the SIX members: ##### include /etc/ldap/schema/core.schema include /etc/ldap/schema/cosine.schema include /etc/ldap/schema/nis.schema include /etc/ldap/schema/inetorgperson.schema include /etc/ldap/schema/misc.schema include /etc/ldap/schema/openldap.schema include /etc/ldap/schema/duaconf.schema include /etc/ldap/schema/dyngroup.schema include /etc/ldap/schema/ppolicy.schema include /etc/ldap/schema/sudo.schema include /etc/ldap/schema/dhcp.schema include /etc/ldap/schema/samba.schema include /usr/share/doc/libpam-ldap/ldapns.schema include /etc/ldap/schema/hdb.schema include /etc/ldap/schema/uber.schema pidfile /var/run/slapd/slapd.pid argsfile /var/run/slapd/slapd.args tool-threads 4 loglevel none modulepath /usr/lib/ldap moduleload back_hdb moduleload back_relay moduleload rwm.la moduleload back_monitor.la moduleload syncprov moduleload accesslog serverID 100 ldaps://10.64.100.100:636/ serverID 107 ldaps://10.64.100.107:636/ serverID 108 ldaps://10.64.100.108:636/ serverID 811 ldaps://10.9.8.11:636/ serverID 812 ldaps://10.9.8.12:636/ serverID 814 ldaps://10.9.8.14:636/ TLSCertificateFile /etc/ldap/ssl/wildcard.site.example.com.crt TLSCertificateKeyFile /etc/ldap/ssl/wildcard.site.example.com.key TLSCACertificateFile /etc/ssl/certs/ca.cert disallow bind_anon sizelimit unlimited timelimit unlimited security tls=0 access to dn.subtree="cn=Subschema" by users read by * none stop access to dn.base="" by users read by * none stop defaultSearchBase dc=real,dc=example,dc=com sasl-realm SITE.EXAMPLE.COM sasl-host ds.site.example.com #sasl-secprops minssf=0 authz-regexp "uid=$.*$,cn=SITE.EXAMPLE.COM,cn=gssapi,cn=auth" "uid=$1,cn=plain,cn=auth,dc=site,dc=example,dc=com" authz-regexp "gidNumber=\\\0+uidNumber=\\ \0,cn=peercred,cn=external,cn=auth" "uid=writer,cn=plain,cn=auth,dc=real,dc=example,dc=com" backend hdb ########### Monitoring Database - For slapd/hdb performance data database monitor rootdn uid=monitor,cn=monitor rootpw {SSHA}encrypted-hash access to dn.subtree="cn=monitor" by group/groupOfUniqueNames/ uniqueMember ="cn=ldapadmin,cn=ldap,cn=groups,dc=real,dc=example,dc=com" read by dn.exact="uid=rootdn,cn=plain,cn=auth,dc=real,dc=example,dc=com" read ########### example.Log database hdb suffix cn=log rootdn "uid=log,cn=log" rootpw {SSHA}encrypted-hash directory /var/lib/ldap/log index reqStart,objectClass,entryCSN,reqResult eq dbconfig set_cachesize 0 2097152 0 overlay syncprov syncprov-nopresent TRUE syncprov-reloadhint TRUE access to dn.subtree="cn=log" by group/groupOfUniqueNames/ uniqueMember ="cn=ldapadmin,cn=ldap,cn=groups,dc=real,dc=example,dc=com" read by dn.base="uid=rootdn,cn=plain,cn=auth,dc=real,dc=example,dc=com" read by dn.base="uid=log,cn=log" read ########### example.real database hdb cachesize 10000 idlcachesize 30000 suffix "dc=real,dc=example,dc=com" checksum checkpoint 100 10 cachefree 20 rootdn "uid=rootdn,cn=plain,cn=auth,dc=real,dc=example,dc=com" rootpw {SSHA}encrypted-hash monitoring on directory "/var/lib/ldap/real" dncachesize 100000 dbconfig set_cachesize 1 0 2 dbconfig set_lg_max 10485760 dbconfig set_flags db_log_autoremove dbconfig set_lg_bsize 2097152 dbconfig set_lk_max_objects 1500 dbconfig set_lk_max_locks 1500 dbconfig set_lk_max_lockers 1500 index objectClass,structuralObjectClass eq index entryCSN,entryUUID eq index cn,uid,memberUid eq syncrepl rid=001 provider=ldaps://10.64.100.100:636/ bindmethod=simple binddn="uid=syncrepl,cn=plain,cn=auth,dc=real,dc=example,dc=com" credentials=syncreplpass scope=sub filter="(objectClass=*)" schemachecking=off searchbase="dc=real,dc=example,dc=com" retry="120 +" sizelimit=unlimited timeout=1 type=refreshAndPersist syncrepl rid=002 provider=ldaps://10.64.100.107:636/ bindmethod=simple binddn="uid=syncrepl,cn=plain,cn=auth,dc=real,dc=example,dc=com" credentials=syncreplpass scope=sub filter="(objectClass=*)" schemachecking=off searchbase="dc=real,dc=example,dc=com" retry="120 +" sizelimit=unlimited timeout=1 type=refreshAndPersist syncrepl rid=003 provider=ldaps://10.64.100.108:636/ bindmethod=simple binddn="uid=syncrepl,cn=plain,cn=auth,dc=real,dc=example,dc=com" credentials=syncreplpass scope=sub filter="(objectClass=*)" schemachecking=off searchbase="dc=real,dc=example,dc=com" retry="120 +" sizelimit=unlimited timeout=1 type=refreshAndPersist syncrepl rid=004 provider=ldaps://10.9.8.14:636/ bindmethod=simple binddn="uid=syncrepl,cn=plain,cn=auth,dc=real,dc=example,dc=com" credentials=syncreplpass scope=sub filter="(objectClass=*)" schemachecking=off searchbase="dc=real,dc=example,dc=com" retry="120 +" sizelimit=unlimited timeout=1 type=refreshAndPersist syncrepl rid=005 provider=ldaps://10.9.8.11:636/ bindmethod=simple binddn="uid=syncrepl,cn=plain,cn=auth,dc=real,dc=example,dc=com" credentials=syncreplpass scope=sub filter="(objectClass=*)" schemachecking=off searchbase="dc=real,dc=example,dc=com" retry="120 +" sizelimit=unlimited timeout=1 type=refreshAndPersist mirrormode true overlay syncprov syncprov-reloadhint TRUE #syncprov-checkpoint 10 5 syncprov-sessionlog 5000 overlay accesslog logdb cn=log logops writes logpurge 7+00:00 2+00:00 logsuccess TRUE include /etc/ldap/acls include /etc/ldap/relays #### Thanks again Jeff

1 0

Re: (ITS#6320)
by masarati＠aero.polimi.it 04 Oct '09

04 Oct '09

> OK, maybe I wasn't clear enough, so I'll rephrase my initial question: > > Is it normal for a 'slapd' server to ONLY correct itself via a restart > of the 'slapd' process? > > I asked because of my earlier findings today. Since waiting for the > system to correct the discrepancy in the DIT by itself proved to be a > futile exercise, and since a manual restart produced the results, it > seemed as though I was observing suboptimal behavior, and was asking > if this was indicative of something else. What about posting your *EXACT* configuration - not a snapshot of it, not a verbal description of how you defined it. Sometimes the devil is in the details. Only make sure you remove passwords, assuming they're correctly spelled in the original. p.

1 0

Re: (ITS#6310) Slapd with pcache crashes under load
by karavelov＠spnet.net 03 Oct '09

03 Oct '09

hyc(a)symas.com wrote: > I haven't touched back-sql in quite a while, and don't have a suitable config > for testing this. I suggest you run under valgrind and see what errors it reports. Hello, I have run the server through valgrind. It crashed on the same structure on different location. The gdb session could be found here: http://purgatory.spnet.net/~karavelov/attr_list/gdb The output from valgrind could be found here: http://purgatory.spnet.net/~karavelov/attr_list/vg In it the lines up to 2833 are output on server start. You could find the address 0x500000000 (found from gdb session) around line 3180. I could see nothing interesting in the log file. I hope this info will help you. If I could gather more information, just say. Luben

1 0

Re: (ITS#6320)
by j＠telepaths.org 02 Oct '09

02 Oct '09

OK, maybe I wasn't clear enough, so I'll rephrase my initial question: Is it normal for a 'slapd' server to ONLY correct itself via a restart of the 'slapd' process? I asked because of my earlier findings today. Since waiting for the system to correct the discrepancy in the DIT by itself proved to be a futile exercise, and since a manual restart produced the results, it seemed as though I was observing suboptimal behavior, and was asking if this was indicative of something else. On Oct 2, 2009, at 23:02 , Howard Chu wrote: > j(a)telepaths.org wrote: >> IMPORTANT UPDATE: >> >> Is it normal for a 'slapd' server to correct itself via a restart of >> the slapd process? Currently, I have one Consumer that is 2-records >> behind in Synchronization - I restarted his process and the records >> immediately were replicated. This normally is NOT standard behavior. >> >> Can anyone explain? Is this expected? Indicative of another problem? > > That's what the "refresh" in "refreshAndPersist" is about. Any > freshly started consumer will automatically sync up to the current > state of the provider. > > -- > -- Howard Chu > CTO, 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#6320)
by j＠telepaths.org 02 Oct '09

02 Oct '09

On Oct 2, 2009, at 23:00 , Howard Chu wrote: > j(a)telepaths.org wrote: >> My last email was likely indecipherable, so re-sending as plain text: >> >> ##### >> >> This may sound like a strange question, but couldn't seem to find the >> answer in the docs: >> >> Would the global "idletimeout" parameter interfere with >> 'refreshAndPersist' operations in any way? > > No, that would be stupid. > Yes Howard -- that would be incredibly stupid. But I had to ask. >> I ask because I have had yet another instance where my three >> production consumers did not get a series of updates that it should >> have. This was hours after successfully adding an accesslog database >> to all Provider servers in question. >> >> When querying the log database: >> >> ldapsearch -b cn=log -xD uid=log,cn=log -w logpassword -s sub -H ldap://ldap-provider-in-question >> >> I see that the records-in-question were in fact updated as they >> should >> have .... but there's absolutely no information hinting towards WHY a >> remote server would fail to get updates (especially when all LDAP >> traffic in between the said-hosts is unrestricted and unmoderated). > > Are you sure? No firewalls in the way? > SOME of the servers receiving updates are separated by firewalls, yes ... HOWEVER (a) there are special policies in place, allowing these hosts to communicate via LDAP[S]; this can be confirmed by running ldapsearch routines from every possible vantage point TO every possible provider, etc., and (b) some of the replication issues observed occurred when all affected hosts (one or more providers and its consumer clients) were in the same local subnet, at which point the firewall is immaterial. I had asked my stupid question about the idletimeout, because this behavior doesn't strike me as simply "not working". Rather, it begins to work .... then just stops. So my next thought was that perhaps the firewall was causing the connections to time-out. But if that were true ... wouldn't both the "retry" and the "timeout" parameters compensate for this? I mean, the man page certainly doesn't contradict my assumption ... Jeff >> Hence why I began to scrutinize the 'idletimeout' parameter >> (previously set to 45 seconds, now has been removed entirely from all >> Providers AND Consumers alike). >> >> Still looking at, testing and contemplating this whole situation ... >> I'll keep you posted, but am curious if anyone has any input to my >> question above, thanks. >> >> ##### >> >> I am officially out of ideas - synchronization is entirely >> unreliable. >> Need guidance ASAP. Thanks ..... > > -- > -- Howard Chu > CTO, 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#6320)
by hyc＠symas.com 02 Oct '09

02 Oct '09

j(a)telepaths.org wrote: > IMPORTANT UPDATE: > > Is it normal for a 'slapd' server to correct itself via a restart of > the slapd process? Currently, I have one Consumer that is 2-records > behind in Synchronization - I restarted his process and the records > immediately were replicated. This normally is NOT standard behavior. > > Can anyone explain? Is this expected? Indicative of another problem? That's what the "refresh" in "refreshAndPersist" is about. Any freshly started consumer will automatically sync up to the current state of the provider. -- -- Howard Chu CTO, 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#6320)
by hyc＠symas.com 02 Oct '09

02 Oct '09

j(a)telepaths.org wrote: > My last email was likely indecipherable, so re-sending as plain text: > > ##### > > This may sound like a strange question, but couldn't seem to find the > answer in the docs: > > Would the global "idletimeout" parameter interfere with > 'refreshAndPersist' operations in any way? No, that would be stupid. > I ask because I have had yet another instance where my three > production consumers did not get a series of updates that it should > have. This was hours after successfully adding an accesslog database > to all Provider servers in question. > > When querying the log database: > > ldapsearch -b cn=log -xD uid=log,cn=log -w logpassword -s sub -H ldap://ldap-provider-in-question > > I see that the records-in-question were in fact updated as they should > have .... but there's absolutely no information hinting towards WHY a > remote server would fail to get updates (especially when all LDAP > traffic in between the said-hosts is unrestricted and unmoderated). Are you sure? No firewalls in the way? > Hence why I began to scrutinize the 'idletimeout' parameter > (previously set to 45 seconds, now has been removed entirely from all > Providers AND Consumers alike). > > Still looking at, testing and contemplating this whole situation ... > I'll keep you posted, but am curious if anyone has any input to my > question above, thanks. > > ##### > > I am officially out of ideas - synchronization is entirely unreliable. > Need guidance ASAP. Thanks ..... -- -- Howard Chu CTO, 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#6320)
by j＠telepaths.org 02 Oct '09

02 Oct '09

IMPORTANT UPDATE: Is it normal for a 'slapd' server to correct itself via a restart of the slapd process? Currently, I have one Consumer that is 2-records behind in Synchronization - I restarted his process and the records immediately were replicated. This normally is NOT standard behavior. Can anyone explain? Is this expected? Indicative of another problem? Jeff

1 0

Re: (ITS#6320)
by j＠telepaths.org 02 Oct '09

02 Oct '09

My last email was likely indecipherable, so re-sending as plain text: ##### This may sound like a strange question, but couldn't seem to find the answer in the docs: Would the global "idletimeout" parameter interfere with 'refreshAndPersist' operations in any way? I ask because I have had yet another instance where my three production consumers did not get a series of updates that it should have. This was hours after successfully adding an accesslog database to all Provider servers in question. When querying the log database: ldapsearch -b cn=log -xD uid=log,cn=log -w logpassword -s sub -H ldap://ldap-provider-in-question I see that the records-in-question were in fact updated as they should have .... but there's absolutely no information hinting towards WHY a remote server would fail to get updates (especially when all LDAP traffic in between the said-hosts is unrestricted and unmoderated). Hence why I began to scrutinize the 'idletimeout' parameter (previously set to 45 seconds, now has been removed entirely from all Providers AND Consumers alike). Still looking at, testing and contemplating this whole situation ... I'll keep you posted, but am curious if anyone has any input to my question above, thanks. ##### I am officially out of ideas - synchronization is entirely unreliable. Need guidance ASAP. Thanks ..... Jeff

1 0

Re: (ITS#6322) slapd suddenly stops working, and starts using 100% CPU
by quanah＠zimbra.com 02 Oct '09

02 Oct '09

--On Friday, October 02, 2009 8:54 PM +0000 hyc(a)symas.com wrote: > strace is useless. Use gdb and get a trace of all running threads when > this occurs. > > http://www.openldap.org/faq/data/cache/59.html You also need to test against a current release of OpenLDAP, like OpenLDAP 2.4.18. --Quanah -- Quanah Gibson-Mount Principal Software Engineer Zimbra, Inc -------------------- Zimbra :: the leader in open source messaging and collaboration

1 0

Re: (ITS#6321) segfault in 2.4.18 replica
by Howard Chu 02 Oct '09

02 Oct '09

Your trace shows pretty clearly that the crash occurred in your Kerberos library. You're going to need to start there to look for the problem.

1 0

Re: (ITS#6310) Slapd with pcache crashes under load
by hyc＠symas.com 02 Oct '09

02 Oct '09

karavelov(a)spnet.net wrote: > Full_Name: luben karavelov > Version: 2.4.18 - HEAD > OS: Debian Linux > URL: > Submission from: (NULL) (212.50.0.80) > > > Hello, > I have 2 running slapd servers for load balancing. The 2 instances are > configured with back-sql and pcache overlay. Every 5-15 minutes one of the > servers crashes. > > The config could be found here: > http://purgatory.spnet.net/~karavelov/slapd.conf.h2 > > A gdb session with the resulting core dump could be found here: > http://purgatory.spnet.net/~karavelov/gdb1 > > Without proxycache overlay the servers does not crash in this manner. > > The software tested is > 1. slapd 2.4.18 with backported pcache.c from HEAD > 2. slapd HEAD I haven't touched back-sql in quite a while, and don't have a suitable config for testing this. I suggest you run under valgrind and see what errors it reports. -- -- Howard Chu CTO, 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#6320)
by j＠telepaths.org 02 Oct '09

02 Oct '09

--Apple-Mail-4--815209214 Content-Transfer-Encoding: 7bit Content-Type: text/plain; charset=us-ascii; format=flowed; delsp=yes This may sound like a strange question, but couldn't seem to find the answer in the docs: Would the global "idletimeout" parameter interfere with 'refreshAndPersist' operations in any way? I ask because I have had yet another instance where my three production consumers did not get a series of updates that it should have. This was hours after successfully adding an accesslog database to all Provider servers in question. When querying the log database: ldapsearch -b cn=log -xD uid=log,cn=log -w logpassword -s sub -H ldap://ldap-provider-in-question I see that the records-in-question were in fact updated as they should have .... but there's absolutely no information hinting towards WHY a remote server would fail to get updates (especially when all LDAP traffic in between the said-hosts is unrestricted and unmoderated). Hence why I began to scrutinize the 'idletimeout' parameter (previously set to 45 seconds, now has been removed entirely from all Providers AND Consumers alike). Still looking at, testing and contemplating this whole situation ... I'll keep you posted, but am curious if anyone has any input to my question above, thanks. Jeff On Oct 1, 2009, at 11:39 PM, Howard Chu wrote: > j(a)telepaths.org wrote: >> Sorry about that .... resending to ITS address: >> >> Regarding use of the accesslog DB ..... is this still an option when >> using 'mirrormode' ? I understand at least in the recent past, this >> option was not compatible with the accesslog overlay ..... > > That's not correct. The accesslog overlay can always be used for > logging purposes. It is just that using it for multimaster delta- > syncrepl is not yet supported. > > -- > -- Howard Chu > CTO, Symas Corp. http://www.symas.com > Director, Highland Sun http://highlandsun.com/hyc/ > Chief Architect, OpenLDAP http://www.openldap.org/project/ --Apple-Mail-4--815209214 Content-Transfer-Encoding: quoted-printable Content-Type: text/html; charset=us-ascii <html><head></head><body style=3D"word-wrap: break-word; = -webkit-nbsp-mode: space; -webkit-line-break: after-white-space; = "><div>This may sound like a strange question, but couldn't seem to find = the answer in the docs:</div><div><br></div><div>Would the global = "idletimeout" parameter interfere with 'refreshAndPersist' operations in = any way?</div><div><br></div><div>I ask because I have had yet another = instance where my three production consumers did not get a series of = updates that it should have.  This was hours after successfully = adding an accesslog database to all Provider servers in = question.</div><div><br></div><div>When querying the log = database:</div><div><br></div><div style=3D"font-size: 14px; = ">ldapsearch -b cn=3Dlog -xD uid=3Dlog,cn=3Dlog -w logpassword -s sub -H = <a = href=3D"ldap://ldap-provider-in-question">ldap://ldap-provider-in-question= </a></div><div><br></div><div>I see that the records-in-question were in = fact updated as they should have .... but there's absolutely no = information hinting towards WHY a remote server would fail to get = updates (especially when all LDAP traffic in between the said-hosts is = unrestricted and unmoderated).  Hence why I began to scrutinize the = 'idletimeout' parameter (previously set to 45 seconds, now has been = removed entirely from all Providers AND Consumers = alike).</div><div><br></div><div>Still looking at, testing and = contemplating this whole situation ... I'll keep you posted, but am = curious if anyone has any input to my question above, = thanks.</div><div><br></div><div>Jeff</div><div><br></div><div><br></div><= div><br></div><br><div><div>On Oct 1, 2009, at 11:39 PM, Howard Chu = wrote:</div><br class=3D"Apple-interchange-newline"><blockquote = type=3D"cite"><div><a href=3D"mailto:j@telepaths.org">j(a)telepaths.org</a> = wrote:<br><blockquote type=3D"cite">Sorry about that .... =  resending to ITS address:<br></blockquote><blockquote = type=3D"cite"><br></blockquote><blockquote type=3D"cite">Regarding use = of the accesslog DB ..... is this still an option = when<br></blockquote><blockquote type=3D"cite">using 'mirrormode' ? =  I understand at least in the recent past, = this<br></blockquote><blockquote type=3D"cite">option was not compatible = with the accesslog overlay .....<br></blockquote><br>That's not correct. = The accesslog overlay can always be used for logging purposes. It is = just that using it for multimaster delta-syncrepl is not yet = supported.<br><br>-- <br>  -- Howard Chu<br>  CTO, Symas Corp. =           <a = href=3D"http://www.symas.com">http://www.symas.com</a><br> =  Director, Highland Sun     <a = href=3D"http://highlandsun.com/hyc/">http://highlandsun.com/hyc/</a><br> =  Chief Architect, OpenLDAP  <a = href=3D"http://www.openldap.org/project/">http://www.openldap.org/project/= </a><br></div></blockquote></div><br></body></html>= --Apple-Mail-4--815209214--

1 0

Re: (ITS#6322) slapd suddenly stops working, and starts using 100% CPU
by hyc＠symas.com 02 Oct '09

02 Oct '09

helge(a)monsternett.no wrote: > Full_Name: Helge Milde > Version: slapd 2.4.11 > OS: Debian 5 > URL: > Submission from: (NULL) (81.175.2.164) > > > Hello, > > In the last two days, slapd has randomly stopped working on our server, about > one time every two or three hours. Before this, slapd had been running without > any problems for about two months. slapd.conf has not been touched since then. > > What happens is that slapd stops taking queries (postfix, dovecot, NSS etc. > starts getting timeouts), and it starts using exactly 100% of one core until we > restart it. > After restart, everything works again (until this happens again). > > It seems to only happen when slapd is under "stress" (we have an 8-core system > with 8G RAM, and so slapd is really never under much "stress"; the biggest CPU > load I've seen is about 40% on one core). The last ldap search before slapd > stops working is always the same: > Oct 2 10:57:38 oi-mail slapd[24550]: conn=1543 op=1 SRCH > base="ou=groups,dc=web,dc=xxxx,dc=net" scope=1 deref=0 > filter="(&(objectClass=posixGroup))" > .. which should return about 1800 entries. Different connections might query > this simultaneously, and it's a query that happens every ~10 seconds on > average. > > I've tried to reproduce this by doing .. > # while [ 1 ]; do ldapsearch -x -H ldaps://.. -b > 'ou=groups,dc=web,dc=xxxx,dc=net' '(&(objectClass=posixAccount))'; done > .. for two minutes without any "luck" :). slapd just uses a bit more CPU, but > never stops working. > > With "loglevel stats stats2", I get nothing out of the logs: > Oct 2 08:42:15 oi-mail slapd[15836]: conn=34798 op=1 ENTRY > dn="cn=xxxx,ou=groups,dc=web,dc=xxxx,dc=net" > ... time of "crash" (we're mid-search at this point); nothing gets logged until > we do a restart: ... > Oct 2 08:42:30 oi-mail slapd[15836]: daemon: shutdown requested and initiated. > Oct 2 08:42:30 oi-mail slapd[15836]: conn=34391 fd=31 closed (slapd shutdown) > ... many entires like the one above, and then I seem to be getting the next > entry from the same connection, right before it closes: ... > Oct 2 08:42:30 oi-mail slapd[15836]: conn=34798 op=1 ENTRY > dn="cn=xxxx,ou=groups,dc=web,dc=xxxx,dc=net" > Oct 2 08:42:30 oi-mail slapd[15836]: conn=34798 fd=81 closed (slapd shutdown) > > I've tried logging more than just stats, but the interesting loglevels also > causes a big performance hit (trace and args), and I'm not really sure which of > the other loglevels could be helpful. > This is a live ldap server, on a server that also hosts other services, so I > simply can't take the performance hit. > > I also did a strace -p<slapd pid>, which only gives "futex(0x41c499e0, > FUTEX_WAIT," until I restart slapd, but the "restarting routine" could be > useful, so here it is: http://www.pastie.org/639170 strace is useless. Use gdb and get a trace of all running threads when this occurs. http://www.openldap.org/faq/data/cache/59.html -- -- Howard Chu CTO, Symas Corp. http://www.symas.com Director, Highland Sun http://highlandsun.com/hyc/ Chief Architect, OpenLDAP http://www.openldap.org/project/

1 0

(ITS#6323) smbk5pwd: Makefile links module for a different directory than it's installed to
by jonathan＠phillipoux.net 02 Oct '09

02 Oct '09

Full_Name: Jonathan Clarke Version: RE24 OS: Linux URL: ftp://ftp.openldap.org/incoming/jonathan-clarke-smbk5pwd-rpath-20091002.pat… Submission from: (NULL) (82.67.204.30) Greetings, The makefile in the smbk5pwd contrib module runs the libtool link phase with rtool=$(libdir), but then installs the module to $(moduledir), which can be different, and thus causes install to bork: ../../../libtool --mode=install cp smbk5pwd.la /usr/lib/openldap libtool: install: error: cannot install `smbk5pwd.la' to a directory not ending in /usr/lib The patch above fixes this, removing libdir completely from the Makefile as it doesn't seem to be needed.

1 0

Re: (ITS#6320)
by j＠telepaths.org 02 Oct '09

02 Oct '09

OK I have a fully-functional accesslog configured on all applicable Provider servers. The respective DIT is now being watched for all WRITES (delete, add, modify and modrdn). I made a change a few minutes ago to a test record, and it DID replicate to ALL slapd servers, so we're looking good in the "short- term". I will check back with you guys later today with any developments, but we should know if there's still a problem today, and maybe now I can get some visibility into it. Thanks again to both of you, Howard and Quanah. Jeff

1 0

Re: (ITS#6320)
by j＠telepaths.org 02 Oct '09

02 Oct '09

Ah, I see. Then the accesslog overlay can be loaded and used on the Provider, but Consumers won't query the Provider any differently than with regular SyncRepl. I will promptly try this, thanks Howard. Jeff On Oct 1, 2009, at 23:39 , Howard Chu wrote: > j(a)telepaths.org wrote: >> Sorry about that .... resending to ITS address: >> >> Regarding use of the accesslog DB ..... is this still an option when >> using 'mirrormode' ? I understand at least in the recent past, this >> option was not compatible with the accesslog overlay ..... > > That's not correct. The accesslog overlay can always be used for > logging purposes. It is just that using it for multimaster delta- > syncrepl is not yet supported. > > -- > -- Howard Chu > CTO, Symas Corp. http://www.symas.com > Director, Highland Sun http://highlandsun.com/hyc/ > Chief Architect, OpenLDAP http://www.openldap.org/project/

1 0

(ITS#6322) slapd suddenly stops working, and starts using 100% CPU
by helge＠monsternett.no 02 Oct '09

02 Oct '09

Full_Name: Helge Milde Version: slapd 2.4.11 OS: Debian 5 URL: Submission from: (NULL) (81.175.2.164) Hello, In the last two days, slapd has randomly stopped working on our server, about one time every two or three hours. Before this, slapd had been running without any problems for about two months. slapd.conf has not been touched since then. What happens is that slapd stops taking queries (postfix, dovecot, NSS etc. starts getting timeouts), and it starts using exactly 100% of one core until we restart it. After restart, everything works again (until this happens again). It seems to only happen when slapd is under "stress" (we have an 8-core system with 8G RAM, and so slapd is really never under much "stress"; the biggest CPU load I've seen is about 40% on one core). The last ldap search before slapd stops working is always the same: Oct 2 10:57:38 oi-mail slapd[24550]: conn=1543 op=1 SRCH base="ou=groups,dc=web,dc=xxxx,dc=net" scope=1 deref=0 filter="(&(objectClass=posixGroup))" .. which should return about 1800 entries. Different connections might query this simultaneously, and it's a query that happens every ~10 seconds on average. I've tried to reproduce this by doing .. # while [ 1 ]; do ldapsearch -x -H ldaps://.. -b 'ou=groups,dc=web,dc=xxxx,dc=net' '(&(objectClass=posixAccount))'; done .. for two minutes without any "luck" :). slapd just uses a bit more CPU, but never stops working. With "loglevel stats stats2", I get nothing out of the logs: Oct 2 08:42:15 oi-mail slapd[15836]: conn=34798 op=1 ENTRY dn="cn=xxxx,ou=groups,dc=web,dc=xxxx,dc=net" ... time of "crash" (we're mid-search at this point); nothing gets logged until we do a restart: ... Oct 2 08:42:30 oi-mail slapd[15836]: daemon: shutdown requested and initiated. Oct 2 08:42:30 oi-mail slapd[15836]: conn=34391 fd=31 closed (slapd shutdown) ... many entires like the one above, and then I seem to be getting the next entry from the same connection, right before it closes: ... Oct 2 08:42:30 oi-mail slapd[15836]: conn=34798 op=1 ENTRY dn="cn=xxxx,ou=groups,dc=web,dc=xxxx,dc=net" Oct 2 08:42:30 oi-mail slapd[15836]: conn=34798 fd=81 closed (slapd shutdown) I've tried logging more than just stats, but the interesting loglevels also causes a big performance hit (trace and args), and I'm not really sure which of the other loglevels could be helpful. This is a live ldap server, on a server that also hosts other services, so I simply can't take the performance hit. I also did a strace -p <slapd pid>, which only gives "futex(0x41c499e0, FUTEX_WAIT," until I restart slapd, but the "restarting routine" could be useful, so here it is: http://www.pastie.org/639170 I understand that this probably isn't enough data to see what the problem is, and so I'm hoping to get some help in debugging this properly. As I've said, args/trace loglevel takes too much of a performance hit, but if this is the only way, we might reconcider. Interesting parts of slapd.conf below. We use slapd.conf instead of cn=config, everything goes over TLS, we're AFAIK only using LDAPv3 binding, and we only have one database entry in slapd.conf. moduleload back_hdb sizelimit 99999 tool-threads 8 threads 16 concurrency 32 backend hdb database hdb cachesize 60000 dbconfig set_cachesize 0 52428800 0 dbconfig set_lk_max_objects 1500 dbconfig set_lk_max_locks 1500 dbconfig set_lk_max_lockers 1500 lastmod on checkpoint 512 30 Best regards, Helge Milde

1 0

Re: (ITS#6320)
by hyc＠symas.com 01 Oct '09

01 Oct '09

j(a)telepaths.org wrote: > Sorry about that .... resending to ITS address: > > Regarding use of the accesslog DB ..... is this still an option when > using 'mirrormode' ? I understand at least in the recent past, this > option was not compatible with the accesslog overlay ..... That's not correct. The accesslog overlay can always be used for logging purposes. It is just that using it for multimaster delta-syncrepl is not yet supported. -- -- Howard Chu CTO, 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#6217) proxycache not returning cached data
by masarati＠aero.polimi.it 01 Oct '09

01 Oct '09

> Sounds more like a schema config issue then. Most likely you don't have > the > matching schema in the proxy server, so it is unable to store the entries > it > has received. That was my first thought as well, but the proxy's slapd.conf he posted earlier included some samba-related schema file (I'm blindly assuming that file was defining sambaSamAccount). p.

1 0

(ITS#6320)
by j＠telepaths.org 01 Oct '09

01 Oct '09

Sorry about that .... resending to ITS address: Regarding use of the accesslog DB ..... is this still an option when using 'mirrormode' ? I understand at least in the recent past, this option was not compatible with the accesslog overlay ..... Jeff

1 0

Re: (ITS#6217) proxycache not returning cached data
by hyc＠symas.com 01 Oct '09

01 Oct '09

Jim van Keulen wrote: > Howard Chu wrote: >> w.van.keulen(a)few.vu.nl wrote: >>> masarati(a)aero.polimi.it wrote: >>>>> Here are slapd.conf and proxycache.conf as attachments. >>>> >>>> I just wanted to feed back before I leave for a few days. I don't see >>>> anything critical in your files. You explicitly give the rootdn write >>>> permissions, which is useless, but apart from this everything looks >>>> fine. >>>> >>>> I've tested a simple setup and it works as expected. I used HEAD and >>>> re24 >>>> code; the latter is nearly identical to 2.4.17. I also tested with TLS. >>>> >>>> At this point, I'm a bit clueless. There must be something we're >>>> overlooking. >> >>> Here is some more info, that I just discovered. >>> If my filter rule is >>> '(&(objectClass=sambaSamAccount)(uid=wvk))' >>> the data is cached the first time, but not returned >>> the second and later time. However when my filter rule is >>> (&(objectClass=posixAccount)(uid=wvk))' >>> it works as expected. >> >> Sounds like you may have already had the entry in the cache DB but with >> an incompatible objectclass before, and the attempt to update it with >> the new objectclass failed. This seems to be related to ITS#6242 which >> was recently fixed in HEAD. Can you please retest with the latest >> overlays/pcache.c? >> > > As you requested I retested with HEAD. However the cache is still not > working correctly. > > When my filter rule is: > '(&(objectClass=posixAccount)(uid=<who>))' the named attributes are > cached and correctly returned from the cache for every uid from the > existing user base > When my filter rule is: > '(&(objectClass=sambaSamAccount)(uid=<who>))' the named attributes are > cached and correctly returned from the cache for a subset of the > existing user base only. For all uid's the query is cached (according to > the log), but for some no data is returned. Sounds more like a schema config issue then. Most likely you don't have the matching schema in the proxy server, so it is unable to store the entries it has received. -- -- Howard Chu CTO, 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#6320) Replication Issues
by quanah＠zimbra.com 01 Oct '09

01 Oct '09

--On Thursday, October 01, 2009 12:20 PM -0700 Jeff Doyle <j(a)telepaths.org> wrote: > Yes, that is the first thing attempted (both via using LOCAL4 -> syslog > and via running slapd via cmd line) > > We see a brand-new server replicate all records (sids, csns, etc all look > fine) without incident. An existing server will receive, as I said, all > of the changes ... at least for awhile. > > Nothing in the sync activity looks out of the ordinary (and I have read > quite a few posts to be able to discern what the items inside mean) > > When a replication error occurs, often nothing at all is seen inside the > logs (no error mesg, no segfault, nothing) to indicate a failure has > occurred. Oftentimes, when SyncRepl fails to replicate, it is NOT during > testing, so it is difficult for us to find out exactly WHEN the error > occurred, as it could have happened at any point within the past 24 hrs, > and up to a week ago. > > I can try to replicate this error deliberately. Unfortunately it is very > difficult to make happen at-will. My concern is that someone will try to > close this ticket before I have witnessed the event. Hm, I would suggest creating an accesslog database on the master that records all of your changes. That way, you can look at the CSN stamp of what failed and look at the change in the accesslog DB. It sounds like however that the replica syncrepl is simply failing to see the change occur on the master if it isn't logging anything about the missing change. --Quanah -- Quanah Gibson-Mount Principal Software Engineer Zimbra, Inc -------------------- Zimbra :: the leader in open source messaging and collaboration

1 0

Re: (ITS#6320) Replication Issues
by j＠telepaths.org 01 Oct '09

01 Oct '09

Yes, that is the first thing attempted (both via using LOCAL4 -> syslog and via running slapd via cmd line) We see a brand-new server replicate all records (sids, csns, etc all look fine) without incident. An existing server will receive, as I said, all of the changes ... at least for awhile. Nothing in the sync activity looks out of the ordinary (and I have read quite a few posts to be able to discern what the items inside mean) When a replication error occurs, often nothing at all is seen inside the logs (no error mesg, no segfault, nothing) to indicate a failure has occurred. Oftentimes, when SyncRepl fails to replicate, it is NOT during testing, so it is difficult for us to find out exactly WHEN the error occurred, as it could have happened at any point within the past 24 hrs, and up to a week ago. I can try to replicate this error deliberately. Unfortunately it is very difficult to make happen at-will. My concern is that someone will try to close this ticket before I have witnessed the event. Jeff On Oct 1, 2009, at 12:14 PM, Quanah Gibson-Mount wrote: > --On Thursday, October 01, 2009 3:19 AM +0000 j(a)telepaths.org wrote: > >> >> --Apple-Mail-6--965444022 >> Content-Transfer-Encoding: 7bit >> Content-Type: text/plain; >> charset=us-ascii; >> format=flowed > > Have you set the loglevel on all servers to include "sync" level > logging? > > --Quanah > > > -- > > Quanah Gibson-Mount > Principal Software Engineer > Zimbra, Inc > -------------------- > Zimbra :: the leader in open source messaging and collaboration

1 0

Re: (ITS#6320) Replication Issues
by quanah＠zimbra.com 01 Oct '09

01 Oct '09

--On Thursday, October 01, 2009 3:19 AM +0000 j(a)telepaths.org wrote: > > --Apple-Mail-6--965444022 > Content-Transfer-Encoding: 7bit > Content-Type: text/plain; > charset=us-ascii; > format=flowed Have you set the loglevel on all servers to include "sync" level logging? --Quanah -- Quanah Gibson-Mount Principal Software Engineer Zimbra, Inc -------------------- Zimbra :: the leader in open source messaging and collaboration

1 0

Re: (ITS#6319) opened files
by hyc＠symas.com 01 Oct '09

01 Oct '09

M8R-njfnr31(a)mailinator.com wrote: > Full_Name: Miki Manó > Version: 2.4.18 > OS: debian linux > URL: > Submission from: (NULL) (91.120.159.49) > > > hello > > i'm running slapd server with 100 clients over ssl. i see the server don't > close > the file descriptors always and the limit of open files is exceeded. how could > i > help your work to find this bug? > > file limit is reached too with following options: > > idletimeout 60 > writetimeout 60 > > the creation time of file descriptors is older than 60s. Please provide the output from "lsof" on the slapd process. -- -- Howard Chu CTO, Symas Corp. http://www.symas.com Director, Highland Sun http://highlandsun.com/hyc/ Chief Architect, OpenLDAP http://www.openldap.org/project/

1 0

ITS#6312 published: SECURITY: VC++: stdio.h(358) : error C3163: '_vsnprintf': attributes inconsistent with previous declaration
by openldap-its＠OpenLDAP.org 01 Oct '09

01 Oct '09

Private ITS#6312 is now publicly readable URL: http://www.OpenLDAP.org/its/?findid=6312

1 0

ITS#6313 published: SECURITY: VC++: stdio.h(358) : error C3163: '_vsnprintf': attributes inconsistent with previous declaration
by openldap-its＠OpenLDAP.org 01 Oct '09

01 Oct '09

Private ITS#6313 is now publicly readable URL: http://www.OpenLDAP.org/its/?findid=6313

1 0

ITS#6314 published: SECURITY: VC++: stdio.h(358) : error C3163: '_vsnprintf': attributes inconsistent with previous declaration
by openldap-its＠OpenLDAP.org 01 Oct '09

01 Oct '09

Private ITS#6314 is now publicly readable URL: http://www.OpenLDAP.org/its/?findid=6314

1 0

ITS#6315 published: SECURITY: VC++: stdio.h(358) : error C3163: '_vsnprintf': attributes inconsistent with previous declaration
by openldap-its＠OpenLDAP.org 01 Oct '09

01 Oct '09

Private ITS#6315 is now publicly readable URL: http://www.OpenLDAP.org/its/?findid=6315

1 0

2025

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

2010

2009

2008

2007

2006

openldap-bugs