dbus-daemon crashed with SIGSEGV in strcmp()

[Dave Pucknell]

Binary package hint: dbus

happens on start up

ProblemType: Crash
Architecture: i386
CrashCounter: 1
Date: Thu Jul 26 20:15:24 2007
DistroRelease: Ubuntu 7.10
ExecutablePath: /usr/bin/dbus-daemon
Package: dbus 1.1.1-3ubuntu1
PackageArchitecture: i386
ProcCmdline: dbus-daemon --fork --print-address 18 --print-pid 20 --session
ProcCwd: /
ProcEnviron:
 PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games
 LANG=en_GB.UTF-8
 SHELL=/bin/bash
Signal: 11
SourcePackage: dbus
StacktraceTop:
 strcmp () from /lib/tls/i686/cmov/libc.so.6
 ?? ()
 ?? ()
 ?? ()
 ?? ()
Title: dbus-daemon crashed with SIGSEGV in strcmp()
Uname: Linux dave-laptop 2.6.22-8-generic #1 SMP Thu Jul 12 15:59:45 GMT 2007 i686 GNU/Linux
UserGroups: adm admin audio cdrom dialout dip fax floppy fuse lpadmin netdev plugdev powerdev scanner tape video

[Apport retracing service (apport)]

StacktraceTop:strcmp () from /lib/tls/i686/cmov/libc.so.6
find_generic_function (table=0x80978b0, key=0x80aeb80, idx=<value optimized out>, compare_func=0xb7e07ff0 <strcmp>, create_if_not_found=1, bucket=0x0,
_dbus_hash_table_insert_string_preallocated (table=0x80978b0, preallocated=0x80bbbe8, key=0x80aeb80 "dave", value=0x80b3ae8) at dbus-hash.c:1680
_dbus_hash_table_insert_string (table=0x80978b0, key=0x80aeb80 "dave", value=0x80b3ae8) at dbus-hash.c:1443
_dbus_user_database_lookup (db=0x80977c8, uid=1000, username=0x80b2278, error=0x0) at dbus-userdb.c:208

[James Westby (james-w)]

Hi,

I believe this problem has been fixed upstream and will be fixed in
Intrepid in the next version.

Thanks,

James

[Ed (cosedi)]

In which version of dbus is this fixed? or is there a patch floating around that fixes this issue? Thanks!

[Ed (cosedi)]

Oh sorry I missed this link in the far left corner:

    * [Edit] freedesktop-bugs #15588
      [RESOLVED FIXED]

https://bugs.freedesktop.org/show_bug.cgi?id=15588

[Jeremy Wilkins (wjeremy)]

Finally, I thought this error was specific to my machine because I couldn't find a relevant bug report for over 6 months. I hope to see the intrepid dbus update fix this since it has been quite a pain with my power management on my laptop.

[Per (per-mathisen)]

I can reproduce a crash in dbus-daemon when terminating a master process, that communicates with the session bus, which has several child processes that also communicate with the same bus.

I am running dbus-1.1.2-9.fc8 (standard install of dbus on Fedora 8).

Let me know if there is anything else you need to debug this problem.

[developer@cobra ~]$ gdb -p 3023
....
Program received signal SIGPIPE, Broken pipe.
[Switching to Thread 140547178473344 (LWP 3023)]
0x0000000000e6e923 in __libc_writev (fd=33, vector=0x7fffb8ac69e0,
count=2) at ../sysdeps/unix/sysv/linux/writev.c:46
46 bytes_written = INLINE_SYSCALL (writev, 3, fd, CHECK_N
(vector, count), count);
(gdb) bt
#0 0x0000000000e6e923 in __libc_writev (fd=33, vector=0x7fffb8ac69e0,
count=2) at ../sysdeps/unix/sysv/linux/writev.c:46
#1 0x00007fd3b0aab445 in _dbus_write_two (fd=33, buffer1=<value
optimized out>, start1=<value optimized out>, len1=-32,
   buffer2=0x7fd3b1983cd8, start2=0, len2=45) at dbus-sysdeps-unix.c:415
#2 0x00007fd3b0aa4888 in do_writing (transport=0x7fd3b1965f40) at
dbus-transport-socket.c:597
#3 0x00007fd3b0aa4ac2 in socket_do_iteration
(transport=0x7fd3b1965f40, flags=1, timeout_milliseconds=-1)
   at dbus-transport-socket.c:991
#4 0x00007fd3b0aa36a4 in _dbus_transport_do_iteration
(transport=0x7fd3b1965f40, flags=1, timeout_milliseconds=-1)
   at dbus-transport.c:942
