Bug 90316

Summary: dbus_transport_ref assertation on threaded dbus_connection_send_with_reply_and_block() calls
Product: dbus Reporter: Ralf Habacker <ralf.habacker>
Component: coreAssignee: D-Bus Maintainers <dbus>
Status: RESOLVED DUPLICATE QA Contact: D-Bus Maintainers <dbus>
Severity: normal    
Priority: medium    
Version: 1.8   
Hardware: Other   
OS: Linux (All)   
Whiteboard:
i915 platform: i915 features:
Attachments: testcase source
CMake build file

Description Ralf Habacker 2015-05-05 12:45:56 UTC
After running the appended test about one hour I got the following assertation:

assertion failed "transport->refcount > 0" file "/home/xxx/src/dbus-1.8/dbus/dbus-transport.c" line 462 function _dbus_transport_ref
Missing separate debuginfo for /lib64/libgcc_s.so.1
Try: zypper install -C "debuginfo(build-id)=26253bec1076626f73b8b13bed9510ae626e1ead"
  /home/xxx/dbus-1.8/usr/local/lib/libdbus-1.so.3(_dbus_print_backtrace+0x1f) [0x7ffff7baf6d9]
  /home/xxx/dbus-1.8/usr/local/lib/libdbus-1.so.3(_dbus_abort+0xd) [0x7ffff7baa489]
  /home/xxx/dbus-1.8/usr/local/lib/libdbus-1.so.3(_dbus_real_assert+0x53) [0x7ffff7b976c6]
  /home/xxx/dbus-1.8/usr/local/lib/libdbus-1.so.3(_dbus_transport_ref+0x3b) [0x7ffff7b8c3df]
  /home/xxx/dbus-1.8/usr/local/lib/libdbus-1.so.3(_dbus_transport_do_iteration+0xbd) [0x7ffff7b8d1b7]
  /home/xxx/dbus-1.8/usr/local/lib/libdbus-1.so.3(_dbus_connection_do_iteration_unlocked+0x183) [0x7ffff7b55c54]
  /home/xxx/dbus-1.8/usr/local/lib/libdbus-1.so.3(+0x24868) [0x7ffff7b57868]
  /home/xxx/dbus-1.8/usr/local/lib/libdbus-1.so.3(+0x26fd6) [0x7ffff7b59fd6]
  /home/xxx/dbus-1.8/usr/local/lib/libdbus-1.so.3(dbus_connection_send_with_reply+0x2ee) [0x7ffff7b5a522]
  /home/xxx/dbus-1.8/usr/local/lib/libdbus-1.so.3(dbus_connection_send_with_reply_and_block+0x207) [0x7ffff7b5a7c2]
  /home/xxx/src/dbus-testcases/89297/dbus-test(fun+0xa4) [0x400ea4]
  /lib64/libpthread.so.0(+0x80db) [0x7ffff791d0db]
  /lib64/libc.so.6(clone+0x6d) [0x7ffff764e58d]

Program received signal SIGABRT, Aborted.
[Switching to Thread 0x7fffdffff700 (LWP 3287)]
0x00007ffff759c4c9 in raise () from /lib64/libc.so.6
(gdb) info thread
  Id   Target Id         Frame 
  11   Thread 0x7fffde7fc700 (LWP 3290) "dbus-test" 0x00007ffff792389c in __lll_lock_wait () from /lib64/libpthread.so.0
  10   Thread 0x7fffdeffd700 (LWP 3289) "dbus-test" 0x00007ffff79210af in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
  9    Thread 0x7fffdf7fe700 (LWP 3288) "dbus-test" 0x00007ffff792389c in __lll_lock_wait () from /lib64/libpthread.so.0
