at-spi-bus-launcher makes Xorg crash when resuming from suspend

[Paulo Marcel Coelho Aragão]

If at-spi2-core is installed, when resuming from suspend messages like these are logged in systemd journal:

at-spi-bus-launcher[31720]: XIO: fatal IO error 11 (Resource temporarily unavailable) on X server ":0.0"
at-spi-bus-launcher[31720]: after 8065 requests (8065 known processed) with 0 events remaining.

The number of requests vary, it can reach more than 15000. Depending on the number of requests, the Xorg server crashes with SIGBUS. Depending on the exact moment Xorg crashes, when lightdm manages to recover, it shows a login greeter, or worst case scenario, it can't recover, a black screen is shown and the desptop session doesn't start.

It took me a long time to discover the cause. The visible symptom was: once in a while when resuming from suspend, I got a login greeter instead of an unlock greeter, or a black screen which forced me to power down. Investigating, I found out that whenever that happened, there was a Xorg core left behind. Looking at the journal messages before the crash, there was always that flood of at-spi2-core requests. So I uninstalled at-spi2-core and Xorg never crashed anymore.

This is a quite severe bug, which makes it impossible to use at-spi2-core.

ProblemType: Bug
DistroRelease: Ubuntu 18.04
Package: at-spi2-core (not installed)
ProcVersionSignature: Ubuntu 4.15.0-22.24-generic 4.15.17
Uname: Linux 4.15.0-22-generic x86_64
ApportVersion: 2.20.9-0ubuntu7.1
Architecture: amd64
CurrentDesktop: XFCE
Date: Wed Jun 6 09:10:12 2018
InstallationDate: Installed on 2018-04-28 (38 days ago)
InstallationMedia: Xubuntu 18.04 LTS "Bionic Beaver" - Release amd64 (20180426)
SourcePackage: at-spi2-core
UpgradeStatus: No upgrade log present (probably fresh install)

[Launchpad Janitor (janitor)]

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

[Claude van Ackere (claude1)]

This happens from time to time in CAJA and when launching VLC.

[Claude van Ackere (claude1)]