#5 0x00007fd3b0a990ee in _dbus_connection_do_iteration_unlocked
(connection=0x7fd3b1966350, flags=1, timeout_milliseconds=-1)
   at dbus-connection.c:1143
#6 0x00007fd3b0a991a8 in
_dbus_connection_send_preallocated_unlocked_no_update
(connection=0x7fd3b1966350,
   preallocated=0x7fd3b19857d0, message=0x7fd3b1983c90,
client_serial=0x0) at dbus-connection.c:1929
#7 0x00007fd3b0a99b19 in
_dbus_connection_send_preallocated_and_unlock (connection=0x21,
preallocated=0x7fffb8ac69e0,
   message=0x2, client_serial=0xffffffffffffffff) at dbus-connection.c:1948
#8 0x00007fd3b0a8c860 in bus_transaction_execute_and_free
(transaction=0x7fd3b197b0c0) at connection.c:2102
#9 0x00007fd3b0a8df35 in bus_connection_disconnected
(connection=0x7fd3b19271f0) at connection.c:225
#10 0x00007fd3b0a8f312 in bus_dispatch_message_filter
(connection=0x7fd3b19271f0, message=0x7fd3b1955b60,
   user_data=<value optimized out>) at dispatch.c:186
#11 0x00007fd3b0a997b0 in dbus_connection_dispatch
(connection=0x7fd3b19271f0) at dbus-connection.c:4350
#12 0x00007fd3b0aacee8 in _dbus_loop_dispatch (loop=0x7fd3b19146b0) at
dbus-mainloop.c:482
#13 0x00007fd3b0aad283 in _dbus_loop_iterate (loop=0x7fd3b19146b0,
block=1) at dbus-mainloop.c:848
#14 0x00007fd3b0aad4cd in _dbus_loop_run (loop=0x7fd3b19146b0) at
dbus-mainloop.c:874
#15 0x00007fd3b0a96da1 in main (argc=7, argv=<value optimized out>) at
main.c:464

(gdb) p *vector
$2 = {iov_base = 0x7fd3b19a9d00, iov_len = 160}

(gdb) up
(gdb) p *buffer2
$3 = {dummy1 = 0x7fd3b19a3460, dummy2 = 45, dummy3 = 172, dummy4 =
2147483639, dummy5 = 0, dummy6 = 0, dummy7 = 0, dummy8 = 0}

(gdb) up
(gdb) p *transport
$4 = {refcount = 2, vtable = 0x7fd3b0cca9e0, connection =
0x7fd3b1966350, loader = 0x7fd3b1941cd0, auth = 0x7fd3b1966030,
 credentials = 0x7fd3b19661f0, max_live_messages_size = 100...

[Colin Walters (walters)]

Hm, I think SIGPIPE is a normal thing to get here. You should do in gdb:

handle SIGPIPE nostop pass

[lcampagn (luke-campagnola)]

Any chance the fix released upstream will make it into Hardy? From the
description, it looked like it dbus just needs to be compiled with an
extra flag enabled. I know intrepid is coming up soon, but this bug
crashes my machine on a daily basis, and a lot of people like myself
will be hanging on to Hardy a bit longer due to KDE4.

[Per (per-mathisen)]

I finally managed to get the crash while gdb was tracing the dbus process. This time it was not a bogus SIGPIPE. Again, this happened while shutting down a host of processes running on dbus.

I have saved the core file, so if you need anything else, let me know.

Backtrace:

Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 140407117903744 (LWP 11324)]
0x0000000000e1a012 in strcmp () from /lib64/libc.so.6
(gdb) bt full
#0 0x0000000000e1a012 in strcmp () from /lib64/libc.so.6
        mallstream = (FILE *) 0x0
        tr_old_memalign_hook = (void *(*)(size_t, size_t, const void *)) 0
        tr_old_malloc_hook = (void *(*)(size_t, const void *)) 0
        tr_old_realloc_hook = (void *(*)(void *, size_t, const void *)) 0
        lock = 0
        mallenv = "MALLOC_TRACE"
        malloc_trace_buffer = 0x0
        tr_old_free_hook = (void (*)(void *, const void *)) 0
        mallwatch = (void *) 0x0
#1 0x00007fb31467abee in find_generic_function (table=0x7fb3155893f0, key=0x7fb3155973b0, idx=10,
    compare_func=0xe1a010 <strcmp>, create_if_not_found=1, bucket=0x0, preallocated=0x7fb315607828)
    at dbus-hash.c:918
        entry = (DBusHashEntry *) 0x7fb3156077f8
