90: Filling in system bus address...
90:   used default system bus "unix:path=/root/dbus-related/dbus-lib/dbus/var/run/dbus/system_bus_socket"
90: Filling in session bus address...
90:   "unix:path=/tmp/dbus-6fS3Q1dC9R,guid=a6fa8cbb7ab01b8ee11aa62b386d441b"
90: Filling in activation bus address...
90:   "none set"
90: opening shared connection to: unix:path=/tmp/dbus-6fS3Q1dC9R,guid=a6fa8cbb7ab01b8ee11aa62b386d441b
90: checking for existing connection
90: creating shared_connections hash table
90:   successfully created shared_connections
90: connecting to unix socket /tmp/dbus-6fS3Q1dC9R abstract=0
90: socket fd 3 opened
90: Successfully connected to unix socket /tmp/dbus-6fS3Q1dC9R
90: client: going from state NeedSendAuth to state WaitingForData
90: Initialized transport on address unix:path=/tmp/dbus-6fS3Q1dC9R
90:   LOCK: _dbus_connection_new_for_transport
90:   UNLOCK: protected_change_watch
90:   LOCK: protected_change_watch
90:   UNLOCK: protected_change_watch
90:   LOCK: protected_change_watch
90: check_read_watch: fd = 3
90:   setting read watch enabled = 0
90:   UNLOCK: protected_change_watch
90:   LOCK: protected_change_watch
90: check_write_watch(): needed = 1 on connection 0x402860 watch 0x4024c8 fd = 3 outgoing messages exist 0
90:   UNLOCK: protected_change_watch
90:   LOCK: protected_change_watch
90:   UNLOCK: _dbus_connection_new_for_transport
90:   LOCK: _dbus_connection_open_internal
90: stored connection to a6fa8cbb7ab01b8ee11aa62b386d441b to be shared
90:   UNLOCK: _dbus_connection_open_internal
90: Allocated slot 0 on allocator 0x2ab19b88 total 1 slots allocated 1 used
90:   LOCK: dbus_connection_get_data
90:   UNLOCK: dbus_connection_get_data
90:   LOCK: dbus_connection_set_data
90:   UNLOCK: dbus_connection_set_data
90:   LOCK: dbus_connection_send_with_reply
90: Allocated slot 0 on allocator 0x2ab19be0 total 1 slots allocated 1 used
90:   UNLOCK: protected_change_timeout
90:   LOCK: protected_change_timeout
90: Message 0x402b88 (1 /org/freedesktop/DBus org.freedesktop.DBus Hello '') for org.freedesktop.DBus added to outgoing queue 0x402860, 1 pending to send
90: Message 0x402b88 serial is 1
90: _dbus_connection_do_iteration_unlocked start
90:   UNLOCK: _dbus_connection_acquire_io_path
90: _dbus_connection_acquire_io_path locking io_path_mutex
90: _dbus_connection_acquire_io_path start connection->io_path_acquired = 0 timeout = 0
90: _dbus_connection_acquire_io_path end connection->io_path_acquired = 1 we_acquired = 1
90: _dbus_connection_acquire_io_path unlocking io_path_mutex
90:   LOCK: _dbus_connection_acquire_io_path
90: Transport iteration flags 0x1 timeout -1 connected = 1
90:  iteration flags = write timeout = -1 read_watch = 0x4024f0 write_watch = 0x4024c8 fd = 3
90: in iteration, need_read=0 need_write=1
90: exchange_credentials: do_reading = 0, do_writing = 1
90: wrote credentials byte
90:  client auth state: bytes to send
90: client: Sent 18 bytes of: AUTH EXTERNAL 30

90: exchange_credentials: do_reading = 0, do_writing = 1
90:  client auth state: waiting for input
90: check_read_watch: fd = 3
90:   setting read watch enabled = 1
90:   UNLOCK: protected_change_watch
90:   LOCK: protected_change_watch
90: check_write_watch(): needed = 0 on connection 0x402860 watch 0x4024c8 fd = 3 outgoing messages exist 1
90:   UNLOCK: protected_change_watch
90:   LOCK: protected_change_watch
90: Not authenticated, not writing anything
90: check_write_watch(): needed = 0 on connection 0x402860 watch 0x4024c8 fd = 3 outgoing messages exist 1
90:   UNLOCK: protected_change_watch
90:   LOCK: protected_change_watch
90:  ... leaving do_iteration()
90: _dbus_transport_do_iteration end
90: _dbus_connection_release_io_path locking io_path_mutex
90: _dbus_connection_release_io_path start connection->io_path_acquired = 1
90: _dbus_connection_release_io_path unlocking io_path_mutex
90: _dbus_connection_do_iteration_unlocked end
90: dispatch status = complete is_connected = 1
90:   UNLOCK: _dbus_connection_update_dispatch_status_and_unlock
90:   LOCK: dbus_connection_unref
90:   UNLOCK: dbus_connection_unref
90:   LOCK: _dbus_connection_lock
90:   UNLOCK: _dbus_connection_unlock
90:   LOCK: _dbus_connection_lock
90:   UNLOCK: _dbus_connection_unlock
90:   LOCK: _dbus_connection_lock
90: doing iteration in _dbus_connection_flush_unlocked
90: _dbus_connection_do_iteration_unlocked start
90:   UNLOCK: _dbus_connection_acquire_io_path
90: _dbus_connection_acquire_io_path locking io_path_mutex
90: _dbus_connection_acquire_io_path start connection->io_path_acquired = 0 timeout = -1
90: _dbus_connection_acquire_io_path end connection->io_path_acquired = 1 we_acquired = 1
90: _dbus_connection_acquire_io_path unlocking io_path_mutex
90:   LOCK: _dbus_connection_acquire_io_path
90: Transport iteration flags 0x7 timeout -1 connected = 1
90:  iteration flags = readwrite timeout = -1 read_watch = 0x4024f0 write_watch = 0x4024c8 fd = 3
90: unlock socket_do_iteration pre poll
90:   UNLOCK: _dbus_connection_unlock
90: lock socket_do_iteration post poll
90:   LOCK: _dbus_connection_lock
90: in iteration, need_read=1 need_write=0
90: exchange_credentials: do_reading = 1, do_writing = 0
90:  client auth state: waiting for input
90:  read 37 bytes in auth phase
90: client: got command "OK a6fa8cbb7ab01b8ee11aa62b386d441b"
90: Got GUID 'a6fa8cbb7ab01b8ee11aa62b386d441b' from the server
90: client: going from state WaitingForData to state Authenticated
90: exchange_credentials: do_reading = 1, do_writing = 0
90:  client auth state: bytes to send
90: check_read_watch: fd = 3
90:   setting read watch enabled = 0
90:   UNLOCK: protected_change_watch
90:   LOCK: protected_change_watch
90: check_write_watch(): needed = 1 on connection 0x402860 watch 0x4024c8 fd = 3 outgoing messages exist 1
90:   UNLOCK: protected_change_watch
90:   LOCK: protected_change_watch
90: do_reading: fd = 3
90: check_write_watch(): needed = 1 on connection 0x402860 watch 0x4024c8 fd = 3 outgoing messages exist 1
90:   UNLOCK: protected_change_watch
90:   LOCK: protected_change_watch
90:  ... leaving do_iteration()
90: _dbus_transport_do_iteration end
90: _dbus_connection_release_io_path locking io_path_mutex
90: _dbus_connection_release_io_path start connection->io_path_acquired = 1
90: _dbus_connection_release_io_path unlocking io_path_mutex
90: _dbus_connection_do_iteration_unlocked end
90: doing iteration in _dbus_connection_flush_unlocked
90: _dbus_connection_do_iteration_unlocked start
90:   UNLOCK: _dbus_connection_acquire_io_path
90: _dbus_connection_acquire_io_path locking io_path_mutex
90: _dbus_connection_acquire_io_path start connection->io_path_acquired = 0 timeout = -1
90: _dbus_connection_acquire_io_path end connection->io_path_acquired = 1 we_acquired = 1
90: _dbus_connection_acquire_io_path unlocking io_path_mutex
90:   LOCK: _dbus_connection_acquire_io_path
90: Transport iteration flags 0x7 timeout -1 connected = 1
90:  iteration flags = readwrite timeout = -1 read_watch = 0x4024f0 write_watch = 0x4024c8 fd = 3
90: unlock socket_do_iteration pre poll
90:   UNLOCK: _dbus_connection_unlock
90: lock socket_do_iteration post poll
90:   LOCK: _dbus_connection_lock
90: in iteration, need_read=0 need_write=1
90: exchange_credentials: do_reading = 0, do_writing = 1
90:  client auth state: bytes to send
90: client: Sent 7 bytes of: BEGIN

