[SRU] (ITS#5518) Assertion error in io.c:234: ber_flush2

I should add that this is more than just xscreensaver that is crapping out with this error.

So after a quick run through the code we find that that the changing of the variable sb->sb_valid (which is what the assert is checking) only happens in one place in sockbuf.c in ber_int_sb_init() and never gets changed again. Therefore we are probably looking at some sort of memory or pointer corruption that ends up twiddling that bit. :(

drewm@frustration:~/openldap2.3-2.4.7$ grep -r sb_valid *
libraries/liblber/lber-int.h:#define sb_valid sb_opts.lbo_valid
libraries/liblber/lber-int.h:#define SOCKBUF_VALID( sb ) ( (sb)->sb_valid == LBER_VALID_SOCKBUF )
libraries/liblber/sockbuf.c: sb->sb_valid=LBER_VALID_SOCKBUF;

I can confirm and reproduce this with my CUPS server hardy 64 bits.
I have a local slave slapd running on the same server, restarting the slapd process causes cupsd to crash with the above assertion in its error log :
root@ifimp:~# ps ax|grep cups
10917 ? Ss 1:04 /usr/sbin/cupsd
18957 pts/0 S+ 0:00 grep cups
root@ifimp:~# /etc/init.d/slapd restart
Stopping OpenLDAP: slapd.
Starting OpenLDAP: slapd.
root@ifimp:~# lpq
lpq: impossible de se connecter au serveur.

100% reproducable here

/var/log/cups/error.log :
I [06/May/2008:15:38:05 +0200] cupsdCloseClient: SSL shutdown successful!
cupsd: /build/buildd/openldap2.3-2.4.7/libraries/liblber/io.c:234: ber_flush2: Assertion `( (sb)->sb_opts.lbo_valid == 0x3 )' failed.

Mik

We find the same assert message in our /var/log/apache2/error.log:

apache2: /build/buildd/openldap2.3-2.4.7/libraries/liblber/io.c:234: ber_flush2: Assertion `( (sb)->sb_opts.lbo_valid == 0x3 )' failed.
[Fri May 09 11:31:31 2008] [notice] child pid 29054 exit signal Aborted (6)

We are using the authnz_ldap_module via apache2 for auth.

We have seen these messages correllating strongly with the frequent authentication failures we're seeing using mercurial with https URLs (ssh:// urls also using LDAP auth seem to be fine).

root@swieten:~# lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description: Ubuntu 8.04
Release: 8.04
Codename: hardy
root@swieten:~# uname -a
Linux swieten 2.6.24-16-server #1 SMP Thu Apr 10 13:15:38 UTC 2008 x86_64 GNU/Linux
root@swieten:~#

#0 0x00007faa07cde095 in raise () from /lib/libc.so.6
#1 0x00007faa07cdfaf0 in abort () from /lib/libc.so.6
#2 0x00007faa07cd72df in __assert_fail () from /lib/libc.so.6
#3 0x00007faa065d33cb in ber_flush2 (sb=0x7faa08009aa0, ber=0x8fe130, freeit=0) at /tmp/openldap2.3-2.4.7/libraries/liblber/io.c:234
#4 0x00007faa06803dcd in ldap_int_flush_request (ld=0x902b30, lr=0x69eaf0) at request.c:152
#5 0x00007faa068044a4 in ldap_send_server_request (ld=0x902b30, ber=0x8fe130, msgid=389, parentreq=0x0, srvlist=0x0, lc=0x655080, bind=0x0) at request.c:348
#6 0x00007faa06803d7a in ldap_send_initial_request (ld=0x902b30, msgtype=99, dn=0x7faa06c44bcf "ou=People,dc=google,dc=com", ber=0x8fe130, msgid=389) at request.c:136
#7 0x00007faa067f0388 in ldap_search (ld=0x902b30, base=0x7faa06c44bcf "ou=People,dc=google,dc=com", scope=1,
   filter=0x7fff1203bf20 "(&(objectClass=posixAccount)(uidNumber=20962))", attrs=0x7faa06c45660, attrsonly=0) at search.c:199
#8 0x00007faa067f08d6 in ldap_search_st (ld=0x902b30, base=0x7faa06c44bcf "ou=People,dc=google,dc=com", scope=1,
   filter=0x7fff1203bf20 "(&(objectClass=posixAccount)(uidNumber=20962))", attrs=0x7faa06c45660, attrsonly=0, timeout=0x7fff1203bdb0, res=0x7fff1203c798) at search.c:357
#9 0x00007faa06a37cc3 in ?? () from /lib/libnss_ldap.so.2
#10 0x00007faa06a37265 in ?? () from /lib/libnss_ldap.so.2
#11 0x00007faa06a37a9c in ?? () from /lib/libnss_ldap.so.2
#12 0x00007faa06a3858b in ?? () from /lib/libnss_ldap.so.2
#13 0x00007faa06a38819 in _nss_ldap_getpwuid_r () from /lib/libnss_ldap.so.2
#14 0x00007faa07d48c90 in getpwuid_r@@GLIBC_2.2.5 () from /lib/libc.so.6
#15 0x00007faa07d48542 in getpwuid () from /lib/libc.so.6
#16 0x000000000040b031 in ?? ()
#17 0x000000000040b680 in ?? ()
#18 0x000000000040b8e1 in ?? ()
#19 0x000000000040c267 in ?? ()
#20 0x0000000000407e68 in ?? ()
#21 0x00007faa07cca1c4 in __libc_start_main () from /lib/libc.so.6
#22 0x0000000000405649 in ?? ()
#23 0x00007fff1203d4b8 in ?? ()
#24 0x0000000000000000 in ?? ()

#0 0x00007f3aafda2095 in raise () from /lib/libc.so.6
#1 0x00007f3aafda3af0 in abort () from /lib/libc.so.6
#2 0x00007f3aafd9b2df in __assert_fail () from /lib/libc.so.6
#3 0x00007f3aae6913cb in ber_flush2 (sb=0x8ffec0, ber=0x902b90, freeit=0) at /tmp/openldap2.3-2.4.7/libraries/liblber/io.c:234
#4 0x00007f3aae8c1dcd in ldap_int_flush_request (ld=0x64cdf0, lr=0x642fe0) at request.c:152
#5 0x00007f3aae8c24a4 in ldap_send_server_request (ld=0x64cdf0, ber=0x902b90, msgid=808, parentreq=0x0, srvlist=0x0, lc=0x644b60, bind=0x0) at request.c:348
#6 0x00007f3aae8c1d7a in ldap_send_initial_request (ld=0x64cdf0, msgtype=99, dn=0x7f3aaed0860f "ou=People,dc=google,dc=com", ber=0x902b90, msgid=808) at request.c:136
#7 0x00007f3aae8ae388 in ldap_search (ld=0x64cdf0, base=0x7f3aaed0860f "ou=People,dc=google,dc=com", scope=1,
   filter=0x7fffba0fffd0 "(&(objectClass=posixAccount)(uidNumber=20962))", attrs=0x7f3aaed090a0, attrsonly=0) at search.c:199
#8 0x00007f3aae8ae8d6 in ldap_search_st (ld=0x64cdf0, base=0x7f3aaed0860f "ou=People,dc=google,dc=com", scope=1,
   filter=0x7fffba0fffd0 "(&(objectClass=posixAccount)(uidNumber=20962))", attrs=0x7f3aaed090a0, attrsonly=0, timeout=0x7fffba0ffe60, res=0x7fffba100848) at search.c:357
#9 0x00007f3aaeaf5337 in do_search_s (base=0x7f3aaed0860f "ou=People,dc=google,dc=com", scope=1, filter=0x7fffba0fffd0 "(&(objectClass=posixAccount)(uidNumber=20962))",
   attrs=0x7f3aaed090a0, sizelimit=1, res=0x7fffba100848) at ldap-nss.c:2686
