[SOLVED] Slow application start in gnome wayland

golias · 2024-04-05 06:37:02

I am trying to debug what could be the reason for the slow start of applications (average around 3 seconds for TextEditor, Nautilus, gnome-calculator, etc.). I have no idea where to start.

The journalctl -b is here: https://0x0.st/XiHE.txt

example of launching TextEditor and taking almost 4 seconds

Apr 05 07:10:41 arch systemd[1144]: Started dbus-:1.2-org.gnome.TextEditor@7.service.
Apr 05 07:10:42 arch gnome-text-edit[5354]: Error loading plugin: libvoikko.so.1: cannot open shared object file: No such file or directory
Apr 05 07:10:42 arch gnome-text-edit[5354]: Error loading plugin: libnuspell.so.5: cannot open shared object file: No such file or directory
Apr 05 07:10:42 arch gnome-text-edit[5354]: Error loading plugin: libhspell.so.0: cannot open shared object file: No such file or directory
Apr 05 07:10:42 arch gnome-text-edit[5354]: Error loading plugin: libaspell.so.15: cannot open shared object file: No such file or directory
Apr 05 07:10:43 arch gnome-shell[1538]: meta_window_set_stack_position_no_sync: assertion 'window->stack_position >= 0' failed
Apr 05 07:10:47 arch gnome-shell[1538]: meta_window_set_stack_position_no_sync: assertion 'window->stack_position >= 0' failed
Apr 05 07:11:00 arch gnome-shell[1538]: meta_window_set_stack_position_no_sync: assertion 'window->stack_position >= 0' failed
Apr 05 07:11:04 arch gnome-shell[1538]: meta_window_set_stack_position_no_sync: assertion 'window->stack_position >= 0' failed
Apr 05 07:11:08 arch systemd[1144]: dbus-:1.2-org.gnome.TextEditor@7.service: Consumed 3.997s CPU time.

Last edited by golias (2024-04-08 18:23:37)

seth · 2024-04-05 12:24:37

That's more like 27s? (dbus timeout?)

Apr 05 07:10:43 arch gnome-shell[1538]: meta_window_set_stack_position_no_sync: assertion 'window->stack_position >= 0' failed
Apr 05 07:10:47 arch gnome-shell[1538]: meta_window_set_stack_position_no_sync: assertion 'window->stack_position >= 0' failed
Apr 05 07:11:00 arch gnome-shell[1538]: meta_window_set_stack_position_no_sync: assertion 'window->stack_position >= 0' failed
Apr 05 07:11:04 arch gnome-shell[1538]: meta_window_set_stack_position_no_sync: assertion 'window->stack_position >= 0' failed

https://gitlab.gnome.org/GNOME/mutter/-/issues/930 (noise, it seems)

5
Apr 05 06:47:11 arch systemd[1144]: Started dbus-:1.2-org.gnome.TextEditor@0.service.
Apr 05 06:47:16 arch systemd[1144]: dbus-:1.2-org.gnome.TextEditor@0.service: Consumed 2.788s CPU time.
4
Apr 05 06:47:18 arch systemd[1144]: Started dbus-:1.2-org.gnome.TextEditor@1.service.
Apr 05 06:47:22 arch systemd[1144]: dbus-:1.2-org.gnome.TextEditor@1.service: Consumed 2.905s CPU time.
4
Apr 05 06:48:21 arch systemd[1144]: Started dbus-:1.2-org.gnome.TextEditor@2.service.
Apr 05 06:48:25 arch systemd[1144]: dbus-:1.2-org.gnome.TextEditor@2.service: Consumed 2.717s CPU time.
4
Apr 05 06:50:24 arch systemd[1144]: Started dbus-:1.2-org.gnome.TextEditor@3.service.
Apr 05 06:50:28 arch systemd[1144]: dbus-:1.2-org.gnome.TextEditor@3.service: Consumed 2.727s CPU time.
5
Apr 05 06:57:36 arch systemd[1144]: Started dbus-:1.2-org.gnome.TextEditor@4.service.
Apr 05 06:57:41 arch systemd[1144]: dbus-:1.2-org.gnome.TextEditor@4.service: Consumed 2.746s CPU time.
5
Apr 05 07:06:41 arch systemd[1144]: Started dbus-:1.2-org.gnome.TextEditor@5.service.
Apr 05 07:06:46 arch systemd[1144]: dbus-:1.2-org.gnome.TextEditor@5.service: Consumed 2.773s CPU time.
5
Apr 05 07:09:16 arch systemd[1144]: Started dbus-:1.2-org.gnome.TextEditor@6.service.
Apr 05 07:09:21 arch systemd[1144]: dbus-:1.2-org.gnome.TextEditor@6.service: Consumed 2.916s CPU time.
27
Apr 05 07:10:41 arch systemd[1144]: Started dbus-:1.2-org.gnome.TextEditor@7.service.
Apr 05 07:11:08 arch systemd[1144]: dbus-:1.2-org.gnome.TextEditor@7.service: Consumed 3.997s CPU time.
2
Apr 05 07:11:09 arch systemd[1144]: Started dbus-:1.2-org.gnome.TextEditor@8.service.
Apr 05 07:11:13 arch systemd[1144]: dbus-:1.2-org.gnome.TextEditor@8.service: Consumed 2.770s CPU time.

