I'll answer your questions in order of increasing difficulty / detail.
Which log files can tell me what's going wrong?
Sorry to be vague, but it really depends. There can be many root causes for various types of hang. For example: GPU driver bugs, running out of memory, disk or swap space, fork bombs & CPU hogs, kernel bugs, shutdown process hangs, etc...
You can narrow down the list of things to look at by knowing more about the symptoms and particular problem (e.g. Shutdown-specific hangs), and which subsystems, processes, and logs are involved with that particular problem area.
For example with shutdown-specific hangs, look at:
- Kernel logs (
dmesg, /var/log/kern.log, journalctl --dmesg --boot[=[ID][±offset]|all])
- Plymouth logs (
/var/boot/log)
- SystemD (specifically:
systemd-shutdown) (journalctl --boot[=[ID][±offset]|all]_PID=1, journalctl --list-boots for IDs, and sometimes /var/log/syslog)
- Finalrd (Should also output to kernel's ringbuffer
dmesg)
how do I read timestamps like e.g. in kern.log: [36169.146130]? How do I get this human-readable?
To look at kernel logs (for current boot) with human readable timestamps:
sudo dmesg -H
sudo journalctl -b 0 -xn10000 --dmesg
To look at last boot kernel logs (current boot 0 minus 1):
sudo journalctl -b -1 -xn10000 --dmesg
The timestamps in the kernel log are in seconds since last boot. You'll notice in the plain sudo dmesg output that the timestamp always starts at [ 0.000000] with the line Linux version x.x.x-x, and increases from there. The reason the timestamps are done this way by default is because many things happen in very quick succession during the Linux kernel boot. The speed of the CPU is able to execute many commands within microseconds. At this level of time granularity, printing the full date / timestamp would be rather pointless.
You can always ask dmesg to print in human readable output with -H / --human flag, which is an alias for --color, --reltime and --pager.
How do I diagnose that?
There are a few ways to debug shutdown, freeze and hang problems. The log files to look at will depend on where the root cause of the issue lies:
- Kernel issues (GPU or other drivers, kernel bugs)
- Check
dmesg output near the end of the boot where it is hanging
- Either turn off splash screen by removing
quiet splash boot parameters, or toggle text-based boot by presssing right arrow → or Escape
- If you have
plymouth splash screen running (quiet splash is in /etc/default/grub by default)
- Run:
sudo update-grub after changing this file to apply the changes into the generated /boot/grub configs.
- If using SystemD, you can drop a script to execute on shutdown here:
/usr/lib/systemd/system-shutdown/debug.sh
This tip is listed in the FreeDesktop.org page: SystemD Debugging
Set and boot with the debug options:
systemd.log_level=debug systemd.log_target=kmsg log_buf_len=1M printk.devkmsg=on enforcing=0
The recommended example script to debug kernel shutdown issues is:
#!/bin/sh
mount -o remount,rw /
dmesg > /shutdown-log.txt
mount -o remount,ro /
You may want to replace dmesg with dmesg --human --nopager for human-readable timestamps.
Note: that the timestamps will be shown once every few seconds, and the rest of the quick boot messages below each full timestamp will still have nanosecond resolution denoted like: +0.002567 for example.
- Reboot, and look for timeouts logged in the resulting file:
/shutdown-log.txt
Finally, the FreeDesktop.org HangDiagnosis Page has some helpful information about the different levels of hang that you may encounter. It also lists some other methods for extracting Linux kernel messages which are more advanced because they may require two computers (netconsole, SSH), or an IEEE1394 Firewire connection (firescope), or else an RS-232 or other serial console. SSH is also a slightly easier option I didn't list, because SSH gets killed during shutdown, it isn't always available depending on the hang level, and it also requires two computers (setup OpenSSH server on the target, remote SSH into it using another computer as client).
SystemD Debug Shell
See Fedora's docs on SystemD debug-shell
Follow the instructions to enable the debug shell, then press Ctrl+Alt+F9 to switch to it.
Note that if you do this during shutdown, you could affect files being in use on the root or /oldroot pivoted root mountpoint. Just be aware that you can cause messages to appear that otherwise wouldn't, and they may be a red herring (or Heisenbug... since you're causing them by being the observer and holding open a shell during shutdown poking at things).
Be sure to disable this when you're done! When enabled, it leaves a security risk where anyone with physical access does not need the root password:
systemctl disable debug-shell
Finalrd Hook Scripts
- See:
man finalrd (or Ubuntu's docs here)
- To use this method, drop a script into
/etc/finalrd/ with any name as long as it ends in .finalrd suffix.
- You can combine this method with the "
/shutdown-log.txt" method from #1 above to view the output later. (This can be helpful if the scrollback buffer is not enabled during shutdown... Shift+PgUp doesn't always work).
- Note: that you'll have to craft the script in such a way as to "bootstrap" any binaries you wish to run in the script during the
setup phase hook.
What this means is that because during shutdown the / root mountpoint is remounted as /oldroot
In other words: SystemD init changes into a new location and moves the old root mounted filesystem into another place (a.k.a. "pivot root")
Because of this, any binaries you'd expect to be in your shell script's PATH are not there anymore.
For Example:: To bootstrap a few tools, show what processes are using files in / root, and show mountpoints, make a script like this:
#!/bin/sh
# SPDX-License-Identifier: GPL-3.0-only
# Copy executables during finalrd setup phase
if [ "$1" = "setup" ]
then
. /usr/share/initramfs-tools/hook-functions
copy_exec /usr/bin/lsof
copy_exec /usr/bin/mount
copy_exec /usr/bin/grep
exit 0
fi
echo '------------ WHAT ELSE IS USING OLDROOT? ------------'
echo ''
# List everything except filter out kworker tasks
lsof . | grep -v kworker
echo '------------ WHAT IS MOUNTED? ------------'
mount
exit 0
I've never managed to execute an Alt-Sysrq-REISUB to force a cleaner shutdown, but that's probably because I'm on a laptop.
Yes, you're probably correct. Many modern keyboards no longer have the SysRq key... much to the displeasure of Linux users and kernel developers. 😏
I'd suggest finding a secondary keyboard that has the SysRq key. I use an older PS/2 keyboard which I leave plugged into the back of a HTPC, and routed the cable into a drawer under the TV stand. You can probably find such a keyboard at a garage sale, or for a very affordable price online. With a laptop, you'll need a USB to PS/2 connector, or a native USB keyboard that has the SysRq key.
Why PS/2?: These old ports are not common to find on laptops, however modern PCs still often have them. If you can use a PS/2 port for the magic SysRq key combos, do it! The reason is simple: PS/2 is more reliable, while USB can often fail to operate during hangs due to the nature of polling. PS/2 is handled at the interrupt level and can often pre-empt other tasks, which is especially helpful on Real-Time Linux kernels. Unfortunately for laptops USB is often the only option, and USB to PS/2 adapters still are presented to the system as standard USB HIDs and get polled.
When things hang, I open the drawer with that PS/2 keyboard and use Alt+SysRq+ r, e, i, s, u, b in that order, maybe pressing each a few times while watching kernel logs to see that the kernel is responding to the commands. I've noticed with some kernel driver hangs, the kernel is keeping the CPU very busy and sometimes the keystrokes don't trigger a response the first time.
Is there a "harmless" but user-visible magic command I could practice this with (during normal operation), so I can find out how to do a REISUB next time?
Most of the commands are pretty harmless in the grand scheme of things, except if you value your data and press Alt+SysRq+b before syncing all disk caches to disk with Alt+SysRq+s. Most of the commands are usually disabled by default via the /proc/sys/kernel/sysrq mask bits. If you know that one of these key combinations is masked, you can press it all you want and the kernel will just output this message:
sysrq: This sysrq operation is disabled.
So to leverage this, just check cat /proc/sys/kernel/sysrq output. On Ubuntu it's set to: 244. So on those systems the Alt+SysRq+n command is masked:
256 = 0x100 - allow nicing of all RT tasks
| Command |
Function |
| n |
Used to make RT tasks nice-able |
Source: Linux Kernel Docs: Magic SysRq Key
So on a system with that bitmask, I can press Alt+SysRq+n all I want and the kernel just says that operation is disabled. That's probably the most reliable no-op way to test that the kernel is responding to the SysRq key combo.
In one terminal, run:
sudo dmesg -H --nopager --follow
Press your disabled SysRq key command (e.g.: Alt+SysRq+n)
Look for the "sysrq: This sysrq operation is disabled." output.
If the kernel doesn't respond, then either:
CONFIG_MAGIC_SYSRQ kernel option was turned off during compile-time- Keyboard does not have
SysRq key, isn't connected, or isn't sending proper keycode
- Kernel is hung at "level 8" or above (as per FreeDesktop's HangDiagnosis classification system)
