Troubleshooting systemd shutdown problems - systemctl hangs in debug shell

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Hi,

I am currently troubleshooting a problem where a raspberry pi zero w will not reboot after running the `reboot` command (it does reboot with `reboot -f` however) - it just "hangs". After enabling the serial console, my best guess was that a job is stuck in systemd, so I tried enabling the early boot shell. However, after I run `reboot` in a normal shell and change to the early boot shell, running the command `systemctl` (for example, `systemctl list-jobs`) just hangs forever. I can ctrl+c out of it and run other commands (`ps`, `ls`, etc) but I can't seem to query systemd through systemctl. Is there some way I can view the current state of systemd without this command?

Some further details:
Linux kernel 5.15.89+ running on raspberry pi zero w (via Raspberry Pi OS)
systemd version: systemd 247 (247.3-7+rpi1+deb11u1)
+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +ZSTD +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=unified

systemd arguments on kernel commandline: systemd.log_level=debug systemd.log_target=kmsg log_buf_len=1M enforcing=0 ignore_loglevel systemd.debug-shell=1


Here is the tail end of the systemd log which is output to the serial console after running `reboot`:

```
[  126.857450] systemd-journald[100]: Successfully sent stream file descriptor to service manager.
[  126.942054] systemd-journald[100]: Successfully sent stream file descriptor to service manager.
[  127.213116] systemd-journald[100]: Successfully sent stream file descriptor to service manager.
[  127.272100] systemd-journald[100]: Successfully sent stream file descriptor to service manager.
[  127.318344] systemd-journald[100]: Successfully sent stream file descriptor to service manager.
[  127.522280] systemd-journald[100]: Successfully sent stream file descriptor to service manager.
[  128.217070] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/bluetooth_2eservice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=799 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[  128.274042] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/bluetooth_2eservice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=800 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[  128.326185] systemd[1]: Child 522 (agetty) died (code=killed, status=15/TERM)
[  128.347548] systemd[1]: getty@tty1.service: Failed to read oom_kill field of memory.events cgroup attribute: No such file or directory
[  128.371639] systemd[1]: getty@tty1.service: Child 522 belongs to getty@tty1.service.
[  128.390389] systemd[1]: getty@tty1.service: Main process exited, code=killed, status=15/TERM
[  128.406372] systemd[1]: getty@tty1.service: Succeeded.
[  128.423193] systemd[1]: getty@tty1.service: Service restart not allowed.
[  128.438162] systemd[1]: getty@tty1.service: Changed stop-sigterm -> dead
[  128.457233] systemd[1]: getty@tty1.service: Job 662 getty@tty1.service/stop finished, result=done
[  128.466383] systemd[1]: Stopped Getty on tty1.
[  128.499079] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/getty_40tty1_2eservice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=801 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[  128.539439] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/getty_40tty1_2eservice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=802 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[  128.575152] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=JobRemoved cookie=803 reply_cookie=0 signature=uoss error-name=n/a error-message=n/a
[  128.610134] systemd[1]: getty@tty1.service: Consumed 40ms CPU time.
[  128.635696] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/getty_40tty1_2eservice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=804 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[  128.672136] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/getty_40tty1_2eservice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=805 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[  128.713716] systemd[1]: Child 525 ((agetty)) died (code=killed, status=15/TERM)
[  128.737541] systemd[1]: getty@ttyGS0.service: Failed to read oom_kill field of memory.events cgroup attribute: No such file or directory
[  128.758022] systemd[1]: getty@ttyGS0.service: Child 525 belongs to getty@ttyGS0.service.
[  128.766575] systemd[1]: getty@ttyGS0.service: Main process exited, code=killed, status=15/TERM
[  128.779496] systemd[1]: getty@ttyGS0.service: Succeeded.
[  128.785390] systemd[1]: getty@ttyGS0.service: Service restart not allowed.
[  128.794270] systemd[1]: getty@ttyGS0.service: Changed stop-sigterm -> dead
[  128.804306] systemd[1]: getty@ttyGS0.service: Job 700 getty@ttyGS0.service/stop finished, result=done
[  128.814886] systemd[1]: Stopped Getty on ttyGS0.
[  128.823697] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/getty_40ttyGS0_2eservice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=806 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[  128.853005] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/getty_40ttyGS0_2eservice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=807 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[  128.881151] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=JobRemoved cookie=808 reply_cookie=0 signature=uoss error-name=n/a error-message=n/a
[  128.904528] systemd[1]: getty@ttyGS0.service: Consumed 7ms CPU time.
[  201.747274] systemd-journald[100]: Sent WATCHDOG=1 notification.
[  301.957264] systemd-journald[100]: Sent WATCHDOG=1 notification.
```

The "Sent WATCHDOG=1 notification." is just printed over and over as long as I leave the system on (I left it running for 12hrs and it did not reboot, it just printed this message). At this point in the shutdown, the early shell is still accessible, but the `systemctl` command just hangs.

I have also posted the full log here as an attachment: https://github.com/raspberrypi/firmware/issues/1559#issuecomment-1403052508

Any pointers you could provide me in further debugging this problem would be greatly appreciated. I am not exactly sure where to go from here seeing as the debug shell seems to be not working for me.

Thanks,
Jeremy

[Index of Archives]     [LARTC]     [Bugtraq]     [Yosemite Forum]     [Photo]

  Powered by Linux