#10 0x00007f3aaeaf503f in do_with_reconnect (base=0x7f3aaed0860f "ou=People,dc=google,dc=com", scope=1, filter=0x7fffba0fffd0 "(&(objectClass=posixAccount)(uidNumber=20962))",
   attrs=0x7f3aaed090a0, sizelimit=1, private=0x7fffba100848, search_func=0x7f3aaeaf5288 <do_search_s>) at ldap-nss.c:2577
#11 0x00007f3aaeaf5c28 in _nss_ldap_search_s (args=0x7fffba1008c0, filterprot=0x7f3aaed0fba0 "(&(objectClass=posixAccount)(uidNumber=%d))", sel=LM_PASSWD, user_attrs=0x0,
   sizelimit=1, res=0x7fffba100848) at ldap-nss.c:3101
#12 0x00007f3aaeaf66b0 in _nss_ldap_getbyname (args=0x7fffba1008c0, result=0x7f3ab00ce8a0, buffer=0x63a070 "statd", buflen=1024, errnop=0x7f3ab20dd698,
   filterprot=0x7f3aaed0fba0 "(&(objectClass=posixAccount)(uidNumber=%d))", sel=LM_PASSWD, parser=0x7f3aaeaf7aa0 <_nss_ldap_parse_pw>) at ldap-nss.c:3448
#13 0x00007f3aaeaf7fec in _nss_ldap_getpwuid_r (uid=20962, result=0x7f3ab00ce8a0, buffer=0x63a070 "statd", buflen=1024, errnop=0x7f3ab20dd698) at ldap-pwd.c:230
#14 0x00007f3aafe0cc90 in getpwuid_r@@GLIBC_2.2.5 () from /lib/libc.so.6
#15 0x00007f3aafe0c542 in getpwuid () from /lib/libc.so.6
#16 0x000000000040b031 in initialize_screensaver_window_1 (ssi=0x8f45f0) at windows.c:915
#17 0x000000000040b680 in initialize_screensaver_window (si=0x7fffba101040) at windows.c:1575
#18 0x000000000040b8e1 in raise_window (si=0x72106, inhibit_fade=0, between_hacks_p=0, dont_clear=0) at windows.c:1735
#19 0x000000000040c267 in blank_screen (si=0x7fffba101040) at windows.c:1923
#20 0x0000000000407e68 in main (argc=1, argv=<value optimized out>) at xscreensaver.c:1198

I have opened a bug about this upstream with the openldap developers.

Thanks
chuck

In frame 3, can you please print *sb, and in frame 4, print *ld, print *lr and attach the info here, thanks.

I've attached a bt full with *sb in frame 3, and *ld/*lr in frame 4. This is similar to backtrace #3 which Andrew Pollock provides earlier, but from a different session. I'm happy to provide more (or print different vars) if it's helpful.

Yes, that helps. Please also print *lc from frame 4, thanks.

