Hi,
my snap applications only start after a long delay. The error message is:
2018/12/28 17:23:36.861954 cmd_run.go:844: WARNING: cannot start document portal: Failed to activate service ‘org.freedesktop.portal.Documents’: timed out (service_start_timeout=120000ms)
It affects all snap applications I have on my system (gimp, libreoffice, inkscape)
It only started recently. Is this a known issue?
Amir
snap version?systemctl restart snapd and trying again?Hello Daniel.
No problem. Outputs bellow. Problem seems limited to GUI applications (thanks for the tip, I never had non-GUI snaps before).
I have apt remove snapd apt install snapd and reboot. I have now tried systemctl restart snapd and no change occurred. I have also tried other things. The org.freedesktop.portal.Documents causing the timeout seems to come from flatpak, so I uninstalled flatpak and reinstalled it from the alexlarsson ppa. No change. Tried installing the apps I had as snaps as flatpaks (GIMP, Inkscape and Libreoffice bc of the versions in the official repos) and there was a delay (like 10 seconds), but that is also not acceptable. For now, I searched for ppas with latest software versions and installed them via apt, but I would like to be able to use snaps. This must have come with one of the recent bionic updates.
:~$ snap version
snap 2.36.3
snapd 2.36.3
series 16
ubuntu 18.04
kernel 4.15.0-43-generic
time snap run gnome-calculator
2018/12/29 19:40:37.096160 cmd_run.go:844: WARNING: cannot start document portal: Failed to activate service ‘org.freedesktop.portal.Documents’: timed out (service_start_timeout=120000ms)
main.go:224: cannot change mount namespace of snap “gnome-calculator” according to change mount (/snap/gtk-common-themes/818/share/icons/Suru /snap/gnome-calculator/260/data-dir/icons/Suru none bind,ro 0 0): cannot use “/snap/gtk-common-themes/818/share/icons/Suru” as bind-mount source: not a directory
Gtk-Message: 19:40:39.213: Failed to load module “appmenu-gtk-module”
Gtk-Message: 19:40:39.278: Failed to load module “topmenu-gtk-module”
Fontconfig warning: “/etc/fonts/conf.avail/53-monospace-lcd-filter.conf”, line 10: Having multiple values in isn’t supported and may not work as expected
** (gnome-calculator:3813): WARNING **: 19:40:40.799: currency.vala:282: Unknown currency ‘Bolivar Soberano’
** (gnome-calculator:3813): WARNING **: 19:40:40.808: currency.vala:412: Currency VEF is not provided by IMF or ECB
real 1m46,018s
user 0m0,598s
sys 0m2,209s
(closed right after start)
:~$ snap run mapscii
ERROR: ld.so: object ‘libgtk3-nocsd.so.0’ from LD_PRELOAD cannot be preloaded (failed to map segment from shared object): ignored.
⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⡿⢿⣆⠀⠀⠀⠀⠀⠀⠀⠀⠀⢨⣿⠟⠃⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠞⠋⠀⠀⢀⣼⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⡿⢿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿
⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⡟⠀⠈⠻⣦⣶⣦⠄⠀⠀⠀⠀⢰⣿⠋⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⢀⣠⣴⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⡿⠟⠟⠻⢿⣿⣿⣿⣿⣿⣿⣿⣿⣿⢻⣫⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⠏⠀⠘⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿⣿
$ snap version
snap 2.39.2+19.10ubuntu1
snapd 2.39.2+19.10ubuntu1
series 16
ubuntu 19.10
kernel 5.0.0-17-generic
$ time snap run docfetcher
2019/06/24 08:44:03.057733 cmd_run.go:893: WARNING: cannot start document portal: Failed to activate service ‘org.freedesktop.portal.Documents’: timed out (service_start_timeout=120000ms)
real 3m16,802s
user 0m5,092s
sys 0m0,412s
What output do you get from snap run --trace-exec docfetcher?
$ LANG=C id
uid=1000(vasilisc) gid=1000(vasilisc) groups=1000(vasilisc),4(adm),20(dialout),21(fax),24(cdrom),25(floppy),26(tape),27(sudo),29(audio),30(dip),44(video),46(plugdev),102(netdev),105(fuse),108(lpadmin),109(scanner),124(sambashare),149(lxd)
$ LANG=C snap run --trace-exec docfetcher
2019/07/03 08:10:01.478248 cmd_run.go:893: WARNING: cannot start document portal: Failed to activate service ‘org.freedesktop.portal.Documents’: timed out (service_start_timeout=120000ms)
[sudo] password for vasilisc:
elapsed time: 0.368278914
(DocFetcher:31544): dconf-WARNING **: Unable to open /home/vasilisc/.local/share/flatpak/exports/share/dconf/profile/user: Permission denied
Slowest 10 exec calls during snap run:
0.013s snap-update-ns
0.044s /snap/core/7270/usr/lib/snapd/snap-confine
0.010s /bin/cat
0.015s /usr/bin/md5sum
0.017s /usr/bin/head
0.019s /bin/cp
0.011s /bin/ln
0.018s /bin/ls
0.011s /usr/bin/printenv
35.232s /snap/docfetcher/1/usr/lib/jvm/java-8-openjdk-amd64/jre/bin/java
Total time: 35.715s
upd 19/07/2019
LANG=C snap run --trace-exec docfetcher
2019/07/19 08:04:22.340013 cmd_run.go:893: WARNING: cannot start document portal: Failed to activate service ‘org.freedesktop.portal.Documents’: timed out (service_start_timeout=120000ms)
[sudo] password for vasilisc:
Sorry, try again.
[sudo] password for vasilisc:
Sorry, try again.
[sudo] password for vasilisc:
sudo: 3 incorrect password attempts
2019/07/19 08:11:46.617998 cmd_run.go:779: cannot extract runtime data: cannot parse end of exec profile: EOF
error: exit status 1
Why privilege escalation is required?
I assume it’s because the --trace-exec requires the same permissions as gdb to use ptrace on the snap’s processes.
I fixed the problem. For some reason, the owner of the ~/.local/share/flatpak/ directory was the root.
/var/log/syslog
Jul 27 07:59:13 vasilisc systemd[13601]: Starting flatpak document portal service…
Jul 27 07:59:13 vasilisc xdg-document-portal[19171]: error: Failed to load db: Could not open file «/home/vasilisc/.local/share/flatpak/db/documents»: failure in open () function: Access denied
Jul 27 07:59:13 vasilisc systemd[13601]: xdg-document-portal.service: Main process exited, code=exited, status=2/INVALIDARGUMENT
Jul 27 07:59:13 vasilisc systemd[13601]: xdg-document-portal.service: Failed with result ‘exit-code’.
After
sudo chown -R $USER:$USER ~/.local/share/
time docfetcher
elapsed time: 0.103026768
real 0m4,398s
user 0m4,740s
sys 0m0,369s
Thank you. This also happend to me and setting the owner correctly fixed the startup times for me.
Had the issue since I installed fatpak on my Kubuntu 19.04.