#2 0x00007fb31467aea6 in find_string_function (table=0x7fb3155893f0, key=0x7fb3155973b0,
    create_if_not_found=1, bucket=0x0, preallocated=0x7fb315607828) at dbus-hash.c:952
No locals.
#3 0x00007fb31467a8b1 in _dbus_hash_table_insert_string_preallocated (table=0x7fb3155973b0,
    preallocated=0x7fb315607828, key=0x7fb3155973b0 "developer", value=0x7fb3155ab350) at dbus-hash.c:1680
        entry = <value optimized out>
#4 0x00007fb31467aad9 in _dbus_hash_table_insert_string (table=0x7fb3155893f0,
    key=0x7fb3155973b0 "developer", value=0x7fb3155ab350) at dbus-hash.c:1443
        preallocated = (DBusPreallocatedHash *) 0xffffff64
#5 0x00007fb31468171e in _dbus_user_database_lookup (db=0x7fb315589260, uid=500, username=0x7fb3155e9fb0,
    error=0x0) at dbus-userdb.c:208
        info = (DBusUserInfo *) 0x7fb3155ab350
#6 0x00007fb3146817e3 in _dbus_user_database_get_username (db=0x7fb3155973b0, username=0xa,
    info=0x7fff1c69b610, error=0xffffffff) at dbus-userdb.c:661
No locals.
#7 0x00007fb314681a2d in _dbus_credentials_add_from_user (credentials=0x7fb3155eb8d0,
    username=0x7fb3155e9fb0) at dbus-userdb.c:507
        db = (DBusUserDatabase *) 0xffffff64
        info = (const DBusUserInfo *) 0x7fb3155e9f60
#8 0x00007fb3146875fe in handle_server_data_external_mech (auth=0x7fb3155e9f60, data=0x7fff1c69b650)
    at dbus-auth.c:1065
No locals.
#9 0x00007fb3146867cb in process_data (auth=0x7fb3155e9f60, args=0x7fff1c69b6a0,
    data_func=0x7fb3146874f0 <handle_server_data_external_mech>) at dbus-auth.c:1606
        end = 6
        decoded = {dummy1 = 0x7fb315595160, dummy2 = 3, dummy3 = 16, dummy4 = 2147483639, dummy5 = 0,
  dummy6 = 0, dummy7 = 0, dummy8 = 0}