(gdb) f 4
#4 0x00007f3a0fb07dcd in ldap_int_flush_request (ld=0x693d90, lr=0x699050) at request.c:152
152 if ( ber_flush2( lc->lconn_sb, lr->lr_ber, LBER_FLUSH_FREE_NEVER ) != 0 ) {
(gdb) print *lc
$4 = {lconn_sb = 0x7f3a11313ab0, lconn_sasl_authctx = 0x7f3a11313ab0, lconn_sasl_sockctx = 0x6c6e65706f2f706d,
  lconn_refcnt = 846225764, lconn_created = 7091318038316594222, lconn_lastused = 7795576359399612786,
  lconn_rebind_inprogress = 1651270249, lconn_rebind_queue = 0x3a3433323a632e6f, lconn_status = 1919246880,
  lconn_server = 0x737341203a326873, lconn_ber = 0x60206e6f69747265, lconn_next = 0x3e2d296273282028}

Hmmm, *lc is completely bogus. 7f3a11313ab0 is clearly in the text segment of the process, and the values starting from lconn_sasl_sockctx are ASCII:

00: 6d 70 2f 6f 70 65 6e 6c 64 61 70 32 2e 34 2e 37 mp/openldap2.4.7
01: 2f 6c 69 62 72 61 72 69 65 73 2f 6c 69 62 6c 62 /libraries/liblb
02: 6f 2e 63 3a 32 33 34 3a 20 62 65 72 73 68 32 3a o.c:234: bersh2:
03: 20 41 73 73 65 72 74 69 6f 6e 20 60 28 20 28 73 Assertion `( (s
04: 62 29 2d 3e 00 00 b)->

I.e., lc's contents are a copy of the actual text location where the assert message was stored.

This would have made more sense if it was random data. Hard to see how a data or stack overwrite could cause pieces of the text segment to get copied into the heap, and ordinarily an assert/abort call doesn't trash the stack like this.

Can you reproduce this bug when libldap, liblber, and nss_ldap are compiled without any optimization?

I found this bug, I think. We're getting identical problems causing Evolution Exchange to crash. The problem is ldap is accessing memory after it's been freed.

Here's the Gnome bug with lots of backtraces and some valgrind logs I used to figure it out:

http://bugzilla.gnome.org/show_bug.cgi?id=512605

and here's the new bug I filed with openldap describing the issue:

http://www.openldap.org/its/index.cgi/Incoming?id=5525;page=1;statetype=1

Marked Evolution Exchange bug as a duplicate.

Looks like my DEB_BUILD_OPTS of noopt wasn't working, I've explicitly set -O0 in my CFLAGS now, and rebuilt. I've yet to manage to reproduce the problem since, but will keep trying.

Please test this patch and let me know if you can still reproduce this failure.

http://www.openldap.org/lists/openldap-commit/200805/msg00112.html

Hi,

Ive added the patch to my openldap test ppa, could you please test with the one found at:

http://launchpad.net/~zulcss/+archive

Thanks
chuck

I no longer seem to be getting the assertion error with this patch. This is again with -O2, as I had trouble reproducing with -O0. I do now somtimes get a SIGPIPE, which is less harmful (eg, xscreensaver is still running).

I've loaded up these libraries to test the Evo Exchange crasher. Unfortunately there was no reliable way to reproduce it; you just had to do lots of work and eventually it would happen. However, I've added a debugging message to the code so that I'll know when I've hit a point where it SHOULD have happened, so I can see if it proceeds correctly in that situation or not. Also unfortunately my company is moving to a new building this weekend so the Exchange server is down at the moment (but should be up later tonight).

Hi,

these packages seems to fix all my problems too, no more segfault since I have them installed

Cheers,
Mik

Great, thanks for the followup. This patch is going in OpenLDAP 2.3.42 and 2.4.10.

Hello,

This bug seems to affect multiple software that has libldap linked against it. I have backported the patch from the openldap CVS tree and made it available in my ppa.

TEST CASE:

1. Enable LDAP authentication.
2. Check for xscreensaver crashes

If you have any questions please feel free to ask.

Thanks
chuck

Accepted into -proposed, please test and give feedback here

Just for info:

This also causes the DBus system daemon to randomly crash without any messages in the log files.

it seems I am still getting a few crashes by night,
occured twice with the new packages : both master and slave (different servers) crashed around 0:00
I thought it could be related to log rotation, but that seems to be a 6:00am thing, so I don't know why it crashes at 0:00
anybody else got these kind of crashes ?

Mik

What "these kind" ? Provide a stack trace.

This bug was fixed in the package openldap2.3 - 2.4.9-1ubuntu1

---------------
openldap2.3 (2.4.9-1ubuntu1) intrepid; urgency=low

  * Merge from debian unstable, remaining changes:
    - debian/apparmor-profile: add AppArmor profile
    - debian/slapd.postinst: Reload AA profile on configuration
    - updated debian/slapd.README.Debian for note on AppArmor
    - debian/control: Recommends apparmor >= 2.1+1075-0ubuntu6
    - debian/control: Conflicts with apparmor-profiles << 2.1+1075-0ubuntu4
      to make sure that if earlier version of apparmour-profiles gets
      installed it won't overwrite our profile.
    - Modify Maintainer value to match the DebianMaintainerField
      speficication.
    - follow ApparmorProfileMigration and force apparmor compalin mode on
      some upgrades (LP: #203529)
    - debian/slapd.dirs: add etc/apparmor.d/force-complain
    - debian/slapd.preinst: create symlink for force-complain on pre-feisty
      upgrades, upgrades where apparmor-profiles profile is unchanged (ie
      non-enforcing) and upgrades where apparmor profile does not exist.
    - debian/slapd.postrm: remove symlink in force-complain/ on purge
    - debian/rules, debian/slapd.links: use hard links to slapd instead of
      symlinks for slap* so these applications aren't confined by apparmor
      (LP: #203898)
    - debian/patches/fix-assertion-io.patch: Fixes ber_flush2 assertion.
      (LP: #215904)
    - debian/patches/fix-dnpretty-assertion.patch: Fix dnPrettyNormal assertion
      error. (LP: #234196)
    - dropped debian/patches/fix-notify-crasher.patch: Fix modify timestamp crashes.
      (LP: #220724)
    - dropped debian/patches/SECURITY_CVE-2008-0658.patch. Already applied
      upstream.
   * Added debian/patches/fix-ucred-libc due to changes how newer glibc handle
     the ucred struct now.

openldap2.3 (2.4.9-1) unstable; urgency=low

  [ Updated debconf translations ]
  * French, thanks to Christian Perrier <email address hidden>.
    Closes: #471792.
  * Finnish, thanks to Esko Arajärvi <email address hidden>. Closes: #475238.
  * Czech, thanks to Miroslav Kure <email address hidden>.
    Closes: #480138.
  * Basque, thanks to Piarres Beobide <email address hidden>.
    Closes: #480177.
  * Vietnamese, thanks to Clytie Siddall <email address hidden>.
    Closes: #480181.
  * Galician, thanks to Jacobo Tarrio <email address hidden>. Closes: #480218.
  * Japanese, thanks to Kenshi Muto <email address hidden>. Closes: #480247.
  * Italian, thanks to Luca Monducci <email address hidden>. (Closes: #477718)
  * Brazilian Portuguese, thanks to Eder L. Marques <email address hidden>
    (Closes: #480172)
  * Portuguese, thanks to Tiago Fernandes <email address hidden>
    (Closes: #481126)
  * Russian, thanks to Yuri Kozlov <email address hidden> (Closes: #481214)
  * Dutch, thanks to "cobaco (aka Bart Cornelis)" <email address hidden>.
    Closes: #483014.

  [ Matthijs Mohlmann ]
  * New upstream release.
    - Bad entryUUID no longer crashes slapd. (Closes: #471867)
    - Fix assertion failure in some modify operations. (Closes: #474161)
    - Mention index in slapd.conf's man page. (Closes: #414650)
    - Fixes to slapd include handl...

We see this in our apache error.log using ldap auth for our production svn server. Eagerly awaiting fix to hit hardy...

We are noticing this when running django development server and unit tests. We're also eagerly awaiting fix to hit hardy.

Will the fix find its way into libapache2-svn on hardy? that is where I need it...
Thanks.

The bug is in the libldap package. When you get a new version of that (which I believe is out now, even for the standard repositories) then all applications that use LDAP (including Evolution, xscreensaver, Apache, etc.) will use it and have the fix.

There's no need for a new Apache package, because there's been no ABI change and so no need to rebuild Apache.

It's the miracle of shared libraries!! :-)

thanks but if it's in hardy I don't see it, this is what I have:
root@server:/svn# aptitude search libldap
i A libldap-2.4-2 - OpenLDAP libraries
p libldap-2.4-2-dbg - Debugging information for OpenLDAP libraries
v libldap-dev -
p libldap-ocaml-dev - LDAP bindings for OCaml
p libldap-ruby1.8 - OpenLDAP library binding for Ruby 1.8
c libldap2 - OpenLDAP libraries
p libldap2-dev - OpenLDAP development libraries
v libldap2-tls -
root@server:/svn# aptitude show libldap-2.4-2
Package: libldap-2.4-2
New: yes
State: installed
Automatically installed: no
Version: 2.4.7-6ubuntu4.1
Priority: important
Section: libs
Maintainer: Ubuntu Core Developers <email address hidden>
Uncompressed Size: 475k
Depends: libc6 (>= 2.4), libgnutls13 (>= 2.0.4-0), libsasl2-2
Conflicts: ldap-utils (<= 2.1.23-1)
Replaces: libldap-2.3-0, libldap2
Description: OpenLDAP libraries
 These are the run-time libraries for the OpenLDAP (Lightweight Directory Access Protocol) servers and
 clients.
Homepage: http://www.openldap.org/

This is what my apache error.log shows almost every hour:
apache2: /build/buildd/openldap2.3-2.4.7/libraries/liblber/io.c:234: ber_flush2: Assertion `( (sb)->sb_opts.lbo_valid == 0x3 )' failed.
[Mon Jun 09 10:16:25 2008] [notice] child pid 6574 exit signal Aborted (6)

Hi,

Please enable hardy-proposed in your /etc/apt/sources.list, so we can get some testing done for 8.04.1

Thanks
chuck

This is still in -proposed? I think it's pretty clear what this bug is and that it's fixed by the update; we've had a number of people testing it and reporting success already. Plus, if you look at the actual patch, it's pretty clear that it fixes the problem.

IMHO this should get promoted out of -proposed and into the standard repo quickly. This is a crasher that impacts a wide range of software. What exactly is the criteria needed to approve the the promote? Maybe we need to figure out a way that this bug is really a security issue :-).

