GNOME Bugzilla – Bug 752722
gnome-session exits without any apparent reason
Last modified: 2016-09-14 11:27:44 UTC
Created attachment 307906 [details] Xorg log Since I upgraded from Fedora 21 to Fedora 22 (gnome-session 3.16.0-1), my GNOME session randomly exits from time to time. What's weird is that the journalctl logs do not show any crash: it looks like gnome-session and gnome-shell decided to exit on their own: juil. 22 14:11:32 milan audit[1]: <audit-1130> pid=1 uid=0 auid=4294967295 ses=4 juil. 22 14:13:09 milan sudo[13521]: pam_unix(sudo:session): session closed for user root juil. 22 14:13:09 milan audit[13521]: <audit-1106> pid=13521 uid=0 auid=1000 ses=1 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 msg='op juil. 22 14:13:09 milan audit[13521]: <audit-1104> pid=13521 uid=0 auid=1000 ses=1 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 msg='op juil. 22 14:46:41 milan polkitd[31152]: Unregistered Authentication Agent for unix-session:1 (system bus name :1.65, object path /org/freedesktop/Pol juil. 22 14:46:43 milan gnome-session[2890]: WARNING: Lost name on bus: org.gnome.SessionManager juil. 22 14:46:52 milan gnome-session[2890]: WARNING: App 'gnome-settings-daemon.desktop' exited with code 1 juil. 22 14:46:52 milan gnome-session[2890]: WARNING: App 'gnome-shell.desktop' exited with code 1 juil. 22 14:46:53 milan gnome-session[2890]: WARNING: Client '/org/gnome/SessionManager/Client3' failed to reply before timeout juil. 22 14:46:53 milan gnome-session[2890]: WARNING: Client '/org/gnome/SessionManager/Client17' failed to reply before timeout juil. 22 14:47:01 milan gdm-password][2700]: pam_unix(gdm-password:session): session closed for user milan juil. 22 14:47:01 milan audit[2700]: <audit-1106> pid=2700 uid=0 auid=1000 ses=1 subj=system_u:system_r:xdm_t:s0-s0:c0.c1023 msg='op=PAM:session_clos juil. 22 14:47:01 milan audit[2700]: <audit-1113> pid=2700 uid=0 auid=1000 ses=1 subj=system_u:system_r:xdm_t:s0-s0:c0.c1023 msg='uid=1000 exe="/usr/ juil. 22 14:47:01 milan audit[2700]: <audit-1104> pid=2700 uid=0 auid=1000 ses=1 subj=system_u:system_r:xdm_t:s0-s0:c0.c1023 msg='op=PAM:setcred gran juil. 22 14:47:19 milan dbus[688]: [system] Activating via systemd: service name='org.freedesktop.GeoClue2' unit='geoclue.service' juil. 22 14:47:19 milan dbus[688]: [system] Successfully activated service 'org.freedesktop.GeoClue2' juil. 22 14:47:19 milan dbus[688]: [system] Activating via systemd: service name='org.freedesktop.ModemManager1' unit='dbus-org.freedesktop.ModemMana juil. 22 14:47:19 milan dbus[688]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.ModemManager1.service': Unit dbus-org.freede juil. 22 14:47:19 milan systemd[1]: Starting Location Lookup Service... juil. 22 14:47:19 milan systemd[1]: Started Location Lookup Service. In Bug 751563 I mistakenly attached an old log with unrelated errors. Now, I can't find any X error (see attached file). The only hint would be that systemd-logind tells X to close the session. Is that the case? [ 25075.974] (II) evdev: PixArt USB Optical Mouse: Close [ 25077.448] (II) UnloadModule: "evdev" [ 25088.192] (II) systemd-logind: releasing fd for 13:76 [ 25088.550] (II) evdev: HP WMI hotkeys: Close [ 25088.647] (II) UnloadModule: "evdev" [ 25088.647] (II) systemd-logind: releasing fd for 13:71 [ 25088.811] (II) UnloadModule: "synaptics" [ 25088.811] (II) systemd-logind: releasing fd for 13:68 [ 25088.826] (II) evdev: AT Translated Set 2 keyboard: Close [ 25088.826] (II) UnloadModule: "evdev" [ 25088.826] (II) systemd-logind: releasing fd for 13:67 [ 25088.835] (II) evdev: HP Webcam: Close [ 25088.910] (II) UnloadModule: "evdev" [ 25088.910] (II) systemd-logind: releasing fd for 13:75 [ 25088.916] (II) evdev: Power Button: Close [ 25088.916] (II) UnloadModule: "evdev" [ 25088.916] (II) systemd-logind: releasing fd for 13:65 [ 25088.931] (II) evdev: Video Bus: Close [ 25088.931] (II) UnloadModule: "evdev" [ 25088.931] (II) systemd-logind: releasing fd for 13:69 [ 25088.949] (II) evdev: Power Button: Close [ 25088.949] (II) UnloadModule: "evdev" [ 25088.949] (II) systemd-logind: releasing fd for 13:66 [ 25090.215] (II) Server terminated successfully (0). Closing log file.
I just experienced a similar issue while running 'dnf upgrade': I got a VT switch starting a new GDM session, which made me think I got logged out. Yet, my GNOME session was still open and I could switch back to it. This issue seems to be related to the original one, as the "gnome-session[2469]: WARNING: Lost name on bus: org.gnome.SessionManager" error indicates. But the logs show that two gnome-session processes were running: 4658 and 2469. It looks like only the latter lost the bus, and its lower PID seems to indicate that it was the GDM gnome-session. Of course, installing updates while the system is running can create all kinds of issues. But since the error is similar, I thought it might be helpful. Here's the relevant excerpt from journalctl -r. Are the systemd-logind messages a mere consequence of the VT switch, or a sign of a deeper problem? [After this the Xorg server for GDM starts] août 24 10:51:15 milan /usr/libexec/gdm-x-session[13246]: X.Org X Server 1.17.2 août 24 10:51:15 milan kernel: audit: type=1105 audit(1440406275.201:826): pid=13170 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:xdm_ août 24 10:51:15 milan audit[13170]: <audit-1105> pid=13170 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:xdm_t:s0-s0:c0.c1023 msg='op= août 24 10:51:15 milan gdm-launch-environment][13170]: pam_unix(gdm-launch-environment:session): session opened for user gdm by (uid=0) août 24 10:51:15 milan systemd[1]: Starting Session c2 of user gdm. août 24 10:51:15 milan systemd[1]: Started Session c2 of user gdm. août 24 10:51:15 milan systemd-logind[690]: New session c2 of user gdm. août 24 10:51:13 milan kernel: audit: type=1103 audit(1440406273.485:825): pid=13170 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:xdm_ août 24 10:51:13 milan kernel: audit: type=1101 audit(1440406273.483:824): pid=13170 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:xdm_ août 24 10:51:13 milan audit[13170]: <audit-1103> pid=13170 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:xdm_t:s0-s0:c0.c1023 msg='op= août 24 10:51:13 milan audit[13170]: <audit-1101> pid=13170 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:xdm_t:s0-s0:c0.c1023 msg='op= août 24 10:51:13 milan kernel: audit: type=1100 audit(1440406273.429:823): pid=13170 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:xdm_ août 24 10:51:13 milan audit[13170]: <audit-1100> pid=13170 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:xdm_t:s0-s0:c0.c1023 msg='op= août 24 10:51:12 milan kernel: audit: type=1104 audit(1440406272.963:822): pid=2368 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:xdm_t août 24 10:51:12 milan audit[2368]: <audit-1104> pid=2368 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:xdm_t:s0-s0:c0.c1023 msg='op=PA août 24 10:51:12 milan kernel: audit: type=1106 audit(1440406272.885:821): pid=2368 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:xdm_t août 24 10:51:12 milan audit[2368]: <audit-1106> pid=2368 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:xdm_t:s0-s0:c0.c1023 msg='op=PA août 24 10:51:12 milan gdm-launch-environment][2368]: pam_unix(gdm-launch-environment:session): session closed for user gdm août 24 10:51:10 milan /usr/libexec/gdm-x-session[4606]: (II) systemd-logind: got pause for 13:76 août 24 10:51:10 milan /usr/libexec/gdm-x-session[4606]: (II) systemd-logind: got pause for 13:69 août 24 10:51:10 milan /usr/libexec/gdm-x-session[4606]: (II) systemd-logind: got pause for 13:65 août 24 10:51:10 milan /usr/libexec/gdm-x-session[4606]: (II) systemd-logind: got pause for 13:72 août 24 10:51:10 milan /usr/libexec/gdm-x-session[4606]: (II) systemd-logind: got pause for 13:70 août 24 10:51:10 milan /usr/libexec/gdm-x-session[4606]: (II) systemd-logind: got pause for 13:67 août 24 10:51:10 milan /usr/libexec/gdm-x-session[4606]: (II) systemd-logind: got pause for 13:68 août 24 10:51:10 milan /usr/libexec/gdm-x-session[4606]: (II) systemd-logind: got pause for 226:0 août 24 10:51:10 milan /usr/libexec/gdm-x-session[4606]: (II) systemd-logind: got pause for 13:66 août 24 10:51:10 milan /usr/libexec/gdm-x-session[4606]: (II) AIGLX: Suspending AIGLX clients for VT switch août 24 10:51:08 milan gnome-session[4658]: (gnome-settings-daemon:4906): color-plugin-WARNING **: failed to connect to device: Failed to connect to août 24 10:51:08 milan /usr/libexec/gdm-x-session[4606]: Reloaded configuration août 24 10:51:08 milan /usr/libexec/gdm-x-session[4606]: Reloaded configuration août 24 10:51:07 milan /usr/libexec/gdm-x-session[4606]: Reloaded configuration août 24 10:51:06 milan polkitd[1100]: Unregistered Authentication Agent for unix-session:c1 (system bus name :1.25, object path /org/freedesktop/Poli août 24 10:51:04 milan gnome-session[2469]: WARNING: Lost name on bus: org.gnome.SessionManager août 24 10:49:38 milan chronyd[2421]: Source 2a00:1080:800::6:1 replaced with 195.154.216.44 août 24 10:45:19 milan svn[11926]: DIGEST-MD5 common mech free août 24 10:45:18 milan svn[11918]: DIGEST-MD5 common mech free août 24 10:45:18 milan svn[11912]: DIGEST-MD5 common mech free août 24 10:45:14 milan svn[11888]: DIGEST-MD5 common mech free août 24 10:44:41 milan gnome-session[4658]: Gjs-Message: JS LOG: pushModal: invocation of begin_modal failed
Seen a forced logout again today. It seems to happen when the system it under heavy IO load. Could it be that a timeout is triggered and leads to a crash? I've also noticed that systemd-journald often crashes at the same time, or a few minutes before, which gnome-session might not like. The relevant excerpt of the logs: août 25 13:00:49 milan polkitd[1100]: Unregistered Authentication Agent for unix-session:2 (system bus name :1.102, object path /org/freedesktop/Poli août 25 13:00:49 milan gnome-session[4658]: WARNING: Client '/org/gnome/SessionManager/Client5' failed to reply before timeout août 25 13:00:49 milan gnome-session[4658]: WARNING: Client '/org/gnome/SessionManager/Client7' failed to reply before timeout août 25 13:00:48 milan gnome-session[4658]: WARNING: App 'gnome-settings-daemon.desktop' exited with code 1 août 25 13:00:20 milan gnome-session[4658]: WARNING: Lost name on bus: org.gnome.SessionManager août 25 12:59:53 milan PackageKit[2573]: new update-packages transaction /15739_aebcccac scheduled from uid 1000
Ping? Any idea about how I could debug this? Today it happened without any logs being related to systemd-journald, nor any timeout. Just this: sept. 15 10:18:26 milan gnome-session[16331]: WARNING: Lost name on bus: org.gnome.SessionManager sept. 15 10:18:29 milan polkitd[1040]: Unregistered Authentication Agent for unix-session:1 (system bus name :1.64, object path /org/freedesktop/Poli sept. 15 10:18:33 milan gdm-password][16153]: pam_unix(gdm-password:session): session closed for user milan
can you get a backtrace of the journald crash? if you wipe (or move out of the way) /var/log/journal does the problem persist?
A trace is available at https://bugzilla.redhat.com/show_bug.cgi?id=1199442, apparently this might be fixed in systemd 223. I've moved /var/log/journal, I'll report if the bug strikes again or not. But it's quite irregular, sometimes I don't see it for two weeks. Also, as I noted in my last comment, sometimes the logout happens without any messages related to journald...
Are you still seeing this?
I've never seen it again on Fedora 24, so this may well have been the systemd issue I referred to in my last comment.