Is it really starting slowly?
Does eg. https://archlinux.org/packages/extra/x86_64/foot/ start faster?
is it maybe more related to https://bbs.archlinux.org/viewtopic.php … 4#p2159644?

golias · 2024-04-05 14:01:16

Hi thanks.

I am using a Lenovo Carbon X1 Gen 9. When booting from live iso from different distros gnome-text-editor launches instantaneously. I have also older version of Carbon X1 (gen 5) running different distro (ubuntu) and also it is much faster.

I tried gnome with x11 in this machine where the error occurs and it was way faster than in wayland, but then for some reason both x11 and wayland became slow again. I don't know what is happening and more frustrating I don't know what to test.

Using foot and GSK_RENDERER=gl had the result, too slow for application to launch. Of course that if the application is running, launching a new instance is much much faster.

Someone suggest that it could be related to xdg-desktop-portal, but I am not sure. Any thoughts?

seth · 2024-04-05 14:23:58

You installed portal at the end of the posted journal, but didn't re-login. There're also no portal related errors logged, but after a re-login
1. a portal service should have started
2. did you get a change in behavior?

Using foot and GSK_RENDERER=gl had the result, too slow for application to launch.

Please don't paraphrase, https://bbs.archlinux.org/viewtopic.php?id=57855
Where did you export GSK_RENDERER=gl and you're suggesting that foot starts slow as well?
Does "foot top" start slow (ie. avoiding the shell)?

if the application is running, launching a new instance is much much faster

New instance or new window?
Is it fast after the first time you started and termianated the process (what would hint at the filesystem cache, ie. slow disk)?

golias · 2024-04-05 15:11:25

Sorry for paraphrasing. I've added "GSK_RENDERER=gl" to the end of /etc/environment and rebooted.

this is cat /etc/environment:

#
# This file is parsed by pam_env module
#
# Syntax: simple "KEY=VAL" pairs on separate lines
#
QT_QPA_PLATFORMTHEME=qt5ct
GSK_RENDERER=gl

regarding foot, I guess I was too fast to reply. I've launched some more instances of it and it is OK. Very fast indeed, from cli "foot" or "foot top" both are fast enough.

regarding xdg-desktop-portal I tried to remove and reinstall several times before posting here, my apologies for the journalctl containing that info.

finally, trying to be clear (i hope) if gnome-text-editor is running and I use middle button of mouse to launch a new instance (?) of gnome-text-editor it is really fast. I think this might be a confusion: i consider this is to be a new instance but I understand it might be as well understood as a new window (please let me know which one is correct for future reference...).

thanks for your patience.

seth · 2024-04-05 16:58:16

This probably just opens a new window (you can check the process list whether you actually get a new process)

So the bottom line is that at least gnome-text-editor but not every program starts slow; do you start it from an interactive shell by entering "gnome-text-editor" or by clicking some desktop menu?
Does it make a difference?
(From the journal and the meta_window_set_stack_position_no_sync warning I assume you tried twice from some GUI and the from a terminal?)

Apr 05 07:11:40 arch systemd[1144]: Started dbus-:1.2-org.gnome.TextEditor@9.service.
Apr 05 07:11:41 arch gnome-text-edit[5453]: Error loading plugin: libvoikko.so.1: cannot open shared object file: No such file or directory
Apr 05 07:11:41 arch gnome-text-edit[5453]: Error loading plugin: libnuspell.so.5: cannot open shared object file: No such file or directory
Apr 05 07:11:41 arch gnome-text-edit[5453]: Error loading plugin: libhspell.so.0: cannot open shared object file: No such file or directory
Apr 05 07:11:41 arch gnome-text-edit[5453]: Error loading plugin: libaspell.so.15: cannot open shared object file: No such file or directory
Apr 05 07:11:43 arch gnome-shell[1538]: meta_window_set_stack_position_no_sync: assertion 'window->stack_position >= 0' failed
Apr 05 07:11:44 arch gnome-shell[1538]: meta_window_set_stack_position_no_sync: assertion 'window->stack_position >= 0' failed

org.gnome.TextEditor starts (through dbus…) 1s later it warns that some plugin libraries aren't available, 2s & 3s later there's a warning about restacking the window, so the problem is likely the window creation.

Is the behavior replicatable between gtk4-demo (slow) and gtk3-demo (fast)?

golias · 2024-04-06 00:08:46

I don't see any difference between gtk4-demo and gtk3-demo, the launch is OK.

I added another user to the system and it seems that gnome-text-editor launches a bit faster yet not in pair with other distros. Just to mention that I've used live iso of ubuntu and fedora and it was much faster.

seth · 2024-04-06 06:07:47

So is the problem limtied to dbus invoked applications?
What does a slow start for eg. the calculator look like?

golias · 2024-04-06 08:34:41

Launching calculator takes twice the time in regular user than in new added user. Here it is the output:

Regular user:

Apr 06 09:01:17 arch systemd[37296]: Started Application launched by gnome-shell.
Apr 06 09:01:19 arch gnome-shell[37636]: meta_window_set_stack_position_no_sync: assertion 'window->stack_position >= 0' failed
Apr 06 09:01:20 arch systemd[37296]: app-gnome-org.gnome.Calculator-45061.scope: Consumed 2.532s CPU time.
Apr 06 09:01:36 arch tracker-miner-fs-3[45089]: (tracker-extract-3:45089): GLib-GIO-WARNING **: 09:01:36.958: Error creating IO channel for /proc/self/mountinfo: Invalid argument (g-io-error-quark, 13)

debug user (new user added yesterday):

Apr 06 09:31:25 arch systemd[52133]: Started Application launched by gnome-shell.
Apr 06 09:31:25 arch gnome-calculato[54078]: currency-provider.vala:407: Cannot use ECB rates as don't have EUR rate
Apr 06 09:31:25 arch org.gnome.Calculator.desktop[54078]: /home/archie/.cache/gnome-calculator/fxtwdcad.xml:1: parser error : Document is empty
Apr 06 09:31:25 arch org.gnome.Calculator.desktop[54078]: ^
Apr 06 09:31:25 arch gnome-calculato[54078]: currency-provider.vala:521: Couldn't parse rate file /home/archie/.cache/gnome-calculator/fxtwdcad.xml
Apr 06 09:31:25 arch gnome-calculato[54078]: currency-provider.vala:615: Cannot use UN rates as don't have USD rate
Apr 06 09:31:26 arch gnome-shell[52497]: meta_window_set_stack_position_no_sync: assertion 'window->stack_position >= 0' failed

Last edited by golias (2024-04-06 09:24:52)

seth · 2024-04-06 21:45:15

Apr 06 09:01:17 arch systemd[37296]: Started Application launched by gnome-shell.
Apr 06 09:01:19 arch gnome-shell[37636]: meta_window_set_stack_position_no_sync: assertion 'window->stack_position >= 0' failed

Apr 06 09:31:25 arch systemd[52133]: Started Application launched by gnome-shell.
Apr 06 09:31:26 arch gnome-shell[52497]: meta_window_set_stack_position_no_sync: assertion 'window->stack_position >= 0' failed

If it takes 1.5s it could easily be the time precision (26.9-25.1=1.8, 19.1-17.9=1.2)
The assertion 'window->stack_position >= 0' fails for both, so that's insignificant

The currency-provider error looks interesting, guess you don't have a network connection w/ the test user?
Does that make a difference? gnome phoning home?

golias · 2024-04-08 14:40:19

You are right to mention it could be the time precision, however the difference is noticeable, it is much faster with the new user. I don't know what else to do.

I have added network connection and run the test again. It is fast:

Apr 08 15:35:02 arch systemd[105937]: Started dbus-:1.2-org.gnome.TextEditor@2.service.
Apr 08 15:35:02 arch gnome-shell[107257]: meta_window_set_stack_position_no_sync: assertion 'window->stack_position >= 0' failed

This is on pair with Ubuntu and other live isos tested, so it might be something related to my user.

I was wondering if this could be something related to authentication, I am sudo user in my account and not in the debug user.

golias · 2024-04-08 16:23:19

I found the culprit and I will mark the problem as solved.

I went to debug both cases (default user and debug user) using strace and found that in the default user the application of a customised theme (Breeze and papyrus) was causing gnome-tex-editor to spend 1 second loading the cursors and icons.
Changing these to default adwaita led to a much increased performance.

TLRD: custom themes is causing Gnome in Wayland to have a slower performance.

Arch Linux

#1 2024-04-05 06:37:02

[SOLVED] Slow application start in gnome wayland

#2 2024-04-05 12:24:37

Re: [SOLVED] Slow application start in gnome wayland

#3 2024-04-05 14:01:16

Re: [SOLVED] Slow application start in gnome wayland

#4 2024-04-05 14:23:58

Re: [SOLVED] Slow application start in gnome wayland

#5 2024-04-05 15:11:25

Re: [SOLVED] Slow application start in gnome wayland

#6 2024-04-05 16:58:16

Re: [SOLVED] Slow application start in gnome wayland

#7 2024-04-06 00:08:46

Re: [SOLVED] Slow application start in gnome wayland

#8 2024-04-06 06:07:47

Re: [SOLVED] Slow application start in gnome wayland

#9 2024-04-06 08:34:41

Re: [SOLVED] Slow application start in gnome wayland

#10 2024-04-06 21:45:15

Re: [SOLVED] Slow application start in gnome wayland

#11 2024-04-08 14:40:19

Re: [SOLVED] Slow application start in gnome wayland

#12 2024-04-08 16:23:19

Re: [SOLVED] Slow application start in gnome wayland

Board footer