Thanks!

Actually Paul, your last comment regarding the bug status here was that you'd be testing, but you hadn't actually posted a confirmation that your problem was resolved.

And MikMak still hasn't provided any further details on whatever crash he's still seeing. So while I'm certain that the patch is correct, there are some loose ends left on this bug report.

The patches fixes random DBus crashes here. We experienced no further problems.

Sorry, I didn't realize people were waiting for me. I have no recipe for reliably reproducing the problem using Evolution so I can't be 100% sure that it's been fixed. However, I've been using the fix since Chuck posted his PPA version on 23 May, and -proposed version since it was uploaded, and I've never had this crash happen since. So, insofar as I can be, I'm sure this bug is crushed.

Cheers!

well I haven't been able to reproduce the crash so far, so might be some
mistake of my own :/
I'll post here if I can new crashes, but for now, it's rock solid.

I am all for pushing it asap for release

Cheers
Mik

On lun, jun 09, 2008 at 07:40:33 -0000, Howard Chu wrote:
> Actually Paul, your last comment regarding the bug status here was that
> you'd be testing, but you hadn't actually posted a confirmation that
> your problem was resolved.
>
> And MikMak still hasn't provided any further details on whatever crash
> he's still seeing. So while I'm certain that the patch is correct, there
> are some loose ends left on this bug report.
>
> --
> [SRU] (ITS#5518) Assertion error in io.c:234: ber_flush2
> https://bugs.launchpad.net/bugs/215904
> You received this bug notification because you are a direct subscriber
> of the bug.

We've had this issue since we moved from svn+ssh to our http based svn with ldap auth. That move also took us from RHEL5 to Hardy so I've been seeing this issue in our apache logs since a week after hardy was out.
We have about 40 svn devs and today alone the:
apache2: /build/buildd/openldap2.3-2.4.7/libraries/liblber/io.c:234: ber_flush2: Assertion `( (sb)->sb_opts.lbo_valid == 0x3 )' failed.
appeared 7 times in the log starting from when people showed up for work around 0900 using it until the patch was applied at 14:51.

It is now 17:15 and no more errors. Even in this short time I can safely say it resolved the issue for us. Thanks guys!

Copied to hardy-updates. Thanks for all the testing feedback!

Do you think the backtrace in bug #239184 is related to this bug?

I don't see this package in hardy-updates, am I missing something ? I'm able to reproduce the crash with Evolution exchange always. Can I get the deb package ? I can verify and update this bug.