-- Logs begin at Thu 2018-11-01 16:00:55 CET, end at Mon 2018-11-26 16:45:36 CET. --
nov. 26 16:42:47 claude-M61PME-S2P mintmenu[12883]: mintMenu.py: Fatal IO error 11 (Ressource temporairement non dispo
nov. 26 16:42:47 claude-M61PME-S2P unknown[12887]: clock-applet: Fatal IO error 11 (Ressource temporairement non dispo
nov. 26 16:42:47 claude-M61PME-S2P at-spi-bus-launcher[12832]: XIO: fatal IO error 11 (Resource temporarily unavailab
nov. 26 16:42:47 claude-M61PME-S2P at-spi-bus-launcher[12832]: after 5057 requests (5057 known processed) with 0
nov. 26 16:42:47 claude-M61PME-S2P unknown[12889]: notification-area-applet: Fatal IO error 11 (Ressource temporaireme
nov. 26 16:42:47 claude-M61PME-S2P unknown[12885]: wnck-applet: Fatal IO error 11 (Ressource temporairement non dispon
nov. 26 16:42:47 claude-M61PME-S2P polkitd(authority=local)[698]: Unregistered Authentication Agent for unix-session:c
nov. 26 16:42:47 claude-M61PME-S2P systemd[1]: session-c12.scope: Killing process 12397 (lightdm) with signal SIGTERM.
nov. 26 16:42:47 claude-M61PME-S2P systemd[1]: session-c12.scope: Killing process 12415 (gnome-keyring-d) with signal
nov. 26 16:42:47 claude-M61PME-S2P systemd[1]: session-c12.scope: Killing process 12762 (ssh-agent) with signal SIGTER
nov. 26 16:42:47 claude-M61PME-S2P systemd[1]: session-c12.scope: Killing process 12912 (applet.py) with signal SIGTER
nov. 26 16:42:47 claude-M61PME-S2P systemd[1]: session-c12.scope: Killing process 13265 (dbus-launch) with signal SIGT
nov. 26 16:42:47 claude-M61PME-S2P systemd[1]: session-c12.scope: Killing process 13931 (xplayer) with signal SIGTERM.
nov. 26 16:42:47 claude-M61PME-S2P systemd[1]: Stopping Session c12 of user claude.
nov. 26 16:42:47 claude-M61PME-S2P systemd[1]: Stopped Session c12 of user claude.
nov. 26 16:42:47 claude-M61PME-S2P systemd-logind[628]: Removed session c12.
nov. 26 16:42:47 claude-M61PME-S2P lightdm[13948]: PAM unable to dlopen(pam_kwallet.so): /lib/security/pam_kwallet.so:
nov. 26 16:42:47 claude-M61PME-S2P lightdm[13948]: PAM adding faulty module: pam_kwallet.so
nov. 26 16:42:47 claude-M61PME-S2P lightdm[13948]: PAM unable to dlopen(pam_kwallet5.so): /lib/security/pam_kwallet5.s
nov. 26 16:42:47 claude-M61PME-S2P lightdm[13948]: PAM adding faulty module: pam_kwallet5.so

Lightdm ends on login screen

[Sebastien Bacher (seb128)]

Thank you for taking the time to report this bug and helping to make Ubuntu better. The issue you are reporting is an upstream one and it would be nice if somebody having it could send the bug to the developers of the software by following the instructions at https://wiki.ubuntu.com/Bugs/Upstream/GNOME. If you have done so, please tell us the number of the upstream bug (or the link), so we can add a bugwatch that will inform us about its status. Thanks in advance.

[Matthijs Kooijman (matthijskooijman)]

I'm also running into this bug (or at least something that looks like it). Typically what happens for me is that I resume from suspend, get an unlock prompt (the system is locked on suspend) and when I log in, the unlock prompt stays visible (the password dots disappear, but I cannot type anything or click any buttons). When I then kill X to recover (ctrl-alt-backspace), I get a new login prompt. Sometimes, logging in again no longer works then, seeing such messages in the console:

jun 21 17:01:50 grubby at-spi-bus-launcher[30649]: XIO: fatal IO error 11 (Resource temporarily unavailable) on X server ":1024"
jun 21 17:01:50 grubby at-spi-bus-launcher[30649]: after 21 requests (21 known processed) with 0 events remaining.
jun 21 17:01:50 grubby gsd-power[30703]: gsd-power: Fatal IO error 11 (Resource temporarily unavailable) on X server :1024.
jun 21 17:01:50 grubby gsd-keyboard[30715]: gsd-keyboard: Fatal IO error 11 (Resource temporarily unavailable) on X server :1024.
jun 21 17:01:50 grubby gsd-xsettings[30696]: gsd-xsettings: Fatal IO error 11 (Resource temporarily unavailable) on X server :1024.
jun 21 17:01:50 grubby gsd-media-keys[30731]: gsd-media-keys: Fatal IO error 11 (Resource temporarily unavailable) on X server :1024.
jun 21 17:01:50 grubby systemd-logind[1100]: Session c9 logged out. Waiting for processes to exit.
jun 21 17:01:50 grubby gsd-clipboard[30695]: gsd-clipboard: Fatal IO error 11 (Resource temporarily unavailable) on X server :1024.
jun 21 17:01:50 grubby gsd-color[30713]: gsd-color: Fatal IO error 11 (Resource temporarily unavailable) on X server :1024.
jun 21 17:01:50 grubby gnome-shell[30633]: Connection to xwayland lost

From the messages, I suspect this might be the same problem as the original poster.

However, I'm not entirely sure if at-spi-bus-launcher is actually the culprit here. Could it be that that the xserver or xwayland (I'm not sure which - I'm using the GNOME xorg session since the wayland session doesn't work for me, but the log does talk about xwayland) crashes and that at-spi-bus-launcher is just the first process to find out (because it does so many requests maybe?). I've also seen some instances where at-spi-bus-launcher is not the first one in the log, and I've tried disabling at-spi-bus-launcher by masking it in systemd (not entirely sure if that really worked), but then I also think I saw a crash where at-spi-bus-launcher would not show up in the log at all.

One additional observation: At some point during testing, while login would not work, I found a logged in session in some virtual terminal. After logging out that session, logins would work again as normal. I'm not entirely sure if there's a causal relationship there, nor where that logged in session came from (but I was testing with two different users to see if there was something in my homedir that triggered it, so perhaps it came from one of those tests...). Vague, but I wanted to mention this just in case it triggers an idea somewhere :-)

As for reporting an upstream issue, that is probably a good idea, though I'm not entirely sure where the cause is. It's probably safe to say it is something in gnome, though.

[Camille Rodriguez (camille.rodriguez)]

Same bug seen on Ubuntu Bionic 18.04.5 LTS with Lenovo P53.

In my case, the bug seen when attempting a domain login in ubuntu. About 75% of the time, the login hangs for several minutes, then the screen turns black, and returns to the greater. Once in a while, the user is able to login.

The workaround of removing the at-spi2-core package effectively stops the crashes -- but this removes also other functionalities. For example, nautilus is removed.

Is there a patch available, or did anyone report the bug upstream yet ?

Logs of the error :
Nov 20 15:44:47 HOSTNAME gnome-session[5658]: gnome-session-binary[5658]: WARNING: Application 'org.gnome.Shell.desktop' failed to register before timeout
Nov 20 15:44:47 HOSTNAME gnome-session[5658]: gnome-session-binary[5658]: CRITICAL: We failed, but the fail whale is dead. Sorry....
Nov 20 15:44:47 HOSTNAME gnome-session-binary[5658]: Unrecoverable failure in required component org.gnome.Shell.desktop
Nov 20 15:44:47 HOSTNAME gnome-session-binary[5658]: WARNING: Application 'org.gnome.Shell.desktop' failed to register before timeout
Nov 20 15:44:47 HOSTNAME gnome-session-binary[5658]: CRITICAL: We failed, but the fail whale is dead. Sorry....
Nov 20 15:44:47 HOSTNAME at-spi-bus-launcher[5774]: XIO: fatal IO error 11 (Resource temporarily unavailable) on X server ":1"
Nov 20 15:44:47 HOSTNAME at-spi-bus-launcher[5774]: after 21 requests (21 known processed) with 0 events remaining.

[Camille Rodriguez (camille.rodriguez)]

upstream bug can be found here https://bugzilla.gnome.org/show_bug.cgi?id=796512

[Sebastien Bacher (seb128)]

bugzilla is deprecated, if that's still happening it would be better to open a new report on https://gitlab.gnome.org/GNOME/at-spi2-core/-/issues

[Camille Rodriguez (camille.rodriguez)]

Ok, thank you for the info, I'll move the bug over there

[Camille Rodriguez (camille.rodriguez)]

https://gitlab.gnome.org/GNOME/at-spi2-core/-/issues/27