Starting dbus-based user-service fails with a timeout

[voidus]

Submission type

• Bug report
• Request for enhancement (RFE)

NOTE: Do not submit anything other than bug reports or RFEs via the issue tracker!

systemd version the issue has been seen with

231

Used distribution

Arch linux

In case of bug report: Expected behaviour you didn't see

systemctl --user start gvfs-daemon succesfully starts the service

In case of bug report: Unexpected behaviour you saw

systemctl --user start gvfs-daemon times out

In case of bug report: Steps to reproduce the problem

systemctl --user start gvfs-daemon

This problem seems hard to reproduce. It has been reported on the unix stackexchange[1] before I encountered it, but that's about it.

When I run dbus-monitor during systemctl --user start gvfs-daemon on a system that is not affected by this bug, the first entry is

method call time=1478174361.631801 sender=:1.0 -> destination=org.freedesktop.DBus serial=13 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=AddMatch
   string "type='signal',sender='org.freedesktop.DBus',path='/org/freedesktop/DBus',interface='org.freedesktop.DBus',member='NameOwnerChanged',arg0='org.gtk.vfs.Daemon'"

This entry is missing on the system that has this issue.

Update: systemd is not connected to the session bus. Running busctl --user | grep systemd1 shows the following line:

org.freedesktop.systemd1                         - -               -                (activatable) -                         -

Any help on how to debug this further would be appreciated.
See my downstream issue[2] for more details.

[1] https://unix.stackexchange.com/questions/308036/why-does-gvfs-with-systemd-dbus-timeout
[2] https://bugs.archlinux.org/task/50871

[poettering]

Hmm, so how does your gvfs-daemon.service look like? And who provides it? And what does gvfs-daemon hang in if it hangs?

I am not entirely sure what we can do from the systemd side about htis...

[voidus]

Thank you for your quick feedback. Here's the unit file, it is shipped with the arch linux "gvfs" package.

voyd@kanne> cat /usr/lib/systemd/user/gvfs-daemon.service
[Unit]
Description=Virtual filesystem service

[Service]
ExecStart=/usr/lib/gvfs/gvfsd
Type=dbus
BusName=org.gtk.vfs.Daemon

When I run systemctl --user start gvfs-daemon, I can use dbus-monitor to observe that the name "org.gtk.vfs.Daemon" is really acquired, but systemd doesn't seem to notice that. This causes systemd to kill it after a timeout and assume it did not start correctly:

voyd@kanne> systemctl --user status gvfs-daemon
● gvfs-daemon.service - Virtual filesystem service
   Loaded: loaded (/usr/lib/systemd/user/gvfs-daemon.service; static; vendor preset: enabled)
   Active: failed (Result: timeout) since Do 2016-11-03 13:04:59 CET; 1h 57min ago
  Process: 30234 ExecStart=/usr/lib/gvfs/gvfsd (code=killed, signal=TERM)
 Main PID: 30234 (code=killed, signal=TERM)
   CGroup: /user.slice/user-1000.slice/user@1000.service/gvfs-daemon.service

Nov 03 13:03:29 kanne systemd[1616]: Starting Virtual filesystem service...
Nov 03 13:04:59 kanne systemd[1616]: gvfs-daemon.service: Start operation timed out. Terminating.
Nov 03 13:04:59 kanne systemd[1616]: Failed to start Virtual filesystem service.
Nov 03 13:04:59 kanne systemd[1616]: gvfs-daemon.service: Unit entered failed state.
Nov 03 13:04:59 kanne systemd[1616]: gvfs-daemon.service: Failed with result 'timeout'.

I think the problem behind this is that systemd is not connected to the session bus, as indicated by busctl --user showing it as (activatable) and the missing "AddMatch" dbus message. (See the original post)

[mbiebl]

Looks like this is happening on Debian as well
https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=841740

[voidus]

The debian issue seems related to me, but I am able to use applications after their dependencies timed out. For example, starting zathura (a pdf reader) works, but takes a very long time. Besides application startup, opening a file chooser dialog is significantly delayed, too.

[falconindy]

As mentioned on IRC, this isn't a bug. The user had a drop-in for user@.service which perturbed DBUS_SESSION_BUS_ADDRESS, causing systemd to never connect to the user bus.