Applications delayed on launch

[Sebastian]

Hello,

i am unsure if this is really a problem with dbus but my first research showed it could be related to dbus.

1.)
No LSB modules are available.
Distributor ID: Ubuntu
Description: Ubuntu 19.10
Release: 19.10
Codename: eoan

Ubuntu Budgie on T460 with 256GB SSD and 16GB RAM

2.)
dbus:
  Installed: 1.12.14-1ubuntu2
  Candidate: 1.12.14-1ubuntu2
  Version table:
 *** 1.12.14-1ubuntu2 500
        500 http://de.archive.ubuntu.com/ubuntu eoan/main amd64 Packages
        100 /var/lib/dpkg/status

3.) I've expected just "normal" loading applications

4.) Some applications are delayed at startup. The application will take around 30s to launch, but afterwards it just runs fine. Affected application I found so far are KeepassXC, Filezilla and OnlyOffice Desktop-Editor. From strace I saw this applications are stopping (for about 20-30s) at this point:

connect(12, {sa_family=AF_UNIX, sun_path="/run/user/1000/bus"}, 110) = 0
getpid() = 8165
geteuid() = 1000
getegid() = 1000
getpid() = 8165
geteuid() = 1000
getegid() = 1000
sendmsg(12, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\0", iov_len=1}], msg_iovlen=1, msg_control=[{cmsg_len=28, cmsg_level=SOL_SOCKET, cmsg_type=SCM_CREDENTIALS, cmsg_data={pid=8165, uid=1000, gid=1000}}], msg_controllen=32, msg_flags=0}, MSG_NOSIGNAL) = 1
sendto(12, "AUTH\r\n", 6, MSG_NOSIGNAL, NULL, 0) = 6
recvfrom(12, "REJECTED EXTERNAL\r\n", 4096, 0, NULL, NULL) = 19
sendto(12, "AUTH EXTERNAL 31303030\r\n", 24, MSG_NOSIGNAL, NULL, 0) = 24
recvfrom(12, "OK 7f079149c4e5e774135107445dc85"..., 4096, 0, NULL, NULL) = 37
sendto(12, "NEGOTIATE_UNIX_FD\r\n", 19, MSG_NOSIGNAL, NULL, 0) = 19
recvfrom(12, "AGREE_UNIX_FD\r\n", 4096, 0, NULL, NULL) = 15
sendto(12, "BEGIN\r\n", 7, MSG_NOSIGNAL, NULL, 0) = 7
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
eventfd2(0, EFD_CLOEXEC|EFD_NONBLOCK) = 14
write(14, "\1\0\0\0\0\0\0\0", 8) = 8
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
poll([{fd=14, events=POLLIN}], 1, 25000) = 1 ([{fd=14, revents=POLLIN}])
read(14, "\1\0\0\0\0\0\0\0", 16) = 8
poll([{fd=14, events=POLLIN}], 1, 25000

During my first research I found this following to topics related to the issue:
https://askubuntu.com/questions/1184774/some-applications-on-ubuntu-19-10-very-slow-to-start

This Stackoverflow topic links to the archlinux forum: https://bbs.archlinux.org/viewtopic.php?id=230036

I can confirm that running the delayed applications with "dbus-launch --exit-with-session application" or by running it as root they are all starting without any delay.

Thanks for your help! Let me know if you need any further information.

Best Regards,
Sebastian

[Sebastien Bacher (seb128)]

Thank you for your bug report. Could you add a 'journalctl -b 0' log after triggering the issue?
What desktop/session do you use?

[Chris Rorden (rorden7)]

This bug seems to impact many GTK2 applications including KeepassXC, Filezilla and OnlyOffice Desktop-Editor, HexChat, Lazarus and any application built using Lazarus that targets the GTK2 platform. Descriptions include

https://askubuntu.com/questions/1182155/filezilla-start-after-25-seconds-delay
https://forum.lazarus.freepascal.org/index.php?topic=47240.0
https://askubuntu.com/questions/1187246/ubuntu-19-10-crash-when-lazarus-runs
https://askubuntu.com/questions/1184774/some-applications-on-ubuntu-19-10-very-slow-to-start

Solutions include:
 1. (temporary). Run as super user, e.g.: sudo ./project1
 2. (temporary). Run using: dbus-launch --exit-with-session ./project1
 3. (Permanent). Install "sudo apt-get install appmenu-gtk2-module" and restart.
I am not sure what the root cause is, but one solution would be to have appmenu-gtk2-module installed whenever someone installs "libgtk2.0-0". It is obvious to the user that that these applications require libgtk-x11-2.0.so.0 as the programs will not launch without it. The problem with the current situation is that the programs do not list appmenu-dtk2-module as a dependency but do not launch appropriately without it.

[Chris Rorden (rorden7)]

This issue is easy to replicate in any clean install of Ubuntu 19.10. For example,
  $ sudo apt install hexchat
  $ hexchat
That would allow you to trouble shoot on an development system.

Happy to provide a full 'journalctl -b 0' log if requested, but probably more useful to generate on a development machine. Here are the last few lines of mine, the "Failed: Could not get window list" sounds promising...

Dec 06 07:42:03 zb systemd[1]: Starting Network Manager Script Dispatcher Service...
Dec 06 07:42:03 zb dbus-daemon[1012]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Dec 06 07:42:03 zb systemd[1]: Started Network Manager Script Dispatcher Service.
Dec 06 07:42:14 zb systemd[1]: NetworkManager-dispatcher.service: Succeeded.
Dec 06 07:42:25 zb thunderbird.desktop[1942]: console.debug: "main/language-dictionaries 80 records loaded from JSON dump"
Dec 06 07:42:25 zb thunderbird.desktop[1942]: console.debug: "main/sites-classification 7 records loaded from JSON dump"
Dec 06 07:42:53 zb xdg-desktop-por[1874]: Failed to get application states: GDBus.Error:org.freedesktop.portal.Error.Failed: Could not get window list: GDBus.Error:org.freedesktop.DBus.Error.AccessDenied: App introspection not allowed
Dec 06 07:42:53 zb kernel: [UFW BLOCK] IN=wlp41s0 OUT= MAC=01:00:5e:00:00:01:00:23:04:18:e6:00:08:00 SRC=10.73.1.1 DST=224.0.0.1 LEN=28 TOS=0x00 PREC=0xC0 TTL=1 ID=21410 PROTO=2
Dec 06 07:42:56 zb kernel: [UFW BLOCK] IN=wlp41s0 OUT= MAC=01:00:5e:00:00:fb:f0:79:59:70:d6:ac:08:00 SRC=10.73.1.231 DST=224.0.0.251 LEN=32 TOS=0x00 PREC=0xC0 TTL=1 ID=0 DF PROTO=2
Dec 06 07:43:51 zb gnome-shell[1942]: Window manager warning: Buggy client sent a _NET_ACTIVE_WINDOW message with a timestamp of 0 for 0x4200034
Dec 06 07:43:51 zb gnome-shell[1942]: Window manager warning: Buggy client sent a _NET_ACTIVE_WINDOW message with a timestamp of 0 for 0x4200034
Dec 06 07:43:53 zb xdg-desktop-por[1874]: Failed to get application states: GDBus.Error:org.freedesktop.portal.Error.Failed: Could not get window list: GDBus.Error:org.freedesktop.DBus.Error.AccessDenied: App introspection not allowed

[Chris Rorden (rorden7)]

Changed status from (incomplete) to (new) as I think my comments provide details to replicate this bug. I assume people who upgrade from 19.04 already have appmenu-gtk2-module installed. However, this is a serious problem for people who make a fresh install of 19.10 and attempt to use a GTK2 application. A quick Google search suggests this impacts users of a wide range of programs that have not yet made the jump to a modern widgetset.

[GH (chili-g)]

Confirming this with KeePass-X on fresh 19.10 install on Lenovo e495.

Also confirming "3. (Permanent). Install "sudo apt-get install appmenu-gtk2-module" and restart." fixed it.

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.

[Akkana Peck (akkzilla)]

Two other apps that show the problem: pavucontrol and cheese.
I'm using the openbox window manager. I assume the apps are looking for some sort of reply that a gnome desktop would give them.

In strace, it's waiting on:

poll([{fd=15, events=POLLIN}], 1, 25000)
(the fd 15 for cheese, 11 for pavucontrol).

If I run journalctl -b 0 while pavucontrol is waiting to start, I get the attached log: I've edited it to show the end of one run of pavucontrol and then a second run up to the point where it hangs (with comments interspersed by me). At the end of the previous run, after I hit ^C, it prints

Failed to create file chooser proxy: Error calling StartServiceByName for org.freedesktop.impl.portal.desktop.gtk: Timeout was reached

A web search for that message gives a gazillion hits -- lots of people are seeing this -- but so far I haven't found a solution/workaround.

[Akkana Peck (akkzilla)]

Found it after modifying the web search a little. I had to start openbox with:

/usr/bin/dbus-launch --exit-with-session openbox --startup $HOME/.config/openbox/autostart

The dbus-launch --exit-with-session apparently starts some service that gnome apps now insist on. This apparently works with other window managers: it was an i3 user who found it.

[Gregor Snak (gsnak)]

This is still broken in Ubuntu 20.04 except now "/usr/bin/dbus-launch --exit-with-session openbox --startup $HOME/.config/openbox/autostart" doesn't work. The only thing that still works is "dbus-launch ./some-lazarus-compiled-app".

If I for example run xterm first "dbus-launch xterm" and run lazarus app in that xterm it is slow again because the fix is not "inherited".

[Digulla-hepe (digulla-hepe)]

Just a heads up: I'm seeing exactly the same behavior on OpenSUSE LEAP 15.2

This happens with Xfce4 desktop.

It seems to be a rare bug; no one has hard about this when I asked on the mailing list.

I did some debugging of keepassxc (since it's a relatively small app).

Installed some debug packages, then "gdb keypassxc", wait 5 seconds
until it stops printing "[New Thread 0x7fffe945b700 (LWP 18090)]", then
Ctrl+C to get the stack traces.

"info threads" to see which threads there are. "thread " + id to switch
between them.

The app hangs for 25 seconds when I try to start it which matches this
timeout:

__GI___poll (fds=0x555555f994d0, nfds=1, timeout=25000) at
../sysdeps/unix/sysv/linux/poll.c:29

Googling returned this analysis:

https://freefilesync.org/forum/viewtopic.php?t=6704

The stack traces look very similar: Threads hanging in __lll_lock_wait
and __GI___poll called from ibus_bus_new_async_client and
g_simple_async_result_get_type respectively.

In the mean time, I've found more apps with the same symptom:

- qmmp

- qtconfig ("Qt 4 settings" in the Xfce settings dialog.)

I'm wondering about this line in the stack trace:

/usr/lib64/qt5/plugins/styles/libqgtk2style.so

Maybe there is a bug in the Qt style which I'm using.

Stack frame 45 says style is
"QGtk2Theme::themeHint(QPlatformTheme::ThemeHint)
const::{lambda()#1}::operator()() const::qstring_literal"

which would match the setting in the "Qt 4 settings" dialog but I'm
using Qt5. Or is the dialog for both?

[August Karlstrom (fusionfile)]

I run Debian 11 and the window manager Blackbox. Installing the package dbus-x11 and replacing

 exec blackbox

with

 exec dbus-launch --exit-with-session blackbox

in ~/.xinitrc solved the problem for me. Now applications like atril and simple-scan launch quickly.

[Arno Teigseth (arnotixe)]

I saw the same behavior as Sebastian in linux mint 20.2.
Tried with apps "flameshot" and "obs-studio" - both behave

QT apps are stuck about 25 seconds. Strace exactly like Sebastian's:

connect(12, {sa_family=AF_UNIX, sun_path="/run/user/1000/bus"}, 110) = 0
… yada yada …
poll([{fd=14, events=POLLIN}], 1, 25000
… 25 second timeout …
(something in strace about … Timeout)

<program runs normally after timeout>

I was helped by (https://www.scivision.dev/disable-gnome-keyring-ssh-agent/)

Edit /etc/xdg/autostart/gnome-keyring-ssh.desktop to include the line:

X-GNOME-Autostart-enabled=false

and restart. Not just logout, full restart.

Now all same apps start in 0 secs.