xdg-desktop-portal and cage don't play well together

[pescepalla]

I use greetd-regreet with cage as a Wayland login manager.

It takes up to 30 seconds before anything other than a black screen shows up.

The issue does not occur if I uninstall xdg-desktop-portal or use Sway as a greetd-regreet backend, so I'm not sure whether this is a problem with cage or xdg-desktop-portal.

OS: Arch Linux WM: Hyprland GPU: NVIDIA 3070

[smcv]

Please check the systemd journal for any relevant warning or error messages? There's very little we can do with "it's slow".

[pescepalla]

I have reinstalled xdg-desktop-portaland xdg-desktop-portal-wlr for testing reasons.

I hope the following is useful:

$ journalctl | grep xdg-desktop-portal
... (I've cut everything out except the latest reboot) ...
Sep 27 13:45:00 stellaris dbus-daemon[884]: [session uid=971 pid=884] Activating via systemd: service name='org.freedesktop.portal.Desktop' unit='xdg-desktop-portal.service' requested by ':1.0' (uid=971 pid=878 comm="regreet")
Sep 27 13:45:00 stellaris dbus-daemon[884]: [session uid=971 pid=884] Activating via systemd: service name='org.freedesktop.portal.Documents' unit='xdg-document-portal.service' requested by ':1.2' (uid=971 pid=887 comm="/usr/lib/xdg-desktop-portal")
Sep 27 13:45:00 stellaris dbus-daemon[575]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.17' (uid=971 pid=887 comm="/usr/lib/xdg-desktop-portal")
Sep 27 13:45:00 stellaris dbus-daemon[884]: [session uid=971 pid=884] Activating via systemd: service name='org.freedesktop.impl.portal.desktop.wlr' unit='xdg-desktop-portal-wlr.service' requested by ':1.2' (uid=971 pid=887 comm="/usr/lib/xdg-desktop-portal")
Sep 27 13:45:25 stellaris dbus-daemon[884]: [session uid=971 pid=884] Activating service name='org.freedesktop.secrets' requested by ':1.2' (uid=971 pid=887 comm="/usr/lib/xdg-desktop-portal")
Sep 27 13:45:39 stellaris dbus-daemon[1057]: [session uid=1000 pid=1057] Activating via systemd: service name='org.freedesktop.portal.Desktop' unit='xdg-desktop-portal.service' requested by ':1.13' (uid=1000 pid=1206 comm="thunar --daemon")
Sep 27 13:45:39 stellaris dbus-daemon[1057]: [session uid=1000 pid=1057] Activating via systemd: service name='org.freedesktop.portal.Documents' unit='xdg-document-portal.service' requested by ':1.20' (uid=1000 pid=1311 comm="/usr/lib/xdg-desktop-portal")
Sep 27 13:45:39 stellaris dbus-daemon[1057]: [session uid=1000 pid=1057] Activating via systemd: service name='org.freedesktop.impl.portal.desktop.wlr' unit='xdg-desktop-portal-wlr.service' requested by ':1.20' (uid=1000 pid=1311 comm="/usr/lib/xdg-desktop-portal")

[smcv]

Please check for messages from any other components around that time, not just xdg-desktop-portal. The D-Bus message bus (usually dbus-daemon or dbus-broker), systemd, whatever is your implementation of org.freedesktop.secrets (probably gnome-keyring or KWallet?), and whatever is your implementation of org.freedesktop.impl.portal.desktop.wlr are all likely to be relevant.

It looks as though there is a 25 second pause after trying to activate xdg-desktop-portal-wlr by systemd --user activation. This is suspicious to me, because 25 seconds is the default timeout for a D-Bus method call. Probably something is going wrong there.

[smcv]

Also, please give version numbers: xdg-desktop-portal 1.17/1.18 has significant behaviour changes compared with earlier versions. ("The latest" is not a version number.)

[pescepalla]

xdg-desktop-portal 1.16.0-3
xdg-desktop-portal-wlr 0.7.0-1
gnome-keyring 1:42.1-3

And here's what happened in those 25 seconds:

Sep 27 13:45:00 stellaris systemd[725]: Created slice User Core Session Slice.
Sep 27 13:45:00 stellaris systemd[725]: Starting D-Bus User Message Bus...
Sep 27 13:45:00 stellaris systemd[725]: Started D-Bus User Message Bus.
Sep 27 13:45:00 stellaris kernel: regreet[878]: memfd_create() called without MFD_EXEC or MFD_NOEXEC_SEAL set
Sep 27 13:45:00 stellaris dbus-daemon[884]: [session uid=971 pid=884] Activating via systemd: service name='org.freedesktop.portal.Desktop' unit='xdg-desktop-portal.service' requested by ':1.0' (uid=971 pid=878 comm="regreet")
Sep 27 13:45:00 stellaris systemd[725]: Starting Portal service...
Sep 27 13:45:00 stellaris dbus-daemon[884]: [session uid=971 pid=884] Activating via systemd: service name='org.freedesktop.portal.Documents' unit='xdg-document-portal.service' requested by ':1.2' (uid=971 pid=887 comm="/usr/lib/xdg-desktop-portal")
Sep 27 13:45:00 stellaris systemd[725]: Starting flatpak document portal service...
Sep 27 13:45:00 stellaris dbus-daemon[884]: [session uid=971 pid=884] Activating via systemd: service name='org.freedesktop.impl.portal.PermissionStore' unit='xdg-permission-store.service' requested by ':1.3' (uid=971 pid=892 comm="/usr/lib/xdg-document-portal")
Sep 27 13:45:00 stellaris systemd[725]: Starting sandboxed app permission store...
Sep 27 13:45:00 stellaris dbus-daemon[884]: [session uid=971 pid=884] Successfully activated service 'org.freedesktop.impl.portal.PermissionStore'
Sep 27 13:45:00 stellaris systemd[725]: Started sandboxed app permission store.
Sep 27 13:45:00 stellaris dbus-daemon[884]: [session uid=971 pid=884] Successfully activated service 'org.freedesktop.portal.Documents'
Sep 27 13:45:00 stellaris systemd[725]: Started flatpak document portal service.
Sep 27 13:45:00 stellaris dbus-daemon[575]: [system] Activating via systemd: service name='org.freedesktop.UPower' unit='upower.service' requested by ':1.15' (uid=0 pid=587 comm="/opt/tuxedo-control-center/resources/dist/tuxedo-c")
Sep 27 13:45:00 stellaris systemd[1]: Starting Daemon for power management...
Sep 27 13:45:00 stellaris dbus-daemon[575]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.17' (uid=971 pid=887 comm="/usr/lib/xdg-desktop-portal")
Sep 27 13:45:00 stellaris systemd[1]: Starting RealtimeKit Scheduling Policy Service...
Sep 27 13:45:00 stellaris dbus-daemon[575]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1'
Sep 27 13:45:00 stellaris systemd[1]: Started RealtimeKit Scheduling Policy Service.
Sep 27 13:45:00 stellaris rtkit-daemon[911]: Successfully called chroot.
Sep 27 13:45:00 stellaris rtkit-daemon[911]: Successfully dropped privileges.
Sep 27 13:45:00 stellaris rtkit-daemon[911]: Successfully limited resources.
Sep 27 13:45:00 stellaris rtkit-daemon[911]: Canary thread running.
Sep 27 13:45:00 stellaris rtkit-daemon[911]: Running.
Sep 27 13:45:00 stellaris rtkit-daemon[911]: Watchdog thread running.
Sep 27 13:45:00 stellaris rtkit-daemon[911]: Supervising 0 threads of 0 processes of 0 users.
Sep 27 13:45:00 stellaris rtkit-daemon[911]: Supervising 0 threads of 0 processes of 0 users.
Sep 27 13:45:00 stellaris rtkit-daemon[911]: Supervising 0 threads of 0 processes of 0 users.
Sep 27 13:45:00 stellaris xdg-desktop-por[887]: No skeleton to export
Sep 27 13:45:00 stellaris dbus-daemon[884]: [session uid=971 pid=884] Activating via systemd: service name='org.freedesktop.impl.portal.desktop.wlr' unit='xdg-desktop-portal-wlr.service' requested by ':1.2' (uid=971 pid=887 comm="/usr/lib/xdg-desktop-portal")
Sep 27 13:45:00 stellaris systemd[725]: Portal service (wlroots implementation) was skipped because of an unmet condition check (ConditionEnvironment=WAYLAND_DISPLAY).
Sep 27 13:45:00 stellaris dbus-daemon[575]: [system] Successfully activated service 'org.freedesktop.UPower'
Sep 27 13:45:00 stellaris systemd[1]: Started Daemon for power management.
Sep 27 13:45:02 stellaris systemd[1]: systemd-rfkill.service: Deactivated successfully.
Sep 27 13:45:07 stellaris syncthing[660]: [I4HKA] INFO: Established secure connection to [REDACTED] at 192.168.1.102:50632-49.12.93.194:22067/relay-client/TLS1.3-TLS_AES_128_GCM_SHA256/WAN-P50
Sep 27 13:45:07 stellaris syncthing[660]: [I4HKA] INFO: Device [REDACTED]  client is "syncthing v1.23.7" named "FP4" at 192.168.1.102:50632-49.12.93.194:22067/relay-client/TLS1.3-TLS_AES_128_GCM_SHA256/WAN-P50
Sep 27 13:45:09 stellaris syncthing[660]: [I4HKA] INFO: quic://0.0.0.0:22000 detected NAT type: Symmetric NAT
Sep 27 13:45:11 stellaris dhcpcd[578]: wlan0: no IPv6 Routers available
Sep 27 13:45:20 stellaris syncthing[660]: [I4HKA] INFO: Detected 1 NAT service
Sep 27 13:45:25 stellaris dbus-daemon[884]: [session uid=971 pid=884] Activating via systemd: service name='org.gtk.vfs.Daemon' unit='gvfs-daemon.service' requested by ':1.0' (uid=971 pid=878 comm="regreet")
Sep 27 13:45:25 stellaris systemd[725]: Starting Virtual filesystem service...
Sep 27 13:45:25 stellaris dbus-daemon[884]: [session uid=971 pid=884] Activating service name='org.freedesktop.secrets' requested by ':1.2' (uid=971 pid=887 comm="/usr/lib/xdg-desktop-portal")
Sep 27 13:45:25 stellaris systemd[725]: Started GNOME Keyring daemon.
Sep 27 13:45:25 stellaris dbus-daemon[884]: [session uid=971 pid=884] Successfully activated service 'org.gtk.vfs.Daemon'
Sep 27 13:45:25 stellaris systemd[725]: Started Virtual filesystem service.
Sep 27 13:45:25 stellaris gnome-keyring-daemon[927]: GNOME_KEYRING_CONTROL=/run/user/971/keyring
Sep 27 13:45:25 stellaris gnome-keyring-daemon[927]: Gkm: unable to create keyring dir: /.local/share/keyrings
Sep 27 13:45:25 stellaris gnome-keyring-d[927]: unable to create keyring dir: /.local/share/keyrings
Sep 27 13:45:25 stellaris gnome-keyring-d[927]: unable to create keyring dir: /.local/share/keyrings
Sep 27 13:45:25 stellaris gnome-keyring-daemon[927]: Gkm: unable to create keyring dir: /.local/share/keyrings
Sep 27 13:45:25 stellaris dbus-daemon[884]: [session uid=971 pid=884] Successfully activated service 'org.freedesktop.secrets'
Sep 27 13:45:25 stellaris gnome-keyring-daemon[927]: The Secret Service was already initialized
Sep 27 13:45:25 stellaris gnome-keyring-d[927]: The Secret Service was already initialized
Sep 27 13:45:25 stellaris gnome-keyring-daemon[922]: discover_other_daemon: 1
Sep 27 13:45:25 stellaris org.freedesktop.secrets[922]: GNOME_KEYRING_CONTROL=/run/user/971/keyring
Sep 27 13:45:25 stellaris dbus-daemon[884]: [session uid=971 pid=884] Activating via systemd: service name='org.a11y.Bus' unit='at-spi-dbus-bus.service' requested by ':1.0' (uid=971 pid=878 comm="regreet")
Sep 27 13:45:25 stellaris systemd[725]: Starting Accessibility services bus...
Sep 27 13:45:25 stellaris dbus-daemon[884]: [session uid=971 pid=884] Successfully activated service 'org.a11y.Bus'
Sep 27 13:45:25 stellaris systemd[725]: Started Accessibility services bus.

[pescepalla]

Compare with the output when xdg-desktop-portal is uninstalled:

Sep 27 17:26:25 stellaris systemd[1]: Starting Daemon for power management...
Sep 27 17:26:25 stellaris dbus-daemon[585]: [system] Successfully activated service 'org.freedesktop.UPower'
Sep 27 17:26:25 stellaris systemd[1]: Started Daemon for power management.
Sep 27 17:26:26 stellaris kernel: logitech-hidpp-device 0003:046D:4057.0005: HID++ 4.5 device connected.
Sep 27 17:26:26 stellaris at-spi-bus-launcher[920]: dbus-daemon[920]: Activating service name='org.a11y.atspi.Registry' requested by ':1.0' (uid=971 pid=888 comm="regreet")
Sep 27 17:26:26 stellaris at-spi-bus-launcher[920]: dbus-daemon[920]: Successfully activated service 'org.a11y.atspi.Registry'
Sep 27 17:26:26 stellaris at-spi-bus-launcher[972]: SpiRegistry daemon is running with well-known name - org.a11y.atspi.Registry
Sep 27 17:26:27 stellaris greetd[976]: config: Config { file: ConfigFile { terminal: ConfigTerminal { vt: None, switch: false }, general: ConfigGeneral { source_profile: true, runfile: "/run/greetd.run" }, default_session: ConfigSession { command: "", user: "" }, initial_session: None }, internal: ConfigInternal { session_worker: 12 } }
Sep 27 17:26:27 stellaris systemd[1]: systemd-rfkill.service: Deactivated successfully.
Sep 27 17:26:29 stellaris dbus-daemon[585]: [system] Activating via systemd: service name='org.freedesktop.home1' unit='dbus-org.freedesktop.home1.service' requested by ':1.18' (uid=0 pid=976 comm="/usr/bin/greetd --session-worker 12")
Sep 27 17:26:29 stellaris dbus-daemon[585]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.home1.service': Unit dbus-org.freedesktop.home1.service not found.
Sep 27 17:26:29 stellaris greetd[700]: pam_unix(greetd:session): session closed for user greeter
Sep 27 17:26:29 stellaris systemd[1]: session-1.scope: Deactivated successfully.
Sep 27 17:26:29 stellaris greetd[976]: pam_unix(greetd:session): session opened for user alessandro(uid=1000) by alessandro(uid=0)

[pescepalla]

I see this has been tagged with needs more info. Let me know if I can help.

[GeorgesStavracas]

Can you please test this with xdg-desktop-portal 1.18.0 or the master branch?

[GeorgesStavracas]

@pescepalla did you manage to test this with xdg-desktop-portal main branch, or at least version 1.18.2?

[pescepalla]

Hi, sorry for the late reply. Issue seems resolved as of 1.18.2.

Thank you!

[GeorgesStavracas]

Thanks for testing it :slightly_smiling_face: