no freeze 8908: [dbus/dbus-connection.c(3490):dbus_connection_send_with_reply_and_block] LOCK 8908: [dbus/dbus-connection.c(3498):dbus_connection_send_with_reply_and_block] UNLOCK 8908: [dbus/dbus-connection.c(3355):dbus_connection_send_with_reply] LOCK 8908: [dbus/dbus-dataslot.c(146):_dbus_data_slot_allocator_alloc] Allocated slot 0 on allocator 0xb702c408 total 1 slots allocated 1 used 8908: [dbus/dbus-connection.c(2006):_dbus_connection_send_preallocated_unlocked_no_update] Message 0x894cb58 (method_call /domainmanagement turaya.domain.manager doSomethingAndSignal 'i') for turaya.domain.manager added to outgoing queue 0x894c690, 1 pending to send 8908: [dbus/dbus-connection.c(2022):_dbus_connection_send_preallocated_unlocked_no_update] Message 0x894cb58 serial is 16 8908: [dbus/dbus-connection.c(1191):_dbus_connection_do_iteration_unlocked] start 8908: [dbus/dbus-connection.c(1060):_dbus_connection_acquire_io_path] UNLOCK 8908: [dbus/dbus-connection.c(1062):_dbus_connection_acquire_io_path] locking io_path_mutex 8908: [dbus/dbus-connection.c(1066):_dbus_connection_acquire_io_path] start connection->io_path_acquired = 0 timeout = 0 8908: [dbus/dbus-connection.c(1109):_dbus_connection_acquire_io_path] end connection->io_path_acquired = 1 we_acquired = 1 8908: [dbus/dbus-connection.c(1111):_dbus_connection_acquire_io_path] unlocking io_path_mutex 8908: [dbus/dbus-connection.c(1114):_dbus_connection_acquire_io_path] LOCK 8908: [dbus/dbus-transport.c(964):_dbus_transport_do_iteration] Transport iteration flags 0x1 timeout -1 connected = 1 8908: [dbus/dbus-transport-socket.c(1047):socket_do_iteration] iteration flags = write timeout = -1 read_watch = 0x894c2e0 write_watch = 0x894c2b8 fd = 6 8908: [dbus/dbus-transport-socket.c(516):do_writing] do_writing(), have_messages = 1, fd = 6 8908: [dbus/dbus-transport-socket.c(666):do_writing] wrote 156 bytes of 156 8908: [dbus/dbus-connection.c(647):_dbus_connection_message_sent] Message 0x894cb58 (method_call /domainmanagement turaya.domain.manager doSomethingAndSignal 'i') removed from outgoing queue 0x894c690, 0 left to send 8908: [dbus/dbus-transport-socket.c(165):check_write_watch] check_write_watch(): needed = 0 on connection 0x894c690 watch 0x894c2b8 fd = 6 outgoing messages exist 0 8908: [dbus/dbus-transport-socket.c(1188):socket_do_iteration] ... leaving do_iteration() 8908: [dbus/dbus-transport.c(978):_dbus_transport_do_iteration] end 8908: [dbus/dbus-connection.c(1135):_dbus_connection_release_io_path] locking io_path_mutex 8908: [dbus/dbus-connection.c(1141):_dbus_connection_release_io_path] start connection->io_path_acquired = 1 8908: [dbus/dbus-connection.c(1146):_dbus_connection_release_io_path] unlocking io_path_mutex 8908: [dbus/dbus-connection.c(1224):_dbus_connection_do_iteration_unlocked] end 8908: [dbus/dbus-connection.c(4194):_dbus_connection_get_dispatch_status_unlocked] dispatch status = complete is_connected = 1 8908: [dbus/dbus-connection.c(4265):_dbus_connection_update_dispatch_status_and_unlock] UNLOCK 8908: [dbus/dbus-connection.c(381):_dbus_connection_lock] LOCK 8908: [dbus/dbus-connection.c(392):_dbus_connection_unlock] UNLOCK 8908: [dbus/dbus-connection.c(381):_dbus_connection_lock] LOCK 8908: [dbus/dbus-connection.c(3568):_dbus_connection_flush_unlocked] middle 8908: [dbus/dbus-connection.c(4194):_dbus_connection_get_dispatch_status_unlocked] dispatch status = complete is_connected = 1 8908: [dbus/dbus-connection.c(2388):_dbus_connection_block_pending_call] dbus_connection_send_with_reply_and_block(): will block 25000 milliseconds for reply serial 16 from 23352 sec 97251 usec 8908: [dbus/dbus-connection.c(1191):_dbus_connection_do_iteration_unlocked] start 8908: [dbus/dbus-connection.c(1060):_dbus_connection_acquire_io_path] UNLOCK 8908: [dbus/dbus-connection.c(1062):_dbus_connection_acquire_io_path] locking io_path_mutex 8908: [dbus/dbus-connection.c(1066):_dbus_connection_acquire_io_path] start connection->io_path_acquired = 0 timeout = 25000 8908: [dbus/dbus-connection.c(1109):_dbus_connection_acquire_io_path] end connection->io_path_acquired = 1 we_acquired = 1 8908: [dbus/dbus-connection.c(1111):_dbus_connection_acquire_io_path] unlocking io_path_mutex 8908: [dbus/dbus-connection.c(1114):_dbus_connection_acquire_io_path] LOCK 8908: [dbus/dbus-transport.c(964):_dbus_transport_do_iteration] Transport iteration flags 0x6 timeout 25000 connected = 1 8908: [dbus/dbus-transport-socket.c(1047):socket_do_iteration] iteration flags = read timeout = 25000 read_watch = 0x894c2e0 write_watch = 0x894c2b8 fd = 6 8908: [dbus/dbus-transport-socket.c(1120):socket_do_iteration] unlock pre poll 8908: [dbus/dbus-connection.c(392):_dbus_connection_unlock] UNLOCK 8908: [dbus/dbus-connection.c(1476):_dbus_connection_handle_watch] start 8908: [dbus/dbus-connection.c(1478):_dbus_connection_handle_watch] LOCK 8908: [dbus/dbus-connection.c(1060):_dbus_connection_acquire_io_path] UNLOCK 8908: [dbus/dbus-connection.c(1062):_dbus_connection_acquire_io_path] locking io_path_mutex 8908: [dbus/dbus-connection.c(1066):_dbus_connection_acquire_io_path] start connection->io_path_acquired = 1 timeout = 1 8908: [dbus/dbus-connection.c(1075):_dbus_connection_acquire_io_path] waiting 1 for IO path to be acquirable 8908: [dbus/dbus-transport-socket.c(1132):socket_do_iteration] lock post poll 8908: [dbus/dbus-connection.c(1109):_dbus_connection_acquire_io_path] end connection->io_path_acquired = 1 we_acquired = 0 8908: [dbus/dbus-connection.c(1111):_dbus_connection_acquire_io_path] unlocking io_path_mutex 8908: [dbus/dbus-connection.c(1114):_dbus_connection_acquire_io_path] LOCK 8908: [dbus/dbus-connection.c(1483):_dbus_connection_handle_watch] UNLOCK 8908: [dbus/dbus-connection.c(1476):_dbus_connection_handle_watch] start 8908: [dbus/dbus-connection.c(1478):_dbus_connection_handle_watch] LOCK 8908: [dbus/dbus-connection.c(1060):_dbus_connection_acquire_io_path] UNLOCK 8908: [dbus/dbus-connection.c(1062):_dbus_connection_acquire_io_path] locking io_path_mutex 8908: [dbus/dbus-connection.c(1066):_dbus_connection_acquire_io_path] start connection->io_path_acquired = 1 timeout = 1 8908: [dbus/dbus-connection.c(1075):_dbus_connection_acquire_io_path] waiting 1 for IO path to be acquirable 8908: [dbus/dbus-connection.c(381):_dbus_connection_lock] LOCK 8908: [dbus/dbus-transport-socket.c(1153):socket_do_iteration] in iteration, need_read=1 need_write=0 8908: [dbus/dbus-transport-socket.c(703):do_reading] fd = 6 8908: [dbus/dbus-transport-socket.c(180):check_read_watch] fd = 6 8908: [dbus/dbus-transport-socket.c(226):check_read_watch] setting read watch enabled = 1 8908: [dbus/dbus-transport-socket.c(847):do_reading] read 200 bytes 8908: [dbus/dbus-marshal-header.c(732):_dbus_header_have_message_untrusted] have 200 bytes, need body 4 + header 128 = 132 8908: [dbus/dbus-marshal-validate.c(723):_dbus_validate_body_with_reason] validating body from pos 0 len 200 sig 'yyyyuua(yv)' 8908: [dbus/dbus-marshal-validate.c(548):validate_body_helper] p = 0x894e737 end = 0x894e790 claimed_len 1 8908: [dbus/dbus-marshal-header.c(806):load_and_validate_field] initially caching field 1 8908: [dbus/dbus-marshal-header.c(806):load_and_validate_field] initially caching field 2 8908: [dbus/dbus-marshal-header.c(806):load_and_validate_field] initially caching field 3 8908: [dbus/dbus-marshal-header.c(806):load_and_validate_field] initially caching field 8 8908: [dbus/dbus-marshal-header.c(806):load_and_validate_field] initially caching field 7 8908: [dbus/dbus-marshal-validate.c(723):_dbus_validate_body_with_reason] validating body from pos 128 len 4 sig 'i' 8908: [dbus/dbus-message.c(4115):load_message] Loaded message 0x894ef60 8908: [dbus/dbus-marshal-header.c(732):_dbus_header_have_message_untrusted] have 68 bytes, need body 4 + header 64 = 68 8908: [dbus/dbus-marshal-validate.c(723):_dbus_validate_body_with_reason] validating body from pos 0 len 68 sig 'yyyyuua(yv)' 8908: [dbus/dbus-marshal-validate.c(548):validate_body_helper] p = 0x894e6f7 end = 0x894e70c claimed_len 1 8908: [dbus/dbus-marshal-header.c(806):load_and_validate_field] initially caching field 6 8908: [dbus/dbus-marshal-header.c(806):load_and_validate_field] initially caching field 5 8908: [dbus/dbus-marshal-header.c(806):load_and_validate_field] initially caching field 8 8908: [dbus/dbus-marshal-header.c(806):load_and_validate_field] initially caching field 7 8908: [dbus/dbus-marshal-validate.c(723):_dbus_validate_body_with_reason] validating body from pos 64 len 4 sig 'i' 8908: [dbus/dbus-message.c(4115):load_message] Loaded message 0x894c9c0 8908: [dbus/dbus-transport.c(1136):_dbus_transport_queue_messages] queueing received message 0x894ef60 8908: [dbus/dbus-connection.c(523):_dbus_connection_queue_received_message_link] Message 0x894ef60 (signal /domainmanagement turaya.domain.manager iDidSomething 'i' reply to 0) added to incoming queue 0x894c690, 1 incoming 8908: [dbus/dbus-transport.c(1136):_dbus_transport_queue_messages] queueing received message 0x894c9c0 8908: [dbus/dbus-connection.c(523):_dbus_connection_queue_received_message_link] Message 0x894c9c0 (method_return no path no interface no member 'i' reply to 16) added to incoming queue 0x894c690, 2 incoming 8908: [dbus/dbus-transport-socket.c(180):check_read_watch] fd = 6 8908: [dbus/dbus-transport-socket.c(226):check_read_watch] setting read watch enabled = 1 8908: [dbus/dbus-transport-socket.c(165):check_write_watch] check_write_watch(): needed = 0 on connection 0x894c690 watch 0x894c2b8 fd = 6 outgoing messages exist 0 8908: [dbus/dbus-transport-socket.c(1188):socket_do_iteration] ... leaving do_iteration() 8908: [dbus/dbus-transport.c(978):_dbus_transport_do_iteration] end 8908: [dbus/dbus-connection.c(1135):_dbus_connection_release_io_path] locking io_path_mutex 8908: [dbus/dbus-connection.c(1141):_dbus_connection_release_io_path] start connection->io_path_acquired = 1 8908: [dbus/dbus-connection.c(1146):_dbus_connection_release_io_path] unlocking io_path_mutex 8908: [dbus/dbus-connection.c(1109):_dbus_connection_acquire_io_path] end connection->io_path_acquired = 1 we_acquired = 1 8908: [dbus/dbus-connection.c(1111):_dbus_connection_acquire_io_path] unlocking io_path_mutex 8908: [dbus/dbus-connection.c(1114):_dbus_connection_acquire_io_path] LOCK 8908: [dbus/dbus-connection.c(1224):_dbus_connection_do_iteration_unlocked] end 8908: [dbus/dbus-connection.c(2412):_dbus_connection_block_pending_call] top of recheck 8908: [dbus/dbus-connection.c(2318):check_for_reply_and_update_dispatch_unlocked] checked for reply 8908: [dbus/dbus-connection.c(2320):check_for_reply_and_update_dispatch_unlocked] dbus_connection_send_with_reply_and_block(): got reply 8908: [dbus/dbus-pending-call.c(172):_dbus_pending_call_set_reply_unlocked] handing message 0x894c9c0 (method return) to pending call serial 16 8908: [dbus/dbus-connection.c(392):_dbus_connection_unlock] UNLOCK 8908: [dbus/dbus-transport-socket.c(919):socket_handle_watch] handling read watch 0x894c2e0 flags = 1 8908: [dbus/dbus-transport-socket.c(703):do_reading] fd = 6 8908: [dbus/dbus-transport-socket.c(180):check_read_watch] fd = 6 8908: [dbus/dbus-transport-socket.c(226):check_read_watch] setting read watch enabled = 1 8908: [dbus/dbus-connection.c(1135):_dbus_connection_release_io_path] locking io_path_mutex 8908: [dbus/dbus-connection.c(1141):_dbus_connection_release_io_path] start connection->io_path_acquired = 1 8908: [dbus/dbus-connection.c(1146):_dbus_connection_release_io_path] unlocking io_path_mutex 8908: [dbus/dbus-connection.c(1495):_dbus_connection_handle_watch] middle 8908: [dbus/dbus-connection.c(4265):_dbus_connection_update_dispatch_status_and_unlock] UNLOCK 8908: [dbus/dbus-connection.c(4271):_dbus_connection_update_dispatch_status_and_unlock] Notifying of change to dispatch status of 0x894c690 now 0 (data remains) 8908: [dbus/dbus-connection.c(1502):_dbus_connection_handle_watch] end 8908: [dbus/dbus-connection.c(4487):dbus_connection_dispatch] 8908: [dbus/dbus-connection.c(4489):dbus_connection_dispatch] LOCK 8908: [dbus/dbus-connection.c(4060):_dbus_connection_acquire_dispatch] UNLOCK 8908: [dbus/dbus-connection.c(4062):_dbus_connection_acquire_dispatch] locking dispatch_mutex 8908: [dbus/dbus-connection.c(4076):_dbus_connection_acquire_dispatch] unlocking dispatch_mutex 8908: [dbus/dbus-connection.c(4079):_dbus_connection_acquire_dispatch] LOCK 8908: [dbus/dbus-connection.c(3932):_dbus_connection_pop_message_link_unlocked] Message 0x894ef60 (signal /domainmanagement turaya.domain.manager iDidSomething 'i') removed from incoming queue 0x894c690, 0 incoming 8908: [dbus/dbus-connection.c(4535):dbus_connection_dispatch] dispatching message 0x894ef60 (signal turaya.domain.manager iDidSomething 'i') 8908: [dbus/dbus-connection.c(4587):dbus_connection_dispatch] UNLOCK 8908: [dbus/dbus-connection.c(4616):dbus_connection_dispatch] LOCK 8908: [dbus/dbus-connection.c(4641):dbus_connection_dispatch] running object path dispatch on message 0x894ef60 (signal turaya.domain.manager iDidSomething 'i') 8908: [dbus/dbus-object-tree.c(818):_dbus_object_tree_dispatch_and_unlock] 1 handlers in the path tree for this message 8908: [dbus/dbus-object-tree.c(849):_dbus_object_tree_dispatch_and_unlock] unlock 8908: [dbus/dbus-connection.c(392):_dbus_connection_unlock] UNLOCK 8908: [dbus/dbus-connection.c(381):_dbus_connection_lock] LOCK 8908: [dbus/dbus-object-tree.c(889):_dbus_object_tree_dispatch_and_unlock] unlock 8908: [dbus/dbus-connection.c(392):_dbus_connection_unlock] UNLOCK 8908: [dbus/dbus-connection.c(4647):dbus_connection_dispatch] LOCK 8908: [dbus/dbus-connection.c(4651):dbus_connection_dispatch] object tree handled message in dispatch 8908: [dbus/dbus-connection.c(4738):dbus_connection_dispatch] ... done dispatching 8908: [dbus/dbus-connection.c(4095):_dbus_connection_release_dispatch] locking dispatch_mutex 8908: [dbus/dbus-connection.c(4103):_dbus_connection_release_dispatch] unlocking dispatch_mutex 8908: [dbus/dbus-connection.c(4749):dbus_connection_dispatch] before final status update 8908: [dbus/dbus-connection.c(4194):_dbus_connection_get_dispatch_status_unlocked] dispatch status = complete is_connected = 1 8908: [dbus/dbus-connection.c(4265):_dbus_connection_update_dispatch_status_and_unlock] UNLOCK 8908: [dbus/dbus-connection.c(4271):_dbus_connection_update_dispatch_status_and_unlock] Notifying of change to dispatch status of 0x894c690 now 1 (complete) 8908: [dbus/dbus-connection.c(984):free_pending_call_on_hash_removal] LOCK 8908: [dbus/dbus-connection.c(392):_dbus_connection_unlock] UNLOCK 8908: [dbus/dbus-connection.c(2325):check_for_reply_and_update_dispatch_unlocked] LOCK 8908: [dbus/dbus-connection.c(4194):_dbus_connection_get_dispatch_status_unlocked] dispatch status = complete is_connected = 1 8908: [dbus/dbus-connection.c(4265):_dbus_connection_update_dispatch_status_and_unlock] UNLOCK 8908: [dbus/dbus-connection.c(381):_dbus_connection_lock] LOCK 8908: [dbus/dbus-connection.c(392):_dbus_connection_unlock] UNLOCK 8908: [dbus/dbus-dataslot.c(184):_dbus_data_slot_allocator_free] Freeing slot 0 on allocator 0xb702c408 total 1 allocated 1 used with freeze 8908: [dbus/dbus-connection.c(3490):dbus_connection_send_with_reply_and_block] LOCK 8908: [dbus/dbus-connection.c(3498):dbus_connection_send_with_reply_and_block] UNLOCK 8908: [dbus/dbus-connection.c(3355):dbus_connection_send_with_reply] LOCK 8908: [dbus/dbus-dataslot.c(146):_dbus_data_slot_allocator_alloc] Allocated slot 0 on allocator 0xb702c408 total 1 slots allocated 1 used 8908: [dbus/dbus-connection.c(2006):_dbus_connection_send_preallocated_unlocked_no_update] Message 0x894cb58 (method_call /domainmanagement turaya.domain.manager doSomethingAndSignal 'i') for turaya.domain.manager added to outgoing queue 0x894c690, 1 pending to send 8908: [dbus/dbus-connection.c(2022):_dbus_connection_send_preallocated_unlocked_no_update] Message 0x894cb58 serial is 14 8908: [dbus/dbus-connection.c(1191):_dbus_connection_do_iteration_unlocked] start 8908: [dbus/dbus-connection.c(1060):_dbus_connection_acquire_io_path] UNLOCK 8908: [dbus/dbus-connection.c(1062):_dbus_connection_acquire_io_path] locking io_path_mutex 8908: [dbus/dbus-connection.c(1066):_dbus_connection_acquire_io_path] start connection->io_path_acquired = 0 timeout = 0 8908: [dbus/dbus-connection.c(1109):_dbus_connection_acquire_io_path] end connection->io_path_acquired = 1 we_acquired = 1 8908: [dbus/dbus-connection.c(1111):_dbus_connection_acquire_io_path] unlocking io_path_mutex 8908: [dbus/dbus-connection.c(1114):_dbus_connection_acquire_io_path] LOCK 8908: [dbus/dbus-transport.c(964):_dbus_transport_do_iteration] Transport iteration flags 0x1 timeout -1 connected = 1 8908: [dbus/dbus-transport-socket.c(1047):socket_do_iteration] iteration flags = write timeout = -1 read_watch = 0x894c2e0 write_watch = 0x894c2b8 fd = 6 8908: [dbus/dbus-transport-socket.c(516):do_writing] do_writing(), have_messages = 1, fd = 6 8908: [dbus/dbus-transport-socket.c(666):do_writing] wrote 156 bytes of 156 8908: [dbus/dbus-connection.c(647):_dbus_connection_message_sent] Message 0x894cb58 (method_call /domainmanagement turaya.domain.manager doSomethingAndSignal 'i') removed from outgoing queue 0x894c690, 0 left to send 8908: [dbus/dbus-transport-socket.c(165):check_write_watch] check_write_watch(): needed = 0 on connection 0x894c690 watch 0x894c2b8 fd = 6 outgoing messages exist 0 8908: [dbus/dbus-transport-socket.c(1188):socket_do_iteration] ... leaving do_iteration() 8908: [dbus/dbus-transport.c(978):_dbus_transport_do_iteration] end 8908: [dbus/dbus-connection.c(1135):_dbus_connection_release_io_path] locking io_path_mutex 8908: [dbus/dbus-connection.c(1141):_dbus_connection_release_io_path] start connection->io_path_acquired = 1 8908: [dbus/dbus-connection.c(1146):_dbus_connection_release_io_path] unlocking io_path_mutex 8908: [dbus/dbus-connection.c(1224):_dbus_connection_do_iteration_unlocked] end 8908: [dbus/dbus-connection.c(4194):_dbus_connection_get_dispatch_status_unlocked] dispatch status = complete is_connected = 1 8908: [dbus/dbus-connection.c(4265):_dbus_connection_update_dispatch_status_and_unlock] UNLOCK 8908: [dbus/dbus-connection.c(381):_dbus_connection_lock] LOCK 8908: [dbus/dbus-connection.c(392):_dbus_connection_unlock] UNLOCK 8908: [dbus/dbus-connection.c(381):_dbus_connection_lock] LOCK 8908: [dbus/dbus-connection.c(3568):_dbus_connection_flush_unlocked] middle 8908: [dbus/dbus-connection.c(4194):_dbus_connection_get_dispatch_status_unlocked] dispatch status = complete is_connected = 1 8908: [dbus/dbus-connection.c(2388):_dbus_connection_block_pending_call] dbus_connection_send_with_reply_and_block(): will block 25000 milliseconds for reply serial 14 from 23327 sec 58989 usec 8908: [dbus/dbus-connection.c(1191):_dbus_connection_do_iteration_unlocked] start 8908: [dbus/dbus-connection.c(1060):_dbus_connection_acquire_io_path] UNLOCK 8908: [dbus/dbus-connection.c(1062):_dbus_connection_acquire_io_path] locking io_path_mutex 8908: [dbus/dbus-connection.c(1066):_dbus_connection_acquire_io_path] start connection->io_path_acquired = 0 timeout = 25000 8908: [dbus/dbus-connection.c(1109):_dbus_connection_acquire_io_path] end connection->io_path_acquired = 1 we_acquired = 1 8908: [dbus/dbus-connection.c(1111):_dbus_connection_acquire_io_path] unlocking io_path_mutex 8908: [dbus/dbus-connection.c(1114):_dbus_connection_acquire_io_path] LOCK 8908: [dbus/dbus-transport.c(964):_dbus_transport_do_iteration] Transport iteration flags 0x6 timeout 25000 connected = 1 8908: [dbus/dbus-transport-socket.c(1047):socket_do_iteration] iteration flags = read timeout = 25000 read_watch = 0x894c2e0 write_watch = 0x894c2b8 fd = 6 8908: [dbus/dbus-transport-socket.c(1120):socket_do_iteration] unlock pre poll 8908: [dbus/dbus-connection.c(392):_dbus_connection_unlock] UNLOCK 8908: [dbus/dbus-connection.c(1476):_dbus_connection_handle_watch] start 8908: [dbus/dbus-connection.c(1478):_dbus_connection_handle_watch] LOCK 8908: [dbus/dbus-connection.c(1060):_dbus_connection_acquire_io_path] UNLOCK 8908: [dbus/dbus-connection.c(1062):_dbus_connection_acquire_io_path] locking io_path_mutex 8908: [dbus/dbus-connection.c(1066):_dbus_connection_acquire_io_path] start connection->io_path_acquired = 1 timeout = 1 8908: [dbus/dbus-connection.c(1075):_dbus_connection_acquire_io_path] waiting 1 for IO path to be acquirable 8908: [dbus/dbus-transport-socket.c(1132):socket_do_iteration] lock post poll 8908: [dbus/dbus-connection.c(381):_dbus_connection_lock] LOCK 8908: [dbus/dbus-transport-socket.c(1153):socket_do_iteration] in iteration, need_read=1 need_write=0 8908: [dbus/dbus-transport-socket.c(703):do_reading] fd = 6 8908: [dbus/dbus-transport-socket.c(180):check_read_watch] fd = 6 8908: [dbus/dbus-transport-socket.c(226):check_read_watch] setting read watch enabled = 1 8908: [dbus/dbus-transport-socket.c(847):do_reading] read 132 bytes 8908: [dbus/dbus-marshal-header.c(732):_dbus_header_have_message_untrusted] have 132 bytes, need body 4 + header 128 = 132 8908: [dbus/dbus-marshal-validate.c(723):_dbus_validate_body_with_reason] validating body from pos 0 len 132 sig 'yyyyuua(yv)' 8908: [dbus/dbus-marshal-validate.c(548):validate_body_helper] p = 0x894e737 end = 0x894e74c claimed_len 1 8908: [dbus/dbus-marshal-header.c(806):load_and_validate_field] initially caching field 1 8908: [dbus/dbus-marshal-header.c(806):load_and_validate_field] initially caching field 2 8908: [dbus/dbus-marshal-header.c(806):load_and_validate_field] initially caching field 3 8908: [dbus/dbus-marshal-header.c(806):load_and_validate_field] initially caching field 8 8908: [dbus/dbus-marshal-header.c(806):load_and_validate_field] initially caching field 7 8908: [dbus/dbus-marshal-validate.c(723):_dbus_validate_body_with_reason] validating body from pos 128 len 4 sig 'i' 8908: [dbus/dbus-message.c(4115):load_message] Loaded message 0x894ef60 8908: [dbus/dbus-transport.c(1136):_dbus_transport_queue_messages] queueing received message 0x894ef60 8908: [dbus/dbus-connection.c(523):_dbus_connection_queue_received_message_link] Message 0x894ef60 (signal /domainmanagement turaya.domain.manager iDidSomething 'i' reply to 0) added to incoming queue 0x894c690, 1 incoming 8908: [dbus/dbus-transport-socket.c(180):check_read_watch] fd = 6 8908: [dbus/dbus-transport-socket.c(226):check_read_watch] setting read watch enabled = 1 8908: [dbus/dbus-transport-socket.c(165):check_write_watch] check_write_watch(): needed = 0 on connection 0x894c690 watch 0x894c2b8 fd = 6 outgoing messages exist 0 8908: [dbus/dbus-transport-socket.c(1188):socket_do_iteration] ... leaving do_iteration() 8908: [dbus/dbus-transport.c(978):_dbus_transport_do_iteration] end 8908: [dbus/dbus-connection.c(1135):_dbus_connection_release_io_path] locking io_path_mutex 8908: [dbus/dbus-connection.c(1141):_dbus_connection_release_io_path] start connection->io_path_acquired = 1 8908: [dbus/dbus-connection.c(1146):_dbus_connection_release_io_path] unlocking io_path_mutex 8908: [dbus/dbus-connection.c(1224):_dbus_connection_do_iteration_unlocked] end 8908: [dbus/dbus-connection.c(2412):_dbus_connection_block_pending_call] top of recheck 8908: [dbus/dbus-connection.c(1109):_dbus_connection_acquire_io_path] end connection->io_path_acquired = 1 we_acquired = 1 8908: [dbus/dbus-connection.c(1111):_dbus_connection_acquire_io_path] unlocking io_path_mutex 8908: [dbus/dbus-connection.c(1114):_dbus_connection_acquire_io_path] LOCK 8908: [dbus/dbus-connection.c(2484):_dbus_connection_block_pending_call] dbus_connection_send_with_reply_and_block(): 24999 milliseconds remain 8908: [dbus/dbus-connection.c(1191):_dbus_connection_do_iteration_unlocked] start 8908: [dbus/dbus-connection.c(1060):_dbus_connection_acquire_io_path] UNLOCK 8908: [dbus/dbus-transport-socket.c(919):socket_handle_watch] handling read watch 0x894c2e0 flags = 1 8908: [dbus/dbus-transport-socket.c(703):do_reading] fd = 6 8908: [dbus/dbus-transport-socket.c(180):check_read_watch] fd = 6 8908: [dbus/dbus-transport-socket.c(226):check_read_watch] setting read watch enabled = 1 8908: [dbus/dbus-connection.c(1135):_dbus_connection_release_io_path] locking io_path_mutex 8908: [dbus/dbus-connection.c(1141):_dbus_connection_release_io_path] start connection->io_path_acquired = 1 8908: [dbus/dbus-connection.c(1146):_dbus_connection_release_io_path] unlocking io_path_mutex 8908: [dbus/dbus-connection.c(1495):_dbus_connection_handle_watch] middle 8908: [dbus/dbus-connection.c(4265):_dbus_connection_update_dispatch_status_and_unlock] UNLOCK 8908: [dbus/dbus-connection.c(4271):_dbus_connection_update_dispatch_status_and_unlock] Notifying of change to dispatch status of 0x894c690 now 0 (data remains) 8908: [dbus/dbus-connection.c(1502):_dbus_connection_handle_watch] end 8908: [dbus/dbus-connection.c(1476):_dbus_connection_handle_watch] start 8908: [dbus/dbus-connection.c(1478):_dbus_connection_handle_watch] LOCK 8908: [dbus/dbus-connection.c(1060):_dbus_connection_acquire_io_path] UNLOCK 8908: [dbus/dbus-connection.c(1062):_dbus_connection_acquire_io_path] locking io_path_mutex 8908: [dbus/dbus-connection.c(1066):_dbus_connection_acquire_io_path] start connection->io_path_acquired = 0 timeout = 1 8908: [dbus/dbus-connection.c(1109):_dbus_connection_acquire_io_path] end connection->io_path_acquired = 1 we_acquired = 1 8908: [dbus/dbus-connection.c(1111):_dbus_connection_acquire_io_path] unlocking io_path_mutex 8908: [dbus/dbus-connection.c(1114):_dbus_connection_acquire_io_path] LOCK 8908: [dbus/dbus-transport-socket.c(919):socket_handle_watch] handling read watch 0x894c2e0 flags = 1 8908: [dbus/dbus-transport-socket.c(703):do_reading] fd = 6 8908: [dbus/dbus-transport-socket.c(180):check_read_watch] fd = 6 8908: [dbus/dbus-transport-socket.c(226):check_read_watch] setting read watch enabled = 1 8908: [dbus/dbus-transport-socket.c(847):do_reading] read 68 bytes 8908: [dbus/dbus-marshal-header.c(732):_dbus_header_have_message_untrusted] have 68 bytes, need body 4 + header 64 = 68 8908: [dbus/dbus-marshal-validate.c(723):_dbus_validate_body_with_reason] validating body from pos 0 len 68 sig 'yyyyuua(yv)' 8908: [dbus/dbus-marshal-validate.c(548):validate_body_helper] p = 0x894e6f7 end = 0x894e70c claimed_len 1 8908: [dbus/dbus-marshal-header.c(806):load_and_validate_field] initially caching field 6 8908: [dbus/dbus-marshal-header.c(806):load_and_validate_field] initially caching field 5 8908: [dbus/dbus-marshal-header.c(806):load_and_validate_field] initially caching field 8 8908: [dbus/dbus-marshal-header.c(806):load_and_validate_field] initially caching field 7 8908: [dbus/dbus-marshal-validate.c(723):_dbus_validate_body_with_reason] validating body from pos 64 len 4 sig 'i' 8908: [dbus/dbus-message.c(4115):load_message] Loaded message 0x894c9c0 8908: [dbus/dbus-transport.c(1136):_dbus_transport_queue_messages] queueing received message 0x894c9c0 8908: [dbus/dbus-connection.c(1062):_dbus_connection_acquire_io_path] locking io_path_mutex 8908: [dbus/dbus-connection.c(1066):_dbus_connection_acquire_io_path] start connection->io_path_acquired = 1 timeout = 24999 8908: [dbus/dbus-connection.c(1075):_dbus_connection_acquire_io_path] waiting 24999 for IO path to be acquirable 8908: [dbus/dbus-connection.c(4487):dbus_connection_dispatch] 8908: [dbus/dbus-connection.c(4489):dbus_connection_dispatch] LOCK 8908: [dbus/dbus-connection.c(523):_dbus_connection_queue_received_message_link] Message 0x894c9c0 (method_return no path no interface no member 'i' reply to 14) added to incoming queue 0x894c690, 2 incoming 8908: [dbus/dbus-transport-socket.c(180):check_read_watch] fd = 6 8908: [dbus/dbus-transport-socket.c(226):check_read_watch] setting read watch enabled = 1 8908: [dbus/dbus-connection.c(1135):_dbus_connection_release_io_path] locking io_path_mutex 8908: [dbus/dbus-connection.c(1141):_dbus_connection_release_io_path] start connection->io_path_acquired = 1 8908: [dbus/dbus-connection.c(1146):_dbus_connection_release_io_path] unlocking io_path_mutex 8908: [dbus/dbus-connection.c(1495):_dbus_connection_handle_watch] middle 8908: [dbus/dbus-connection.c(4265):_dbus_connection_update_dispatch_status_and_unlock] UNLOCK 8908: [dbus/dbus-connection.c(1502):_dbus_connection_handle_watch] end 8908: [dbus/dbus-connection.c(4060):_dbus_connection_acquire_dispatch] UNLOCK 8908: [dbus/dbus-connection.c(4062):_dbus_connection_acquire_dispatch] locking dispatch_mutex 8908: [dbus/dbus-connection.c(4076):_dbus_connection_acquire_dispatch] unlocking dispatch_mutex 8908: [dbus/dbus-connection.c(4079):_dbus_connection_acquire_dispatch] LOCK 8908: [dbus/dbus-connection.c(1109):_dbus_connection_acquire_io_path] end connection->io_path_acquired = 1 we_acquired = 1 8908: [dbus/dbus-connection.c(1111):_dbus_connection_acquire_io_path] unlocking io_path_mutex 8908: [dbus/dbus-connection.c(3932):_dbus_connection_pop_message_link_unlocked] Message 0x894ef60 (signal /domainmanagement turaya.domain.manager iDidSomething 'i') removed from incoming queue 0x894c690, 1 incoming 8908: [dbus/dbus-connection.c(4535):dbus_connection_dispatch] dispatching message 0x894ef60 (signal turaya.domain.manager iDidSomething 'i') 8908: [dbus/dbus-connection.c(4587):dbus_connection_dispatch] UNLOCK 8908: [dbus/dbus-connection.c(4616):dbus_connection_dispatch] LOCK 8908: [dbus/dbus-connection.c(1114):_dbus_connection_acquire_io_path] LOCK 8908: [dbus/dbus-connection.c(4641):dbus_connection_dispatch] running object path dispatch on message 0x894ef60 (signal turaya.domain.manager iDidSomething 'i') 8908: [dbus/dbus-object-tree.c(818):_dbus_object_tree_dispatch_and_unlock] 1 handlers in the path tree for this message 8908: [dbus/dbus-object-tree.c(849):_dbus_object_tree_dispatch_and_unlock] unlock 8908: [dbus/dbus-connection.c(392):_dbus_connection_unlock] UNLOCK 8908: [dbus/dbus-transport.c(964):_dbus_transport_do_iteration] Transport iteration flags 0x6 timeout 24999 connected = 1 8908: [dbus/dbus-transport-socket.c(1047):socket_do_iteration] iteration flags = read timeout = 24999 read_watch = 0x894c2e0 write_watch = 0x894c2b8 fd = 6 8908: 8908: [dbus/dbus-connection.c(381):_dbus_connection_lock] LOCK [dbus/dbus-transport-socket.c(1120):socket_do_iteration] unlock pre poll 8908: [dbus/dbus-connection.c(392):_dbus_connection_unlock] UNLOCK 8908: [dbus/dbus-object-tree.c(889):_dbus_object_tree_dispatch_and_unlock] unlock 8908: [dbus/dbus-connection.c(392):_dbus_connection_unlock] UNLOCK 8908: [dbus/dbus-connection.c(4647):dbus_connection_dispatch] LOCK 8908: [dbus/dbus-connection.c(4651):dbus_connection_dispatch] object tree handled message in dispatch 8908: [dbus/dbus-connection.c(4738):dbus_connection_dispatch] ... done dispatching 8908: [dbus/dbus-connection.c(4095):_dbus_connection_release_dispatch] locking dispatch_mutex 8908: [dbus/dbus-connection.c(4103):_dbus_connection_release_dispatch] unlocking dispatch_mutex 8908: [dbus/dbus-connection.c(4749):dbus_connection_dispatch] before final status update 8908: [dbus/dbus-connection.c(4265):_dbus_connection_update_dispatch_status_and_unlock] UNLOCK 8908: [dbus/dbus-connection.c(4487):dbus_connection_dispatch] 8908: [dbus/dbus-connection.c(4489):dbus_connection_dispatch] LOCK 8908: [dbus/dbus-connection.c(4060):_dbus_connection_acquire_dispatch] UNLOCK 8908: [dbus/dbus-connection.c(4062):_dbus_connection_acquire_dispatch] locking dispatch_mutex 8908: [dbus/dbus-connection.c(4076):_dbus_connection_acquire_dispatch] unlocking dispatch_mutex 8908: [dbus/dbus-connection.c(4079):_dbus_connection_acquire_dispatch] LOCK 8908: [dbus/dbus-connection.c(3932):_dbus_connection_pop_message_link_unlocked] Message 0x894c9c0 (method_return no path no interface no member 'i') removed from incoming queue 0x894c690, 0 incoming 8908: [dbus/dbus-connection.c(4535):dbus_connection_dispatch] dispatching message 0x894c9c0 (method_return no interface no member 'i') 8908: [dbus/dbus-connection.c(4551):dbus_connection_dispatch] Dispatching a pending reply 8908: [dbus/dbus-pending-call.c(172):_dbus_pending_call_set_reply_unlocked] handing message 0x894c9c0 (method return) to pending call serial 14 8908: [dbus/dbus-connection.c(392):_dbus_connection_unlock] UNLOCK 8908: [dbus/dbus-connection.c(984):free_pending_call_on_hash_removal] LOCK 8908: [dbus/dbus-connection.c(392):_dbus_connection_unlock] UNLOCK 8908: [dbus/dbus-connection.c(4555):dbus_connection_dispatch] LOCK 8908: [dbus/dbus-connection.c(4556):dbus_connection_dispatch] pending call completed in dispatch 8908: [dbus/dbus-connection.c(4738):dbus_connection_dispatch] ... done dispatching 8908: [dbus/dbus-connection.c(4095):_dbus_connection_release_dispatch] locking dispatch_mutex 8908: [dbus/dbus-connection.c(4103):_dbus_connection_release_dispatch] unlocking dispatch_mutex 8908: [dbus/dbus-connection.c(4749):dbus_connection_dispatch] before final status update 8908: [dbus/dbus-connection.c(4194):_dbus_connection_get_dispatch_status_unlocked] dispatch status = complete is_connected = 1 8908: [dbus/dbus-connection.c(4265):_dbus_connection_update_dispatch_status_and_unlock] UNLOCK 8908: [dbus/dbus-connection.c(4271):_dbus_connection_update_dispatch_status_and_unlock] Notifying of change to dispatch status of 0x894c690 now 1 (complete) !!!!!!!!!!!!!!!!!!!at this point the 25 sec delay occurs!!!!!!!!!!!!!!!!!!!!!!!!!!!!! 8908: [dbus/dbus-transport-socket.c(1132):socket_do_iteration] lock post poll 8908: [dbus/dbus-connection.c(381):_dbus_connection_lock] LOCK 8908: [dbus/dbus-transport-socket.c(1153):socket_do_iteration] in iteration, need_read=0 need_write=0 8908: [dbus/dbus-transport-socket.c(165):check_write_watch] check_write_watch(): needed = 0 on connection 0x894c690 watch 0x894c2b8 fd = 6 outgoing messages exist 0 8908: [dbus/dbus-transport-socket.c(1188):socket_do_iteration] ... leaving do_iteration() 8908: [dbus/dbus-transport.c(978):_dbus_transport_do_iteration] end 8908: [dbus/dbus-connection.c(1135):_dbus_connection_release_io_path] locking io_path_mutex 8908: [dbus/dbus-connection.c(1141):_dbus_connection_release_io_path] start connection->io_path_acquired = 1 8908: [dbus/dbus-connection.c(1146):_dbus_connection_release_io_path] unlocking io_path_mutex 8908: [dbus/dbus-connection.c(1224):_dbus_connection_do_iteration_unlocked] end 8908: [dbus/dbus-connection.c(2412):_dbus_connection_block_pending_call] top of recheck 8908: [dbus/dbus-connection.c(4194):_dbus_connection_get_dispatch_status_unlocked] dispatch status = complete is_connected = 1 8908: [dbus/dbus-connection.c(2425):_dbus_connection_block_pending_call] Pending call completed by dispatch 8908: [dbus/dbus-connection.c(4265):_dbus_connection_update_dispatch_status_and_unlock] UNLOCK 8908: [dbus/dbus-connection.c(381):_dbus_connection_lock] LOCK 8908: [dbus/dbus-connection.c(392):_dbus_connection_unlock] UNLOCK 8908: [dbus/dbus-dataslot.c(184):_dbus_data_slot_allocator_free] Freeing slot 0 on allocator 0xb702c408 total 1 allocated 1 use