Package: python3-dbusmock
Version: 0.34.3-1
Severity: important
Tags: unreproducible
Control: affects -1 + src:mutter
User: debian...@lists.debian.org
Usertags: flaky

After my recent upload of mutter 48.4-2 to unstable, its autopkgtest 
failed on ppc64el. At least one of the failures (monitor-unit.test) had 
this logged, and the test subsequently timed out:

https://ci.debian.net/packages/m/mutter/testing/ppc64el/62167381/
https://ci.debian.net/data/autopkgtest/testing/ppc64el/m/mutter/62167381/artifacts.tar.gz
> Starting mocked services...
> Traceback (most recent call last):
>   File 
> "/usr/libexec/installed-tests/mutter-16/mutter-installed-dbus-session.py", 
> line 22, in <module>
>     result = meta_run(MutterDBusRunner,
>                       extra_env=extra_env,
>                       setup_argparse=add_extra_args,
>                       handle_argparse=handle_extra_args)
>   File "/usr/share/mutter-16/tests/mutter_dbusrunner.py", line 325, in 
> meta_run
>     return run_test_mocked(klass, rest,
>                            launch=args.launch,
>                            bind_sockets=True,
>                            extra_env=extra_env)
>   File "/usr/share/mutter-16/tests/mutter_dbusrunner.py", line 271, in 
> run_test_mocked
>     klass.setUpClass(launch=launch,
>     ~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^
>                      bind_sockets=bind_sockets)
>                      ^^^^^^^^^^^^^^^^^^^^^^^^^^
>   File "/usr/share/mutter-16/tests/mutter_dbusrunner.py", line 67, in 
> setUpClass
>     (klass.mocks_manager, klass.mock_obj) = klass.start_from_local_template(
>                                             ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^
>         'meta-mocks-manager', {'templates-dir': klass.__get_templates_dir()})
>         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
>   File "/usr/share/mutter-16/tests/mutter_dbusrunner.py", line 119, in 
> start_from_local_template
>     return klass.start_from_template(template, params, system_bus=system_bus)
>            ~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
>   File "/usr/share/mutter-16/tests/mutter_dbusrunner.py", line 108, in 
> start_from_template
>     klass.spawn_server_template(template,
>     ~~~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^
>                                 params,
>                                 ^^^^^^^
>                                 get_subprocess_stdout(),
>                                 ^^^^^^^^^^^^^^^^^^^^^^^^
>                                 system_bus=system_bus)
>                                 ^^^^^^^^^^^^^^^^^^^^^^
>   File "/usr/lib/python3/dist-packages/dbusmock/testcase.py", line 438, in 
> spawn_server_template
>     server = SpawnedMock.spawn_with_template(template, parameters, bustype, 
> stdout, stderr=None)
>   File "/usr/lib/python3/dist-packages/dbusmock/testcase.py", line 614, in 
> spawn_with_template
>     server = SpawnedMock.spawn_for_name(module.BUS_NAME, module.MAIN_OBJ, 
> interface_name, bustype, stdout, stderr)
>   File "/usr/lib/python3/dist-packages/dbusmock/testcase.py", line 557, in 
> spawn_for_name
>     bus = bustype.get_connection()
>   File "/usr/lib/python3/dist-packages/dbusmock/testcase.py", line 58, in 
> get_connection
>     return dbus.bus.BusConnection(val)
>            ~~~~~~~~~~~~~~~~~~~~~~^^^^^
>   File "/usr/lib/python3/dist-packages/dbus/bus.py", line 120, in __new__
>     bus = cls._new_for_bus(address_or_type, mainloop=mainloop)
> dbus.exceptions.DBusException: org.freedesktop.DBus.Error.NoServer: Failed to 
> connect to socket /tmp/dbusmock_data_nh20oy7q/system_bus.socket: Connection 
> refused

I think this indicates that dbusmock started a dbus-daemon to be the 
mock system bus, but then attempted to connect to the socket before the 
dbus-daemon was listening on that socket. There is a (very) short window 
of time between bind() and listen() during which connection attempts 
will fail.

If my theory is correct, this will be difficult to reproduce on-demand: 
you would have to be very unlucky with how processes get scheduled.

dbus-daemon provides two mechanisms to avoid this race condition window:

1. If you run it with --print-address=FD and/or --print-pid=FD, and then 
read until EOF on the given file descriptor(s) (often 1 for stdout, but 
may be any writeable fd), then the read will block until after the 
dbus-daemon has called listen(), closing the race condition. This is how 
dbus-run-session(1) is implemented.

2. Or, if you run it with --fork, it will "daemonize" and the foreground 
process will not exit until the background process has called listen(). 
This is how dbus-launch(1) is implemented.

I would recommend (1.), blocking on a read() until --print-address or 
--print-pid has produced its result (you can ignore the printed address 
or pid if you don't need it). For example test/gvfs-test in 
gvfs_1.57.2-2 and tests/test-dconf.py in dconf_0.40.0-5 both do this, in 
a way that should be compatible with dbusmock's use of subprocess.Popen.

Thanks,
    smcv

Reply via email to