#10 0x00007fb3146869eb in handle_server_state_waiting_for_auth (auth=0x7fb3155e9f60,
    command=<value optimized out>, args=0x7fff1c69b720) at dbus-auth.c:1658
        i = 9
        mech = {dummy1 = 0x7fb3155e4750, dummy2 = 8, dummy3 = 16, dummy4 = 2147483639, dummy5 = 0,
  dummy6 = 0, d...

[Colin Walters (walters)]

Looks like a valid crash. Note this is against 1.2.2 (Fedora 8). Quick analysis:

* We had some changes in this function quite recently. There was a bug where the userdb cache was mistakenly disabled.
* There were also important fixes to dbus-sysdeps-unix.c:fill_user_info which this depends on.

Per, do you have a minimized test case you can post for this bug? If not - is the bug strongly related to the parent-child relationship, or should I be able to make a test case of just multiple processes connecting to the bus and getting killed?

[Hew (hew)]

Marking Fix Released, as the upstream fix is now in Ubuntu. Thanks for your report.

[Adam Collard (adam-collard)]

This bug contains the crasher upstream. The other bug #15588 is about the #ifdef mix up

[Mark Seaborn (mseaborn-cmedresearch)]

I hit this problem in the version of dbus in Ubuntu hardy (1.1.20-1ubuntu3.2). I can reproduce it using valgrind or electric-fence.

With valgrind (note that the version in hardy doesn't work; I used the version from Ubuntu jaunty):
$ valgrind dbus-1.1.20/bus/dbus-daemon --session --print-address=10 10>/tmp/dbus-address
(and in another terminal:)
$ DBUS_SESSION_BUS_ADDRESS=$(cat /tmp/dbus-address) python -c "import dbus; dbus.SessionBus()"

valgrind produces the following warning twice:
==9193== Invalid read of size 1
==9193== at 0x56A09EE: strcmp (mc_replace_strmem.c:337)
==9193== by 0x135BCC: find_generic_function (dbus-hash.c:918)
==9193== by 0x1357FE: _dbus_hash_table_insert_string_preallocated (dbus-hash.c:1680)
==9193== by 0x135AD1: _dbus_hash_table_insert_string (dbus-hash.c:1443)
==9193== by 0x13E6ED: _dbus_user_database_lookup (dbus-userdb.c:208)
==9193== by 0x13E822: _dbus_user_database_get_username (dbus-userdb.c:659)
==9193== by 0x13EB2F: _dbus_credentials_add_from_user (dbus-userdb.c:505)
==9193== by 0x145570: handle_server_data_external_mech (dbus-auth.c:1066)
==9193== by 0x14454C: process_data (dbus-auth.c:1607)
==9193== by 0x1447AA: handle_server_state_waiting_for_auth (dbus-auth.c:1659)
==9193== by 0x143BF4: _dbus_auth_do_work (dbus-auth.c:2101)
==9193== by 0x132B45: _dbus_transport_get_is_authenticated (dbus-transport.c:687)
==9193== Address 0x77e6030 is 0 bytes inside a block of size 9 free'd
==9193== at 0x569EDFA: free (vg_replace_malloc.c:323)
==9193== by 0x138360: dbus_free (dbus-memory.c:644)
==9193== by 0x13E31F: _dbus_user_info_free (dbus-userdb.c:78)
==9193== by 0x13E3A5: _dbus_user_info_free_allocated (dbus-userdb.c:49)
==9193== by 0x1357AF: _dbus_hash_table_insert_ulong (dbus-hash.c:1610)
==9193== by 0x13E6CC: _dbus_user_database_lookup (dbus-userdb.c:201)
==9193== by 0x13E822: _dbus_user_database_get_username (dbus-userdb.c:659)
==9193== by 0x13EB2F: _dbus_credentials_add_from_user (dbus-userdb.c:505)
==9193== by 0x145570: handle_server_data_external_mech (dbus-auth.c:1066)
==9193== by 0x14454C: process_data (dbus-auth.c:1607)
==9193== by 0x1447AA: handle_server_state_waiting_for_auth (dbus-auth.c:1659)
==9193== by 0x143BF4: _dbus_auth_do_work (dbus-auth.c:2101)

With gdb:
$ gdb --args dbus-1.1.20/bus/dbus-daemon --session --print-address=12 12>/tmp/dbus-address
(gdb) set environment LD_PRELOAD /usr/lib/libefence.so.0.0
(gdb) run
(and in another terminal:)
$ DBUS_SESSION_BUS_ADDRESS=$(cat /tmp/dbus-address) python -c "import dbus; dbus.SessionBus()"

To fix, apply the patch in Bug 15588 and use --enable-userdb-cache.

[Mark Seaborn (mseaborn-cmedresearch)]

*** Bug 15589 has been marked as a duplicate of this bug. ***

[Michael Blinn (mblinn-gmail)]

Would love to see this in Hardy, as I run two Hardy LTSP servers and they go.down.hard about once a month with something akin to the following:

kernel [2304380.017052] dbus-daemon[7508]: segfault at 7f53f08b8780 rip 7f53ef81eae2 rsp 7ffff83d59f8 error 4
followed quickly by the deaths of seahorse, Network-Manager, avahi, consolekit-daemon and hal

[Michael Blinn (mblinn-gmail)]

Had a dbus segfault again today - just happened to be 3 seconds after restarting NIS on a slave+client server.

Here's a few lines of logs, perhaps it'll help:

Jul 8 14:01:10 servername ypserv[7018]: Reloading securenets file
Jul 8 14:01:10 servername ypserv[7018]: Reloading /etc/ypserv.conf
Jul 8 14:01:13 servername kernel: [741132.171330] dbus-daemon[6856]: segfault at bd167b90 rip 7f0ab45b1080 rsp 7fffbd167a88 error 4
Jul 8 14:01:13 servername avahi-daemon[6989]: Disconnected from D-Bus, exiting.
Jul 8 14:01:13 servername avahi-daemon[6989]: Got SIGQUIT, quitting.
Jul 8 14:01:14 servername avahi-daemon[6989]: Leaving mDNS multicast group on interface eth1.IPv4 with address 1.2.3.4.
Jul 8 14:01:14 servername avahi-daemon[6989]: Leaving mDNS multicast group on interface eth0.IPv4 with address 192.168.0.1.
Jul 8 14:01:16 servername ypbind[1558]: Connection to D-BUS system message bus failed: Failed to connect to socket /var/run/dbus/system_bus_socket: Connection refused.
Jul 8 14:01:16 servername ypbind[1558]: Assuming online mode
Jul 8 14:01:16 servername console-kit-daemon[7882]: WARNING: Couldn't connect to system bus: Failed to connect to socket /var/run/dbus/system_bus_socket: Connection refused
Jul 8 14:01:19 servername kernel: [741137.478268] end_request: I/O error, dev fd0, sector 0
Jul 8 14:01:19 servername kernel: [741137.505956] end_request: I/O error, dev fd0, sector 0
Jul 8 14:01:19 servername console-kit-daemon[7882]: WARNING: Couldn't connect to system bus: Failed to connect to socket /var/run/dbus/system_bus_socket: Connection refused

[Simon McVittie (smcv)]

On Bug #15589, Scott wrote this useful-looking summary of the bug:
> D-Bus relies on the userdb cache being enabled to be able to hold on to user
> info structures (which don't have refcounting).
>
> Test case:
> 1) disable the userdb cache
> 2) start a minimal dbus server
> 3) connect to it _from the same username_
>
> The server will have already looked up its own username, and will be holding on
> to the info for that (to compare it against users coming in, I suspect).
>
> When the new connection comes in, it will look up the username of *that*, which
> will invalidate the existing entry in the hash table. Then when it compares
> the new info with the info of its own user, you'll be reading from free'd
> memory.
>
> This could be partially fixed by not putting new info entries into the hash
> table, but then there'd be a memory leak for every time you looked one up,
> since it won't be clear who owns it.