* 8    Thread 0x7fffdffff700 (LWP 3287) "dbus-test" 0x00007ffff759c4c9 in raise () from /lib64/libc.so.6
  7    Thread 0x7ffff4b59700 (LWP 3286) "dbus-test" 0x00007ffff792389c in __lll_lock_wait () from /lib64/libpthread.so.0
  6    Thread 0x7ffff535a700 (LWP 3285) "dbus-test" 0x00007ffff79210af in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
  5    Thread 0x7ffff5b5b700 (LWP 3284) "dbus-test" 0x00007ffff79210af in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
  4    Thread 0x7ffff635c700 (LWP 3283) "dbus-test" 0x00007ffff7921458 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
  3    Thread 0x7ffff6b5d700 (LWP 3282) "dbus-test" 0x00007ffff79210af in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
  2    Thread 0x7ffff735e700 (LWP 3281) "dbus-test" 0x00007ffff79210af in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
  1    Thread 0x7ffff7fbe700 (LWP 3277) "dbus-test" 0x00007ffff761f20d in nanosleep () from /lib64/libc.so.6

(gdb) thread 11
#0  0x00007ffff792389c in __lll_lock_wait () from /lib64/libpthread.so.0
(gdb) bt
#0  0x00007ffff792389c in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x00007ffff791f4f2 in _L_lock_957 () from /lib64/libpthread.so.0
#2  0x00007ffff791f35a in pthread_mutex_lock () from /lib64/libpthread.so.0
#3  0x00007ffff7bb1125 in _dbus_platform_rmutex_lock (mutex=0x604060) at /home/xxx/src/dbus-1.8/dbus/dbus-sysdeps-pthread.c:158
#4  0x00007ffff7b8b1ed in _dbus_rmutex_lock (mutex=0x604060) at /home/xxx/src/dbus-1.8/dbus/dbus-threads.c:127
#5  0x00007ffff7b5590f in _dbus_connection_acquire_io_path (connection=0x603f50, timeout_milliseconds=0) at /home/xxx/src/dbus-1.8/dbus/dbus-connection.c:1126
#6  0x00007ffff7b55b73 in _dbus_connection_do_iteration_unlocked (connection=0x603f50, pending=0x0, flags=1, timeout_milliseconds=-1) at /home/xxx/src/dbus-1.8/dbus/dbus-connection.c:1210
#7  0x00007ffff7b57868 in _dbus_connection_send_preallocated_unlocked_no_update (connection=0x603f50, preallocated=0x0, message=0x7fffe0000950, client_serial=0x0) at /home/xxx/src/dbus-1.8/dbus/dbus-connection.c:2057
#8  0x00007ffff7b59fd6 in _dbus_connection_send_unlocked_no_update (connection=0x603f50, message=0x7fffe0000950, client_serial=0x0) at /home/xxx/src/dbus-1.8/dbus/dbus-connection.c:3267
#9  0x00007ffff7b5a522 in dbus_connection_send_with_reply (connection=0x603f50, message=0x7fffe0000950, pending_return=0x7fffde7fbe90, timeout_milliseconds=10) at /home/xxx/src/dbus-1.8/dbus/dbus-connection.c:3468
#10 0x00007ffff7b5a7c2 in dbus_connection_send_with_reply_and_block (connection=0x603f50, message=0x7fffe0000950, timeout_milliseconds=10, error=0x7fffde7fbf10) at /home/xxx/src/dbus-1.8/dbus/dbus-connection.c:3562
#11 0x0000000000400ea4 in fun ()
#12 0x00007ffff791d0db in start_thread () from /lib64/libpthread.so.0
#13 0x00007ffff764e58d in clone () from /lib64/libc.so.6

