Bug#852014: desktop-base: Boot hangs if plymouth is not installed
Hi Aurélien,
Thank you for your response, and I am sorry for filing the bug against
the wrong package. I hope that the log output in this message will help
to narrow down the problem. But I fear that it may remain a mystery, and
I accept that Debian unstable can sometimes be true to its name. :)
TL;DR version: I would suggest that the systemd-based bootup should give
up after 3 failed attempts of starting up gdm, like I believe it used to
be in the past. Now it seems to be doing it forever.
I'm not sure it's raised against the correct package tough, or I will
need more information to analyze this problem.
Unfortunately, I cannot reproduce the problem any more (even after
removing plymouth and downgrading all systemd-related packages to 232-11
or 232-9). But see the /var/log/apt/history.log excerpt near the end of
this message.
After some analysis (booting into rescue mode and entering the root
password, and following the instructions to view the systemd log),
I figured out that the fatal error was that
exec /bin/plymouth failed, because the program was not installed.
Could you share more complete logs about that ?
It seems that journalctl only keeps the systemd log since the system
startup. I did not attempt to record any logs when the system did not
boot beyond the single-user mode. I do have some kernel and user-space
messages in /var/log/messages from the failed startup attempts. Maybe
the real error was this one:
Jan 20 14:39:17 hp org.gnome.Shell.desktop[1071]: /usr/bin/gnome-shell:
error while loading shared libraries: libmutter-cogl.so: cannot open
shared object file: No such file or directory
Jan 20 14:39:17 hp gnome-session[1063]: gnome-session-binary[1063]:
WARNING: App 'org.gnome.Shell.desktop' exited with code 127
Jan 20 14:39:17 hp gdm3: GdmDisplay: display lasted 0,106016 seconds
Jan 20 14:39:17 hp gdm3: Child process -1059 was already dead.
Jan 20 14:39:17 hp gdm3: Child process 1043 was already dead.
Jan 20 14:39:17 hp gdm3: Unable to kill session worker process
Jan 20 14:39:17 hp /usr/lib/gdm3/gdm-x-session[1090]: Unable to run X
server
…
Jan 20 14:39:57 hp gdm3: GdmDisplay: display lasted 0,083347 seconds
Jan 20 14:39:57 hp gdm3: Child process -13450 was already dead.
Jan 20 14:39:57 hp gdm3: Child process 13437 was already dead.
Jan 20 14:39:57 hp gdm3: Unable to kill session worker process
Jan 20 14:39:57 hp /usr/lib/gdm3/gdm-x-session[13480]: Unable to run X
server
Jan 20 14:39:57 hp gdm3: Child process -13480 was already dead.
Jan 20 14:39:57 hp gdm3: Child process 13465 was already dead.
Jan 20 14:39:57 hp gdm3: Unable to kill session worker process
Jan 20 14:39:57 hp org.gnome.Shell.desktop[13510]: /usr/bin/gnome-shell:
error while loading shared libraries: libmutter-cogl.so: cannot open
shared object file: No such file or directory
Jan 20 14:39:57 hp gnome-session[13502]: gnome-session-binary[13502]:
WARNING: App 'org.gnome.Shell.desktop' exited with code 127
Jan 20 14:39:57 hp gdm3: GdmDisplay: display lasted 0,079726 seconds
Jan 20 14:39:57 hp gdm3: Could not start command
'/usr/lib/gdm3/gdm-session-worker': Liian monta avointa tiedostoa
Jan 20 14:39:57 hp gdm3: Child process -13498 was already dead.
Jan 20 14:39:57 hp gdm3: Child process 13486 was already dead.
Jan 20 14:39:57 hp gdm3: Unable to kill session worker process
Back in the days before systemd, a failure to start up gdm3 or xdm or
whatever would result in a text dialog after 3 or so failed attempts,
and there would be getty listening to some virtual consoles at /dev/tty1
to /dev/tty6. But, when the above happened, the system was seemingly
dead. It seems to me that it went into an infinite loop and eventually
run out of file descriptors (or maybe I had pressed ctrl-alt-del which
was obeyed after 1 or 2 seconds). "Liian monta avointa tiedostoa" is the
Finnish translation of "Too many open files".
On some occasion, I left the system there for 5 or 10 minutes, but there
was no progress. (And on this laptop, the status LED for mass storage
activity is pretty well hidden, so I did not even notice that there was
constant SSD activity going on.)
In /var/log/syslog there is a bit more detail of the above
startup/shutdown loops of the gdm service:
Jan 20 14:39:16 hp systemd[1]: Started Session c4 of user Debian-gdm.
Jan 20 14:39:16 hp kernel: [ 35.891506] iwlwifi 0000:02:00.0: L1
Enabled - LTR Enabled
Jan 20 14:39:16 hp kernel: [ 35.891772] iwlwifi 0000:02:00.0: L1
Enabled - LTR Enabled
Jan 20 14:39:16 hp systemd[936]: Reached target Paths.
Jan 20 14:39:16 hp systemd[936]: Reached target Timers.
Jan 20 14:39:16 hp systemd[936]: Listening on GnuPG cryptographic agent
(access for web browsers).
Jan 20 14:39:16 hp systemd[936]: Listening on GnuPG network certificate
management daemon.
Jan 20 14:39:16 hp systemd[936]: Listening on GnuPG cryptographic agent
and passphrase cache.
Jan 20 14:39:16 hp systemd[936]: Listening on GnuPG cryptographic agent
(ssh-agent emulation).
Jan 20 14:39:16 hp systemd[936]: Listening on GnuPG cryptographic agent
and passphrase cache (restricted).
Jan 20 14:39:16 hp systemd[936]: Starting D-Bus User Message Bus Socket.
Jan 20 14:39:16 hp systemd[936]: Listening on D-Bus User Message Bus Socket.
Jan 20 14:39:16 hp systemd[936]: Reached target Sockets.
Jan 20 14:39:16 hp systemd[936]: Reached target Basic System.
Jan 20 14:39:16 hp systemd[936]: Reached target Default.
Jan 20 14:39:16 hp systemd[936]: Startup finished in 10ms.
Jan 20 14:39:16 hp systemd[1]: Started User Manager for UID 117.
Jan 20 14:39:16 hp /usr/lib/gdm3/gdm-x-session[941]: Unable to run X
server
Jan 20 14:39:16 hp gdm3: Child process -941 was already dead.
Jan 20 14:39:16 hp gdm3: Child process 926 was already dead.
Jan 20 14:39:16 hp systemd[1]: Stopping User Manager for UID 117...
Jan 20 14:39:16 hp gdm3: Unable to kill session worker process
Jan 20 14:39:16 hp systemd[936]: Stopped target Default.
Jan 20 14:39:16 hp systemd[936]: Stopped target Basic System.
Jan 20 14:39:16 hp systemd[936]: Stopped target Sockets.
Jan 20 14:39:16 hp systemd[936]: Closed GnuPG network certificate
management daemon.
Jan 20 14:39:16 hp systemd[936]: Closed D-Bus User Message Bus Socket.
Jan 20 14:39:16 hp systemd[936]: Closed GnuPG cryptographic agent
(ssh-agent emulation).
Jan 20 14:39:16 hp systemd[936]: Stopped target Paths.
Jan 20 14:39:16 hp systemd[936]: Closed GnuPG cryptographic agent and
passphrase cache (restricted).
Jan 20 14:39:16 hp systemd[936]: Closed GnuPG cryptographic agent and
passphrase cache.
Jan 20 14:39:16 hp systemd[936]: Closed GnuPG cryptographic agent
(access for web browsers).
Jan 20 14:39:16 hp systemd[936]: Reached target Shutdown.
Jan 20 14:39:16 hp systemd[936]: Starting Exit the Session...
Jan 20 14:39:16 hp systemd[936]: Stopped target Timers.
Jan 20 14:39:16 hp systemd[936]: Received SIGRTMIN+24 from PID 946
(kill).
Jan 20 14:39:16 hp systemd[1]: Stopped User Manager for UID 117.
Jan 20 14:39:16 hp systemd[1]: Removed slice User Slice of Debian-gdm.
Jan 20 14:39:16 hp systemd[1]: Created slice User Slice of Debian-gdm.
Jan 20 14:39:16 hp systemd[1]: Starting User Manager for UID 117...
Jan 20 14:39:16 hp systemd[1]: Started Session c5 of user Debian-gdm.
Jan 20 14:39:16 hp systemd[954]: Listening on GnuPG cryptographic agent
(access for web browsers).
Jan 20 14:39:16 hp systemd[954]: Starting D-Bus User Message Bus Socket.
Jan 20 14:39:16 hp systemd[954]: Listening on GnuPG cryptographic agent
(ssh-agent emulation).
Jan 20 14:39:16 hp systemd[954]: Reached target Paths.
Jan 20 14:39:16 hp systemd[954]: Listening on GnuPG network certificate
management daemon.
Jan 20 14:39:16 hp systemd[954]: Listening on GnuPG cryptographic agent
and passphrase cache (restricted).
Jan 20 14:39:16 hp systemd[954]: Reached target Timers.
Jan 20 14:39:16 hp systemd[954]: Listening on GnuPG cryptographic agent
and passphrase cache.
Jan 20 14:39:16 hp systemd[954]: Listening on D-Bus User Message Bus
Socket.
Jan 20 14:39:16 hp systemd[954]: Reached target Sockets.
Jan 20 14:39:16 hp systemd[954]: Reached target Basic System.
Jan 20 14:39:16 hp systemd[954]: Reached target Default.
Jan 20 14:39:16 hp systemd[954]: Startup finished in 9ms.
Jan 20 14:39:16 hp systemd[1]: Started User Manager for UID 117.
Jan 20 14:39:16 hp systemd[954]: Started D-Bus User Message Bus.
Jan 20 14:39:16 hp kernel: [ 35.971377] IPv6: ADDRCONF(NETDEV_UP):
wlp2s0: link is not ready
Jan 20 14:39:16 hp NetworkManager[747]: <info> [1484915956.9129] device
(wlp2s0): set-hw-addr: set MAC address to 76:1C:4F:FC:57:34 (scanning)
Jan 20 14:39:16 hp kernel: [ 35.979080] iwlwifi 0000:02:00.0: L1
Enabled - LTR Enabled
Jan 20 14:39:16 hp kernel: [ 35.979712] iwlwifi 0000:02:00.0: L1
Enabled - LTR Enabled
Jan 20 14:39:16 hp org.gnome.Shell.desktop[971]: /usr/bin/gnome-shell:
error while loading shared libraries: libmutter-cogl.so: cannot open
shared object file: No such file or directory
Jan 20 14:39:16 hp gnome-session[963]: gnome-session-binary[963]:
WARNING: App 'org.gnome.Shell.desktop' exited with code 127
Jan 20 14:39:16 hp gnome-session-binary[963]: WARNING: App
'org.gnome.Shell.desktop' exited with code 127
Jan 20 14:39:16 hp gnome-session-binary[963]: Unrecoverable failure in
required component org.gnome.Shell.desktop
Jan 20 14:39:16 hp gdm3: GdmDisplay: display lasted 0,084995 seconds
…
I hope that the above output helps you to reproduce the problem.
Possibly the issue is a wrong LD_LIBRARY_PATH or similar. It seems that
I did have libmutter0i installed already on January 9, supplying the
file /usr/lib/x86_64-linux-gnu/mutter/libmutter-cogl.so.
I do remember that installing plymouth did install some other packages,
but I cannot remember the names of those packages. In
/var/log/apt/history.log I see the following which lead to fixing my
problem. I hope someone can figure out the explanation from the version
numbers below.
Start-Date: 2017-01-20 17:54:58
Commandline: apt upgrade
Upgrade: debconf:amd64 (1.5.59, 1.5.60), gnome-session:amd64 (3.22.2-1,
3.22.2-2), gnome-session-common:amd64 (3.22.2-1, 3.22.2-2),
os-prober:amd64 (1.71, 1.72), xserver-common:amd64 (2:1.19.0-3,
2:1.19.1-4), openssl:amd64 (1.1.0c-2, 1.1.0c-3),
libsystemd0:amd64 (232-11, 232-12), libpulsedsp:amd64 (9.0-5, 10.0-1),
pulseaudio:amd64 (9.0-5, 10.0-1), debconf-i18n:amd64 (1.5.59, 1.5.60),
libbz2-1.0:amd64 (1.0.6-8, 1.0.6-8+b1), python3:amd64 (3.5.1-4,
3.5.3-1), libepoxy0:amd64 (1.3.1-1, 1.3.1-2), xserver-xephyr:amd64
(2:1.19.0-3, 2:1.19.1-4), python3-minimal:amd64 (3.5.1-4, 3.5.3-1),
libxcomposite1:amd64 (1:0.4.4-1, 1:0.4.4-2), libpulse0:amd64 (9.0-5,
10.0-1), libpython3-stdlib:amd64 (3.5.1-4, 3.5.3-1), exfat-utils:amd64
(1.2.5-1, 1.2.5-2), libpulse-mainloop-glib0:amd64 (9.0-5, 10.0-1),
systemd-sysv:amd64 (232-11, 232-12), gnome-shell-common:amd64 (3.22.2-2,
3.22.2-3), libpam-systemd:amd64 (232-11, 232-12), xwayland:amd64
(2:1.19.0-3, 2:1.19.1-4), systemd:amd64 (232-11, 232-12),
exfat-fuse:amd64 (1.2.5-1, 1.2.5-2), bzip2:amd64 (1.0.6-8, 1.0.6-8+b1),
gnome-session-bin:amd64 (3.22.2-1, 3.22.2-2), bash:amd64 (4.4-2, 4.4-3),
pulseaudio-module-bluetooth:amd64 (9.0-5, 10.0-1), gnome-shell:amd64
(3.22.2-2, 3.22.2-3), libssl1.1:amd64 (1.1.0c-2, 1.1.0c-3),
pulseaudio-utils:amd64 (9.0-5, 10.0-1)
End-Date: 2017-01-20 17:55:26
Start-Date: 2017-01-20 17:55:36
Commandline: apt install plymouth
Install: libplymouth4:amd64 (0.9.2-4, automatic), plymouth:amd64
(0.9.2-4)
End-Date: 2017-01-20 17:55:46
Best regards,
Marko
Reply to: