Fix for test-bus unit test on Windows while running the check_segfault_no_auto_start test

Yiyang Fei yiyangfei36 at yahoo.com
Tue Apr 26 00:16:23 UTC 2016


Hi,
The test-bus unit test on Windows systems fails during the check_segfault_no_auto_start test.  The output of the error is as follows:

8740: [bus\dispatch.c(389):bus_dispatch] Giving message to org.freedesktop.DBus8740: [bus\driver.c(2653):bus_driver_handle_message] Driver got a method call: StartServiceByName8740: [bus\driver.c(2671):bus_driver_handle_message] Found driver handler for StartServiceByName8740: [bus\connection.c(2586):bus_transaction_add_cancel_hook]      adding cancel hook function = 00007FF70D762EE0 data = 000001E176D9F7A08740: [bus\activation.c(1527):add_cancel_pending_to_transaction] Saved pending activation to be canceled if the transaction fails8740: [bus\activation.c(2134):bus_activation_activate_service] Spawning c:/program ...Activating service name='org.freedesktop.DBus.TestSuiteSegfaultService'8740: [dbus\dbus-sysdeps-win.c(1141):_dbus_socketpair] full-duplex pipe 712:712 <-> 744:7448740: [dbus\dbus-spawn-win.c(597):babysitter] babysitter: spawning org.freedesktop.DBus.TestSuiteSegfaultService8740: [dbus\dbus-watch.c(318):_dbus_watch_list_set_functions] Adding a read watch on fd 712 using newly-set add watch function8740: [dbus\dbus-socket-set-poll.c(146):socket_set_poll_add] before adding fd 712 to 000001E176D99280, 4 en/4 res/9 alloc8740: [bus\driver.c(2691):bus_driver_handle_message] Driver handler succeeded8740: [bus\signals.c(1333):bus_matchmaker_get_rules] Looking up rules for message_type 0, interface <null>8740: [bus\signals.c(1333):bus_matchmaker_get_rules] Looking up rules for message_type 0, interface org.freedesktop.DBus8740: [bus\signals.c(1333):bus_matchmaker_get_rules] Looking up rules for message_type 1, interface <null>8740: [bus\signals.c(1333):bus_matchmaker_get_rules] Looking up rules for message_type 1, interface org.freedesktop.DBus8740: [bus\signals.c(2079):get_recipients_from_list] Checking whether message matches rule  for connection 000001E176DAE6308740: [bus\signals.c(2079):get_recipients_from_list] Checking whether message matches rule  for connection 000001E176DAE1F08740: [bus\signals.c(2079):get_recipients_from_list] Checking whether message matches rule  for connection 000001E176DAEDA08740: [bus\connection.c(2511):bus_transaction_execute_and_free] TRANSACTION: executing8740: [dbus\dbus-connection.c(4716):dbus_connection_dispatch] LOCK8740: [dbus\dbus-connection.c(4725):dbus_connection_dispatch] filter handled message in dispatch8740: [dbus\dbus-connection.c(4856):dbus_connection_dispatch]  ... done dispatching8740: [dbus\dbus-connection.c(4169):_dbus_connection_release_dispatch] locking dispatch_mutex8740: [dbus\dbus-connection.c(4177):_dbus_connection_release_dispatch] unlocking dispatch_mutex8740: [dbus\dbus-connection.c(406):_dbus_connection_unlock] UNLOCK8740: [dbus\dbus-connection.c(4873):dbus_connection_dispatch] LOCK8740: [dbus\dbus-connection.c(4879):dbus_connection_dispatch] before final status update8740: [dbus\dbus-connection.c(4268):_dbus_connection_get_dispatch_status_unlocked] dispatch status = complete is_connected = 18740: [dbus\dbus-connection.c(406):_dbus_connection_unlock] UNLOCK8740: [dbus\dbus-connection.c(4345):_dbus_connection_update_dispatch_status_and_unlock] Notifying of change to dispatch status of 000001E176DAE630 now 1 (complete)8740: [dbus\dbus-sysdeps-win.c(1358):_dbus_poll] select: to=0 R:136 E:136 R:364 E:364 R:424 E:424 R:480 E:480 R:712 E:712 [dbus\dbus-sysdeps-win.c(1388):_dbus_poll] select: = 08740: [dbus\dbus-sysdeps-win.c(1358):_dbus_poll] select: to=0 R:360 E:360 R:420 E:420 R:476 E:476 [dbus\dbus-sysdeps-win.c(1388):_dbus_poll] select: = 08740: [bus\dispatch.c(557):block_connection_until_message_from_bus] expecting: reply to activating segfault service8740: [dbus\dbus-connection.c(4384):dbus_connection_get_dispatch_status] start8740: [dbus\dbus-connection.c(4386):dbus_connection_get_dispatch_status] LOCK8740: [dbus\dbus-connection.c(4268):_dbus_connection_get_dispatch_status_unlocked] dispatch status = complete is_connected = 18740: [dbus\dbus-connection.c(406):_dbus_connection_unlock] UNLOCK8740: [dbus\dbus-connection.c(2979):dbus_connection_get_is_connected] LOCK8740: [dbus\dbus-connection.c(406):_dbus_connection_unlock] UNLOCK8740: [bus\test.c(233):bus_test_run_bus_loop] ---> Dispatching on "server side"8740: [bus\test.c(243):bus_test_run_bus_loop] ---> blocking on "server side"8740: [dbus\dbus-sysdeps-win.c(1358):_dbus_poll] select: to=3000 R:136 E:136 R:364 E:364 R:424 E:424 R:480 E:480 R:712 E:712 [dbus\dbus-sysdeps-win.c(1388):_dbus_poll] select: = 0Failed to activate service 'org.freedesktop.DBus.TestSuiteSegfaultService': timed out8740: [dbus\dbus-connection.c(2979):dbus_connection_get_is_connected] LOCK8740: [dbus\dbus-connection.c(406):_dbus_connection_unlock] UNLOCK8740: [bus\connection.c(2554):bus_transaction_send_error_reply] Sending error reply org.freedesktop.DBus.Error.TimedOut "Failed to activate service 'org.freedesktop.DBus.TestSuiteSegfaultService': timed out"8740: [bus\connection.c(2277):bus_transaction_send_from_driver] Sending (no interface) (no member) org.freedesktop.DBus.Error.TimedOut from driver8740: [bus\policy.c(1068):bus_client_policy_check_can_receive]   (policy) checking receive rules, eavesdropping = 08740: [bus\policy.c(1081):bus_client_policy_check_can_receive]   (policy) skipping non-receive rule8740: [bus\policy.c(1237):bus_client_policy_check_can_receive]   (policy) used rule, allow now = 18740: [bus\policy.c(1081):bus_client_policy_check_can_receive]   (policy) skipping non-receive rule8740: [dbus\dbus-connection.c(6298):dbus_connection_get_outgoing_size] LOCK8740: [dbus\dbus-connection.c(406):_dbus_connection_unlock] UNLOCK8740: [dbus\dbus-connection.c(6359):dbus_connection_get_outgoing_unix_fds] LOCK8740: [dbus\dbus-connection.c(406):_dbus_connection_unlock] UNLOCK8740: [bus\bus.c(1778):bus_context_check_security_policy] security policy allowing message8740: [dbus\dbus-connection.c(2979):dbus_connection_get_is_connected] LOCK8740: [dbus\dbus-connection.c(406):_dbus_connection_unlock] UNLOCK8740: [bus\connection.c(2343):bus_transaction_send]   trying to add error interface=(unset) member=(unset) error=org.freedesktop.DBus.Error.TimedOut to transaction8740: [dbus\dbus-connection.c(2979):dbus_connection_get_is_connected] LOCK8740: [dbus\dbus-connection.c(406):_dbus_connection_unlock] UNLOCK8740: [dbus\dbus-connection.c(3171):dbus_connection_preallocate_send] LOCK8740: [dbus\dbus-connection.c(406):_dbus_connection_unlock] UNLOCK8740: [bus\connection.c(2370):bus_transaction_send] about to prepend message8740: [bus\connection.c(2378):bus_transaction_send] prepended message8740: [bus\connection.c(2511):bus_transaction_execute_and_free] TRANSACTION: executing8740: [dbus\dbus-connection.c(3232):dbus_connection_send_preallocated] LOCK8740: [dbus\dbus-connection.c(2034):_dbus_connection_send_preallocated_unlocked_no_update] Message 000001E176DC0A00 (error no path no interface no member 's') for :1.0 added to outgoing queue 000001E176DAE630, 1 pending to send8740: [dbus\dbus-connection.c(2050):_dbus_connection_send_preallocated_unlocked_no_update] Message 000001E176DC0A00 serial is 408740: [dbus\dbus-connection.c(1203):_dbus_connection_do_iteration_unlocked] start8740: [dbus\dbus-connection.c(406):_dbus_connection_unlock] UNLOCK8740: [dbus\dbus-connection.c(1074):_dbus_connection_acquire_io_path] locking io_path_mutex8740: [dbus\dbus-connection.c(1078):_dbus_connection_acquire_io_path] start connection->io_path_acquired = 0 timeout = 08740: [dbus\dbus-connection.c(1121):_dbus_connection_acquire_io_path] end connection->io_path_acquired = 1 we_acquired = 18740: [dbus\dbus-connection.c(1123):_dbus_connection_acquire_io_path] unlocking io_path_mutex8740: [dbus\dbus-connection.c(1126):_dbus_connection_acquire_io_path] LOCK8740: [dbus\dbus-transport.c(991):_dbus_transport_do_iteration] Transport iteration flags 0x1 timeout -1 connected = 18740: [dbus\dbus-transport-socket.c(1087):socket_do_iteration]  iteration flags = write timeout = -1 read_watch = 000001E176DAB180 write_watch = 000001E176DAB9F0 fd = 3648740: [dbus\dbus-transport-socket.c(520):do_writing] do_writing(), have_messages = 1, fd = 3648740: [dbus\dbus-sysdeps-win.c(621):_dbus_write_socket_two] WSASend: len1+2=128+90 fd=3648740: [dbus\dbus-sysdeps-win.c(637):_dbus_write_socket_two] WSASend: = 2188740: [dbus\dbus-transport-socket.c(707):do_writing]  wrote 218 bytes of 2188740: [dbus\dbus-connection.c(660):_dbus_connection_message_sent_unlocked] Message 000001E176DC0A00 (error no path no interface no member 's') removed from outgoing queue 000001E176DAE630, 0 left to send8740: [dbus\dbus-transport-socket.c(165):check_write_watch] check_write_watch(): needed = 0 on connection 000001E176DAE630 watch 000001E176DAB9F0 fd = 364 outgoing messages exist 08740: [dbus\dbus-transport-socket.c(1231):socket_do_iteration]  ... leaving do_iteration()8740: [dbus\dbus-transport.c(1005):_dbus_transport_do_iteration] end8740: [dbus\dbus-connection.c(1147):_dbus_connection_release_io_path] locking io_path_mutex8740: [dbus\dbus-connection.c(1153):_dbus_connection_release_io_path] start connection->io_path_acquired = 18740: [dbus\dbus-connection.c(1158):_dbus_connection_release_io_path] unlocking io_path_mutex8740: [dbus\dbus-connection.c(1236):_dbus_connection_do_iteration_unlocked] end8740: [dbus\dbus-connection.c(2081):_dbus_connection_send_preallocated_and_unlock] middle8740: [dbus\dbus-connection.c(4268):_dbus_connection_get_dispatch_status_unlocked] dispatch status = complete is_connected = 18740: [dbus\dbus-connection.c(406):_dbus_connection_unlock] UNLOCK8740: [dbus\dbus-watch.c(354):_dbus_watch_list_set_functions] Removing all pre-existing watches8740: [dbus\dbus-socket-set-poll.c(221):socket_set_poll_remove] after removing fd 712 from 000001E176D99280, 4 en/4 res/9 alloc8740: [dbus\dbus-sysdeps-win.c(1358):_dbus_poll] select: to=0 R:136 E:136 R:364 E:364 R:424 E:424 R:480 E:480 [dbus\dbus-sysdeps-win.c(1388):_dbus_poll] select: = 08740: [bus\test.c(251):bus_test_run_bus_loop] ---> Done dispatching on "server side"8740: [bus\test.c(208):bus_test_run_clients_loop] ---> Dispatching on "client side"8740: [dbus\dbus-sysdeps-win.c(1358):_dbus_poll] select: to=0 R:360 E:360 R:420 E:420 R:476 E:476 [dbus\dbus-sysdeps-win.c(1410):_dbus_poll] select: = 1: R:360 [dbus\dbus-connection.c(1496):_dbus_connection_handle_watch] start8740: [dbus\dbus-connection.c(1498):_dbus_connection_handle_watch] LOCK8740: [dbus\dbus-connection.c(406):_dbus_connection_unlock] UNLOCK8740: [dbus\dbus-connection.c(1074):_dbus_connection_acquire_io_path] locking io_path_mutex8740: [dbus\dbus-connection.c(1078):_dbus_connection_acquire_io_path] start connection->io_path_acquired = 0 timeout = 18740: [dbus\dbus-connection.c(1121):_dbus_connection_acquire_io_path] end connection->io_path_acquired = 1 we_acquired = 18740: [dbus\dbus-connection.c(1123):_dbus_connection_acquire_io_path] unlocking io_path_mutex8740: [dbus\dbus-connection.c(1126):_dbus_connection_acquire_io_path] LOCK8740: [dbus\dbus-transport-socket.c(959):socket_handle_watch] handling read watch 000001E176DAB090 flags = 18740: [dbus\dbus-transport-socket.c(746):do_reading] fd = 3608740: [dbus\dbus-transport-socket.c(181):check_read_watch] fd = 3608740: [dbus\dbus-transport-socket.c(227):check_read_watch]   setting read watch enabled = 18740: [dbus\dbus-sysdeps-win.c(400):_dbus_read_socket] recv: count=2048 fd=3608740: [dbus\dbus-sysdeps-win.c(410):_dbus_read_socket] recv: = 2188740: [dbus\dbus-transport-socket.c(887):do_reading]  read 218 bytes8740: [dbus\dbus-marshal-header.c(747):_dbus_header_have_message_untrusted] have 218 bytes, need body 90 + header 128 = 2188740: [dbus\dbus-marshal-validate.c(723):_dbus_validate_body_with_reason] validating body from pos 0 len 218 sig 'yyyyuua(yv)'8740: [dbus\dbus-marshal-validate.c(548):validate_body_helper] p = 000001E176DB1E0F end = 000001E176DB1E8A claimed_len 18740: [dbus\dbus-marshal-header.c(821):load_and_validate_field] initially caching field 68740: [dbus\dbus-marshal-header.c(821):load_and_validate_field] initially caching field 48740: [dbus\dbus-marshal-header.c(821):load_and_validate_field] initially caching field 58740: [dbus\dbus-marshal-header.c(821):load_and_validate_field] initially caching field 88740: [dbus\dbus-marshal-header.c(821):load_and_validate_field] initially caching field 78740: [dbus\dbus-marshal-validate.c(723):_dbus_validate_body_with_reason] validating body from pos 128 len 90 sig 's'8740: [dbus\dbus-message.c(4334):load_message] Loaded message 000001E176DC0A008740: [dbus\dbus-transport.c(1159):_dbus_transport_queue_messages] queueing received message 000001E176DC0A008740: [dbus\dbus-transport-socket.c(181):check_read_watch] fd = 3608740: [dbus\dbus-transport-socket.c(227):check_read_watch]   setting read watch enabled = 18740: [dbus\dbus-connection.c(530):_dbus_connection_queue_received_message_link] Message 000001E176DC0A00 (error no path no interface no member 's' reply to 38) added to incoming queue 000001E176DAE0E0, 1 incoming8740: [dbus\dbus-transport-socket.c(181):check_read_watch] fd = 3608740: [dbus\dbus-transport-socket.c(227):check_read_watch]   setting read watch enabled = 18740: [dbus\dbus-sysdeps-win.c(400):_dbus_read_socket] recv: count=2048 fd=3608740: [dbus\dbus-sysdeps-win.c(406):_dbus_read_socket] recv: failed: Resource temporarily unavailable (10035)8740: [dbus\dbus-connection.c(1147):_dbus_connection_release_io_path] locking io_path_mutex8740: [dbus\dbus-connection.c(1153):_dbus_connection_release_io_path] start connection->io_path_acquired = 18740: [dbus\dbus-connection.c(1158):_dbus_connection_release_io_path] unlocking io_path_mutex8740: [dbus\dbus-connection.c(1515):_dbus_connection_handle_watch] middle8740: [dbus\dbus-connection.c(406):_dbus_connection_unlock] UNLOCK8740: [dbus\dbus-connection.c(1522):_dbus_connection_handle_watch] end8740: [dbus\dbus-sysdeps-win.c(1358):_dbus_poll] select: to=0 R:360 E:360 R:420 E:420 R:476 E:476 [dbus\dbus-sysdeps-win.c(1388):_dbus_poll] select: = 08740: [bus\test.c(226):bus_test_run_clients_loop] ---> Done dispatching on "client side"8740: [dbus\dbus-connection.c(4384):dbus_connection_get_dispatch_status] start8740: [dbus\dbus-connection.c(4386):dbus_connection_get_dispatch_status] LOCK8740: [dbus\dbus-connection.c(406):_dbus_connection_unlock] UNLOCK8740: [dbus\dbus-sysdeps-win.c(1358):_dbus_poll] select: to=0 R:136 E:136 R:364 E:364 R:424 E:424 R:480 E:480 [dbus\dbus-sysdeps-win.c(1388):_dbus_poll] select: = 08740: [dbus\dbus-sysdeps-win.c(1358):_dbus_poll] select: to=0 R:360 E:360 R:420 E:420 R:476 E:476 [dbus\dbus-sysdeps-win.c(1388):_dbus_poll] select: = 08740: [dbus\dbus-connection.c(2979):dbus_connection_get_is_connected] LOCK8740: [dbus\dbus-connection.c(406):_dbus_connection_unlock] UNLOCK8740: [dbus\dbus-connection.c(4384):dbus_connection_get_dispatch_status] start8740: [dbus\dbus-connection.c(4386):dbus_connection_get_dispatch_status] LOCK8740: [dbus\dbus-connection.c(406):_dbus_connection_unlock] UNLOCK8740: [dbus\dbus-connection.c(4096):dbus_connection_pop_message] start8740: [dbus\dbus-connection.c(4384):dbus_connection_get_dispatch_status] start8740: [dbus\dbus-connection.c(4386):dbus_connection_get_dispatch_status] LOCK8740: [dbus\dbus-connection.c(406):_dbus_connection_unlock] UNLOCK8740: [dbus\dbus-connection.c(4105):dbus_connection_pop_message] LOCK8740: [dbus\dbus-connection.c(406):_dbus_connection_unlock] UNLOCK8740: [dbus\dbus-connection.c(4136):_dbus_connection_acquire_dispatch] locking dispatch_mutex8740: [dbus\dbus-connection.c(4150):_dbus_connection_acquire_dispatch] unlocking dispatch_mutex8740: [dbus\dbus-connection.c(4153):_dbus_connection_acquire_dispatch] LOCK8740: [dbus\dbus-connection.c(4000):_dbus_connection_pop_message_link_unlocked] Message 000001E176DC0A00 (error no path no interface no member sig:'s' serial:40) removed from incoming queue 000001E176DAE0E0, 0 incoming8740: [dbus\dbus-connection.c(4111):dbus_connection_pop_message] Returning popped message 000001E176DC0A008740: [dbus\dbus-connection.c(4169):_dbus_connection_release_dispatch] locking dispatch_mutex8740: 8740: [dbus\dbus-spawn-win.c(163):close_socket_to_babysitter] [dbus\dbus-connection.c(4177):_dbus_connection_release_dispatch] Closing babysitterunlocking dispatch_mutex8740: [dbus\dbus-connection.c(4268):_dbus_connection_get_dispatch_status_unlocked] dispatch status = complete is_connected = 18740: 8740: [dbus\dbus-watch.c(686):dbus_watch_set_data] [dbus\dbus-connection.c(406):_dbus_connection_unlock] Setting watch fd 18446744073709551615 data to data = 0000000000000000 function = 0000000000000000 from data = 0000000000000000 function = 0000000000000000UNLOCK8740: [bus\dispatch.c(640):verbose_message_received] Received message interface "(unset)" member "(unset)" error name "org.freedesktop.DBus.Error.TimedOut" on 000001E176DAE0E0check_segfault_service_no_auto_start:3043 received message interface "(unset)" member "(unset)" error name "org.freedesktop.DBus.Error.TimedOut" on 000001E176DAE0E0, expecting not this errorsegfault_service_no_auto_start failed during oomFile "X:\qaweb\dbus\bus\dispatch.c" line 4736 process 8740 should not have been reached: test failed8740: [dbus\dbus-sysdeps-win.c(2687):_dbus_print_backtrace]   D-Bus not compiled with backtrace support8740: [dbus\dbus-sysdeps-win.c(510):_dbus_close_socket] _dbus_close_socket: socket=712, 

Since test-segfault.exe application never claims the requested service, it makes sense that DBUS_ERROR_TIMED_OUT is returned.  It seems like the following change should be made to dispatch.c:
diff --git a/bus/dispatch.c b/bus/dispatch.cindex edfa1b4..680cad3 100644--- a/bus/dispatch.c+++ b/bus/dispatch.c@@ -3026,6 +3026,11 @@ check_segfault_service_no_auto_start (BusContext     *context,         {           /* unhandled exceptions are normal exit codes */         }+      else if (dbus_message_is_error (message,+                                      DBUS_ERROR_TIMED_OUT))+        {+          /* If a service quits unexpectedly, a time out error is expected */+        } #else       else if (dbus_message_is_error (message,                                       DBUS_ERROR_SPAWN_CHILD_SIGNALED))

Yiyang Fei
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.freedesktop.org/archives/dbus/attachments/20160426/d5038576/attachment-0001.html>


More information about the dbus mailing list