systemd dbus activation timeout on first try

[laped83]

Hi. Iam trying to create an dbus service that is activated when needed by systemd like described in section (DBus activation) in the following link.

https://fedoraproject.org/wiki/Packaging:Systemd#DBus_activation

My issue is that the service is started but the first dbus call, that activated it, times out but the following calls afterwards works. I have tried to boil it down to the following code that can reproduce it.

Maybe I have misunderstood how to use adbus and I'm still pretty new in the async world. I appreciate any help and hope you can reproduce this issue with the following wall of text :)

I have tried to implement that the same Foo service as show in (which works in the first try):

https://github.com/stylesuxx/python-dbus-examples/blob/master/receiver.py

dbus service (receiver py)

#!/usr/bin/env python3
import adbus
import asyncio

service_name = 'sub.domain.tld'
object_path = '/tld/domain/sub/Test'
object_interface = 'tld.domain.sub.TestInterface'

class FooService(adbus.server.Object):
    def __init__(self, service):
        super().__init__(service, object_path, object_interface)

    @adbus.server.method()
    def foo(self) -> str:
        return 'Foo'

loop = asyncio.get_event_loop()

service = adbus.Service(service_name, bus='system', replace_existing=True, allow_replacement=True)

obj = FooService(service)

loop.run_forever()

systemd service unit file

cat /usr/lib/systemd/system/dbus-sub.domain.tld.service 
[Unit]
Description=Sub tld service test

[Service]
Type=dbus
BusName=sub.domain.tld
ExecStart=python3 /home/laa/git/cons/octopus/receiver.py
User=username

systemd system-services

cat /usr/share/dbus-1/system-services/sub.domain.tld.service 
[D-BUS Service]
Name=sub.domain.tld
SystemdService=dbus-sub.domain.tld.service

# This service should not be bus activated if systemd isn't running,
# so that activation won't conflict with the init script startup.
Exec=/bin/false

Allow dbus service

cat /etc/dbus-1/system.d/sub.domain.tld.conf 
<!DOCTYPE busconfig PUBLIC
 "-//freedesktop//DTD D-BUS Bus Configuration 1.0//EN"
 "http://www.freedesktop.org/standards/dbus/1.0/busconfig.dtd">
<busconfig>
  <policy user="username">
    <allow own="sub.domain.tld"/>
  </policy>
  <policy context="default">
    <allow send_destination="sub.domain.tld"/>
  </policy>
</busconfig>

Environment

cat /etc/redhat-release 
Fedora release 32 (Thirty Two

systemctl --version
systemd 245 (v245.4-1.fc32)

Python 3.8.2 (default, Feb 28 2020, 00:00:00) 
[GCC 10.0.1 20200216 (Red Hat 10.0.1-0.8)] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import adbus
>>> adbus.__version__
'1.1.1'

Output

time busctl call sub.domain.tld /tld/domain/sub/Test tld.domain.sub.TestInterface Foo 
Call failed: Connection timed out
real	0m25.017s
user	0m0.006s
sys	0m0.006s
 time busctl call sub.domain.tld /tld/domain/sub/Test tld.domain.sub.TestInterface Foo 
s "Foo"

real	0m0.013s
user	0m0.003s
sys	0m0.008s

[laped83]

Added wireshark trace for both a working and a non working situation

Working old style dbus python binding:
1.668 - Terminal/User call
1.669 - Activated service (tld.domain.sub.TestInterface foo)

Non working service using adbus (Times out after 25 seconds)
1.646 - Terminal User call
1.647 - Activated service (tld.domain.sub.TestInterface Foo)

wireshark_trace.zip

[laped83]

Created this gif that should show the issue. busctl method is called (with timeout 10 seconds) for the dbus-sub.domain.tld (reveiver.py) and service is started by systemd as shown in journalctl. But as shown the first call times out after 10 seconds and only the following call works when the service allready is started.

[charleseidsness]

Resolved with PR #65