(gdb) thread 10
[Switching to thread 10 (Thread 0x7fffdeffd700 (LWP 3289))]
#0  0x00007ffff79210af in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
(gdb) bt
#0  0x00007ffff79210af in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ffff7bb1352 in _dbus_platform_condvar_wait (cond=0x604130, mutex=0x604090) at /home/xxx/src/dbus-1.8/dbus/dbus-sysdeps-pthread.c:217
#2  0x00007ffff7b8b341 in _dbus_condvar_wait (cond=0x604130, mutex=0x604090) at /home/xxx/src/dbus-1.8/dbus/dbus-threads.c:246
#3  0x00007ffff7b5583f in _dbus_connection_acquire_io_path (connection=0x603f50, timeout_milliseconds=-1) at /home/xxx/src/dbus-1.8/dbus/dbus-connection.c:1108
#4  0x00007ffff7b55b73 in _dbus_connection_do_iteration_unlocked (connection=0x603f50, pending=0x0, flags=7, timeout_milliseconds=-1) at /home/xxx/src/dbus-1.8/dbus/dbus-connection.c:1210
#5  0x00007ffff7b5a95e in _dbus_connection_flush_unlocked (connection=0x603f50) at /home/xxx/src/dbus-1.8/dbus/dbus-connection.c:3619
#6  0x00007ffff7b581a1 in _dbus_connection_block_pending_call (pending=0x7fffc8001ec0) at /home/xxx/src/dbus-1.8/dbus/dbus-connection.c:2399
#7  0x00007ffff7b81478 in dbus_pending_call_block (pending=0x7fffc8001ec0) at /home/xxx/src/dbus-1.8/dbus/dbus-pending-call.c:741
#8  0x00007ffff7b5a82b in dbus_connection_send_with_reply_and_block (connection=0x603f50, message=0x7fffc8002090, timeout_milliseconds=10, error=0x7fffdeffcf10) at /home/xxx/src/dbus-1.8/dbus/dbus-connection.c:3575
#9  0x0000000000400ea4 in fun ()
#10 0x00007ffff791d0db in start_thread () from /lib64/libpthread.so.0
Comment 1 Ralf Habacker 2015-05-05 12:46:23 UTC
Created attachment 115546 [details]
testcase source
Comment 2 Ralf Habacker 2015-05-05 12:47:06 UTC
Created attachment 115547 [details]
CMake build file
Comment 3 Ralf Habacker 2015-05-05 12:47:53 UTC
I used the following command line to run the test case:

DBUS_FATAL_WARNINGS=0 LD_LIBRARY_PATH=/home/xxx/dbus-1.8/usr/local/lib gdb  ./dbus-test
Comment 4 Simon McVittie 2015-05-05 14:33:55 UTC
(In reply to Ralf Habacker from comment #0)
> assertion failed "transport->refcount > 0" file
> "/home/xxx/src/dbus-1.8/dbus/dbus-transport.c" line 462 function
> _dbus_transport_ref

This could be Bug #90312?
Comment 5 Ralf Habacker 2015-05-05 14:37:56 UTC
(In reply to Simon McVittie from comment #4)
> (In reply to Ralf Habacker from comment #0)
> > assertion failed "transport->refcount > 0" file
> > "/home/xxx/src/dbus-1.8/dbus/dbus-transport.c" line 462 function
> > _dbus_transport_ref
> 
> This could be Bug #90312?

Will rerun test case with recent dbus-1.8 source, which includes the related patch.
Comment 6 Ralf Habacker 2015-05-24 21:37:52 UTC
(In reply to Ralf Habacker from comment #5)
> (In reply to Simon McVittie from comment #4)
> > (In reply to Ralf Habacker from comment #0)
> > > assertion failed "transport->refcount > 0" file
> > > "/home/xxx/src/dbus-1.8/dbus/dbus-transport.c" line 462 function
> > > _dbus_transport_ref
> > 
> > This could be Bug #90312?
> 
> Will rerun test case with recent dbus-1.8 source, which includes the related
> patch.

running the test case with the related patch applied did not produce the error after 24 hours of running, while without the patch the error happens after 1-2 hours.
Comment 7 Simon McVittie 2015-05-26 10:45:28 UTC
(In reply to Ralf Habacker from comment #6)
> running the test case with the related patch applied did not produce the
> error after 24 hours of running, while without the patch the error happens
> after 1-2 hours.

Thanks for checking this! I think we can call this a duplicate of Bug #90312 based on your testing. Fixed in git for 1.8.18 and 1.9.16.

*** This bug has been marked as a duplicate of bug 90312 ***
Comment 8 Simon McVittie 2015-05-26 10:46:09 UTC
(In reply to Simon McVittie from comment #7)
> Fixed in git for 1.8.18 and 1.9.16.

Er, I mean, fixed in 1.8.18 and 1.9.16 which were already released.

Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.