90: check_read_watch: fd = 3
90:   setting read watch enabled = 1
90:   UNLOCK: protected_change_watch
90:   LOCK: protected_change_watch
90: check_write_watch(): needed = 1 on connection 0x402860 watch 0x4024c8 fd = 3 outgoing messages exist 1
90:   UNLOCK: protected_change_watch
90:   LOCK: protected_change_watch
90: check_write_watch(): needed = 1 on connection 0x402860 watch 0x4024c8 fd = 3 outgoing messages exist 1
90:   UNLOCK: protected_change_watch
90:   LOCK: protected_change_watch
90:  ... leaving do_iteration()
90: _dbus_transport_do_iteration end
90: _dbus_connection_release_io_path locking io_path_mutex
90: _dbus_connection_release_io_path start connection->io_path_acquired = 1
90: _dbus_connection_release_io_path unlocking io_path_mutex
90: _dbus_connection_do_iteration_unlocked end
90: doing iteration in _dbus_connection_flush_unlocked
90: _dbus_connection_do_iteration_unlocked start
90:   UNLOCK: _dbus_connection_acquire_io_path
90: _dbus_connection_acquire_io_path locking io_path_mutex
90: _dbus_connection_acquire_io_path start connection->io_path_acquired = 0 timeout = -1
90: _dbus_connection_acquire_io_path end connection->io_path_acquired = 1 we_acquired = 1
90: _dbus_connection_acquire_io_path unlocking io_path_mutex
90:   LOCK: _dbus_connection_acquire_io_path
90: Transport iteration flags 0x7 timeout -1 connected = 1
90:  iteration flags = readwrite timeout = -1 read_watch = 0x4024f0 write_watch = 0x4024c8 fd = 3
90: unlock socket_do_iteration pre poll
90:   UNLOCK: _dbus_connection_unlock
90: lock socket_do_iteration post poll
90:   LOCK: _dbus_connection_lock
90: in iteration, need_read=0 need_write=1
90: do_writing(), have_messages = 1, fd = 3
90:  wrote 128 bytes of 128
90: Message 0x402b88 (1 /org/freedesktop/DBus org.freedesktop.DBus Hello '') removed from outgoing queue 0x402860, 0 left to send
90: check_write_watch(): needed = 0 on connection 0x402860 watch 0x4024c8 fd = 3 outgoing messages exist 0
90:   UNLOCK: protected_change_watch
90:   LOCK: protected_change_watch
90:  ... leaving do_iteration()
90: _dbus_transport_do_iteration end
90: _dbus_connection_release_io_path locking io_path_mutex
90: _dbus_connection_release_io_path start connection->io_path_acquired = 1
90: _dbus_connection_release_io_path unlocking io_path_mutex
90: _dbus_connection_do_iteration_unlocked end
90: _dbus_connection_flush_unlocked middle
90:  0 unused bytes sent to message loader
90: dispatch status = complete is_connected = 1
90: dbus_connection_send_with_reply_and_block(): will block 25000 milliseconds for reply serial 1 from 946685208 sec 1606 usec to 946685233 sec 1606 usec
90: _dbus_connection_do_iteration_unlocked start
90:   UNLOCK: _dbus_connection_acquire_io_path
90: _dbus_connection_acquire_io_path locking io_path_mutex
90: _dbus_connection_acquire_io_path start connection->io_path_acquired = 0 timeout = 25000
90: _dbus_connection_acquire_io_path end connection->io_path_acquired = 1 we_acquired = 1
90: _dbus_connection_acquire_io_path unlocking io_path_mutex
90:   LOCK: _dbus_connection_acquire_io_path
90: Transport iteration flags 0x6 timeout 25000 connected = 1
90:  iteration flags = read timeout = 25000 read_watch = 0x4024f0 write_watch = 0x4024c8 fd = 3
90: unlock socket_do_iteration pre poll
90:   UNLOCK: _dbus_connection_unlock
90: lock socket_do_iteration post poll
90:   LOCK: _dbus_connection_lock
90: in iteration, need_read=1 need_write=0
90: do_reading: fd = 3
90: check_read_watch: fd = 3
90:   setting read watch enabled = 1
90:   UNLOCK: protected_change_watch
90:   LOCK: protected_change_watch
90:  read 89 bytes
90: have 89 bytes, need body 9 + header 80 = 89
90: validating body from pos 0 len 89 sig 'yyyyuua(yv)'
90: p = 0x40386f end = 0x403899 claimed_len 1
90: initially caching field 6
90: initially caching field 5
90: initially caching field 8
90: initially caching field 7
90: validating body from pos 80 len 9 sig 's'
90: Loaded message 0x404050
90: queueing received message 0x404050
90:   UNLOCK: protected_change_timeout
90:   LOCK: protected_change_timeout
90: Message 0x404050 (2 no path no interface no member 's' reply to 1) added to incoming queue 0x402860, 1 incoming
90: check_read_watch: fd = 3
90:   setting read watch enabled = 1
90:   UNLOCK: protected_change_watch
90:   LOCK: protected_change_watch
90: check_write_watch(): needed = 0 on connection 0x402860 watch 0x4024c8 fd = 3 outgoing messages exist 0
90:   UNLOCK: protected_change_watch
90:   LOCK: protected_change_watch
90:  ... leaving do_iteration()
90: _dbus_transport_do_iteration end
90: _dbus_connection_release_io_path locking io_path_mutex
90: _dbus_connection_release_io_path start connection->io_path_acquired = 1
90: _dbus_connection_release_io_path unlocking io_path_mutex
90: _dbus_connection_do_iteration_unlocked end
90: _dbus_connection_block_pending_call top of recheck
90: check_for_reply_and_update_dispatch_unlocked checked for reply
90: dbus_connection_send_with_reply_and_block(): got reply
90:   handing message 0x404050 (method return) to pending call serial 1
90:   UNLOCK: _dbus_connection_unlock
90:   LOCK: free_pending_call_on_hash_removal
90:   UNLOCK: _dbus_connection_unlock
90:   LOCK: _dbus_connection_lock
90:   UNLOCK: _dbus_connection_unlock
90:   LOCK: check_for_reply_and_update_dispatch_unlocked
90: dispatch status = complete is_connected = 1
90:   UNLOCK: _dbus_connection_update_dispatch_status_and_unlock
90:   LOCK: dbus_connection_unref
90:   UNLOCK: dbus_connection_unref
90:   LOCK: _dbus_connection_lock
90:   UNLOCK: _dbus_connection_unlock
90:   LOCK: _dbus_connection_lock
90:   UNLOCK: _dbus_connection_unlock
90:   LOCK: _dbus_connection_lock
90:   UNLOCK: _dbus_connection_unlock
90: Freeing slot 0 on allocator 0x2ab19be0 total 1 allocated 1 used
90:   LOCK: dbus_connection_unref
90:   UNLOCK: dbus_connection_unref
90:   LOCK: dbus_connection_set_exit_on_disconnect
90:   UNLOCK: dbus_connection_set_exit_on_disconnect
90:   LOCK: dbus_connection_get_data
90:   UNLOCK: dbus_connection_get_data
message content : TestSignal-@@@@@
90:   LOCK: dbus_connection_send
90: Message 0x402ce8 (4 /com/wiley/test com.wiley.test TestSignal 's') for com.wiley.test added to outgoing queue 0x402860, 1 pending to send
90: Message 0x402ce8 serial is 2
90: _dbus_connection_do_iteration_unlocked start
90:   UNLOCK: _dbus_connection_acquire_io_path
90: _dbus_connection_acquire_io_path locking io_path_mutex
90: _dbus_connection_acquire_io_path start connection->io_path_acquired = 0 timeout = 0
90: _dbus_connection_acquire_io_path end connection->io_path_acquired = 1 we_acquired = 1
90: _dbus_connection_acquire_io_path unlocking io_path_mutex
90:   LOCK: _dbus_connection_acquire_io_path
90: Transport iteration flags 0x1 timeout -1 connected = 1
90:  iteration flags = write timeout = -1 read_watch = 0x4024f0 write_watch = 0x4024c8 fd = 3
90: do_writing(), have_messages = 1, fd = 3
90:  wrote 130 bytes of 130
90: Message 0x402ce8 (4 /com/wiley/test com.wiley.test TestSignal 's') removed from outgoing queue 0x402860, 0 left to send
90: check_write_watch(): needed = 0 on connection 0x402860 watch 0x4024c8 fd = 3 outgoing messages exist 0
90:   UNLOCK: protected_change_watch
90:   LOCK: protected_change_watch
90:  ... leaving do_iteration()
90: _dbus_transport_do_iteration end
90: _dbus_connection_release_io_path locking io_path_mutex
90: _dbus_connection_release_io_path start connection->io_path_acquired = 1
90: _dbus_connection_release_io_path unlocking io_path_mutex
90: _dbus_connection_do_iteration_unlocked end
90: _dbus_connection_send_preallocated_and_unlock middle
90: dispatch status = complete is_connected = 1
90:   UNLOCK: _dbus_connection_update_dispatch_status_and_unlock
90:   LOCK: dbus_connection_unref
90:   UNLOCK: dbus_connection_unref
90:   LOCK: dbus_connection_flush
90: _dbus_connection_flush_unlocked middle
90: dispatch status = complete is_connected = 1
90:   UNLOCK: _dbus_connection_update_dispatch_status_and_unlock
90:   LOCK: dbus_connection_unref
90:   UNLOCK: dbus_connection_unref
90: dbus_connection_flush end
Sending signal to D-Bus
90:   LOCK: dbus_connection_unref
90:   UNLOCK: dbus_connection_unref
signal sender=org.freedesktop.DBus -> dest=(null destination) serial=15 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameOwnerChanged
   string ":1.5"
   string ""
   string ":1.5"
method call sender=:1.5 -> dest=org.freedesktop.DBus serial=1 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=Hello
signal sender=org.freedesktop.DBus -> dest=(null destination) serial=16 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameOwnerChanged
   string ":1.5"
   string ":1.5"
   string ""