Dropping priority and severity since this now only happens in a non-default compile-time configuration (you have to disable the userdb cache explicitly).

[Chengwei-yang-cn (chengwei-yang-cn)]

See #bug 15588

[Chengwei-yang-cn (chengwei-yang-cn)]

#0 0x0000000000e1a012 in strcmp () from /lib64/libc.so.6
        mallstream = (FILE *) 0x0
        tr_old_memalign_hook = (void *(*)(size_t, size_t, const void *)) 0
        tr_old_malloc_hook = (void *(*)(size_t, const void *)) 0
        tr_old_realloc_hook = (void *(*)(void *, size_t, const void *)) 0
        lock = 0
        mallenv = "MALLOC_TRACE"
        malloc_trace_buffer = 0x0
        tr_old_free_hook = (void (*)(void *, const void *)) 0
        mallwatch = (void *) 0x0
#1 0x00007fb31467abee in find_generic_function (table=0x7fb3155893f0, key=0x7fb3155973b0, idx=10,
    compare_func=0xe1a010 <strcmp>, create_if_not_found=1, bucket=0x0, preallocated=0x7fb315607828)
    at dbus-hash.c:918
        entry = (DBusHashEntry *) 0x7fb3156077f8
#2 0x00007fb31467aea6 in find_string_function (table=0x7fb3155893f0, key=0x7fb3155973b0,
    create_if_not_found=1, bucket=0x0, preallocated=0x7fb315607828) at dbus-hash.c:952
No locals.
#3 0x00007fb31467a8b1 in _dbus_hash_table_insert_string_preallocated (table=0x7fb3155973b0,
    preallocated=0x7fb315607828, key=0x7fb3155973b0 "developer", value=0x7fb3155ab350) at dbus-hash.c:1680
        entry = <value optimized out>
#4 0x00007fb31467aad9 in _dbus_hash_table_insert_string (table=0x7fb3155893f0,
    key=0x7fb3155973b0 "developer", value=0x7fb3155ab350) at dbus-hash.c:1443
        preallocated = (DBusPreallocatedHash *) 0xffffff64
#5 0x00007fb31468171e in _dbus_user_database_lookup (db=0x7fb315589260, uid=500, username=0x7fb3155e9fb0,

Seems it's different with #bug 15588, From the above backtrace, it fail due to update userdb table, after #bug 15588 fixed, this can only happen if compiling with "--disable-userdb-cache" because it still try to update userdb hash table, this is not necessary because userdb cache disabled by user.

So here is a patch to fix it.

[Chengwei-yang-cn (chengwei-yang-cn)]

Created attachment 82467
[PATCH] Do not update user db cache if build with "--disable-userdb-cache"

[Chengwei-yang-cn (chengwei-yang-cn)]

(In reply to comment #9)
> Created attachment 82467 [details] [review]
> [PATCH] Do not update user db cache if build with "--disable-userdb-cache"

verified with valgrind before/after applying this patch, it works fine.

BTW, I'd like to open another bug for userdb-cache option, there still are a lot of code to be disabled at compile time if build with '--disable-userdb-cache'.

[Chengwei-yang-cn (chengwei-yang-cn)]

Created attachment 82468
[PATCH v2] Do not update user db cache if build with "--disable-userdb-cache"

fixed coding style.

[Simon McVittie (smcv)]

Since 1.7.6 it is impossible to disable the userdb cache. There, solved :-)