[Pkg-utopia-maintainers] Bug#1018880: dbus-user-session: GNOME applications such as evince and nautilus start with a 25-second delay via ssh

[Simon McVittie]

Control: retitle -1 under ssh X11 forwarding, apps like nautilus that use xdg-desktop-portal start with 25s delay
Control: affects -1 + nautilus evince xdg-desktop-portal xdg-desktop-portal-gtk

On Wed, 07 Sep 2022 at 11:35:52 +0200, Vincent Lefevre wrote:
> On 2022-09-07 09:19:26 +0100, Simon McVittie wrote:
> > If you're expecting graphical applications to work "when I connect by
> > ssh", then presumably you're doing *something* that you're not saying
> 
> X11 forwarding.

Thank you, that is the crucial piece of missing context that I needed.

> > In a Debian X11 environment, /etc/X11/Xsession.d/20dbus_xdg-runtime is
> > meant to do something similar for you, so if you are in an X11 environment
> > where that's not working, either something has gone wrong somewhere or
> > your X11 environment is not participating in Debian's system-integration
> > mechanisms.
> 
> But /etc/X11/Xsession.d/20dbus_xdg-runtime isn't run via ssh, AFAIK.

Yes, X11 forwarding is an example of an X11 environment that doesn't
participate in Debian's X11 integration. There has never been a particularly
coherent design for how X11 forwarding should fit into the D-Bus session
bus, or into systemd user sessions.

> > It might help to try to reproduce a minimal version of the same problem
> > in a virtual machine, perhaps starting from one of the Debian Live images.

A minimal reproducer seems to be:

- boot a text-mode session (I used debian-live-11.4.0-amd64-standard.iso)
- sudo apt update
- sudo apt install openssh-server
- sudo systemctl enable --now ssh
- enable a ssh login (ssh-import-id is a useful way to do this quickly)
- sudo apt install nautilus
- (xdg-desktop-portal-gtk is pulled in as a dependency, this is significant)

and from another machine, in a ssh -X session:

- echo $DISPLAY
- nautilus

Expected result: nautilus starts quickly.

Actual result: it takes a while.

Looking at the systemd journal, I think the problem here is the interaction
between xdg-desktop-portal, its desktop-specific implementation (in this
case xdg-desktop-portal-gtk), and X11 forwarding:

> Sep 07 10:19:22 debian dbus-daemon[5956]: [session uid=1000 pid=5956] Activating via systemd: service name='org.freedesktop.portal.Desktop' unit='xdg-desktop-portal.service' requested by ':1.1' (uid=1000 pid=5954 comm="nautilus ")
> Sep 07 10:19:22 debian systemd[1201]: Starting Portal service...
...
> Sep 07 10:19:22 debian dbus-daemon[5956]: [session uid=1000 pid=5956] Activating via systemd: service name='org.freedesktop.impl.portal.desktop.gtk' unit='xdg-desktop-portal-gtk.service' requested by ':1.8' (uid=1000 pid=6015 comm="/usr/libexec/xdg-desktop-portal ")
> Sep 07 10:19:22 debian systemd[1201]: Starting Portal service (GTK+/GNOME implementation)...
> Sep 07 10:19:22 debian xdg-desktop-portal-gtk[6031]: Unable to init server: Could not connect: Connection refused
> Sep 07 10:19:22 debian xdg-desktop-por[6031]: cannot open display:
> Sep 07 10:19:22 debian systemd[1201]: xdg-desktop-portal-gtk.service: Main process exited, code=exited, status=1/FAILURE
> Sep 07 10:19:22 debian systemd[1201]: xdg-desktop-portal-gtk.service: Failed with result 'exit-code'.
> Sep 07 10:19:22 debian systemd[1201]: Failed to start Portal service (GTK+/GNOME implementation).

Immediately after that failure, there is a 25 second gap in the message
timestamps, and then nautilus starts doing other setup:

> Sep 07 10:19:47 debian dbus-daemon[5956]: [session uid=1000 pid=5956] Activating via systemd: service name='org.gtk.vfs.UDisks2VolumeMonitor' unit='gvfs-udisks2-volume-monitor.service' requested by ':1.1' (uid=1000 pid=5954 comm="nautilus ")

Part of the root cause here is that xdg-desktop-portal-gtk is a systemd
user-service that cannot work without either an X11 or Wayland display
(its purpose is to show prompts when a sandboxed application wants to
do something that needs your permission); but during X11 forwarding,
no component is responsible for telling systemd --user where user-services
can find your X11 display, so xdg-desktop-portal-gtk fails to start.

Because X11 forwarding isn't part of the integrated system involving
x11-common, there's no good component to be responsible for that.
A ssh login session probably should *not* be doing this automatically,
because in your specific case (X11 forwarding with no local GUI),
it would be beneficial to tell systemd --user about your DISPLAY, but
in a more typical desktop use-case (local Wayland or X11), it would
be harmful to do that (because it would make parts of the overall GUI
unexpectedly pop up on the forwarded X11 display instead of locally,
until the forwarded display disconnects, at which point those parts of
the GUI would just not work at all).

Another problem here is that when xdg-desktop-portal-gtk fails and exits
unsuccessfully, that information is getting lost somewhere in the chain
of communication between nautilus, xdg-desktop-portal, dbus-daemon and
systemd --user. The result is that instead of an error being reported
back immediately, there is no reply to a D-Bus method call, which makes
something (either nautilus or xdg-desktop-portal, I can't immediately
tell which) unable to continue until its D-Bus client library gives up and
times out the method call, for which the default timeout is 25 seconds.
I think this might be because systemd does not send the ActivationFailure
message if a transaction is queued but later fails
(https://github.com/systemd/systemd/issues/21520), and nobody has taught
dbus-daemon to do more detailed monitoring of systemd's state to be able
to observe when a unit that it asked for has failed.

Another part of the problem here is probably that something (nautilus or
xdg-desktop-portal or both, probably both) is doing something over D-Bus
that talks to xdg-desktop-portal-gtk, and blocking until that method call
has finished, rather than doing it asynchronously if possible.

    smcv