Raspbian system-wide hang after using "reset" and logging-off from the serial console

Question

I'm looking for an explanation and/or a solution for resolving an issue when connecting to the Pi by its serial console connection: After using the "reset" command at any point during a session - a subsequent log-off causes the entire system to hang (at least systemd).

I can reproduce this on multiple units - including a Pi 2 and a Pi 3. I'm using a clean install of 2016-05-27-raspbian-jessie-lite.img - and can reproduce without any updates, as well as with all updates applied.

I was / still am suspecting a systemd-related issue here. I've tried repeating the same with both Debian Jessie and CentOS 7 within VirtualBox, and have not been able to reproduce - so this appears to be Raspbian-specific.

Can anyone else at least reproduce the following?

1. Use of a Raspberry Pi 2 or 3 Model B, using the May 2016 version of Raspbian Jessie Lite.
2. The serial console enabled and connected, as per http://elinux.org/RPi_Serial_Connection.
   • Note that the Pi 3 requires adding enable_uart=1 at the end of /boot/config.txt.

3. Using a separate SSH or tty0 (keyboard/monitor) console, validate that any or all of the following complete successfully and immediately:

   systemctl status --no-pager
   systemctl --no-pager
   systemctl status [email protected]
   

   Also observe using ps -Afl|grep agetty, that the following is running on ttyS0:

   /sbin/agetty --keep-baud 115200 38400 9600 ttyS0 vt102
   

4. Using the serial console (ttyS0):

   1. Log-in and out (exit) repeatedly, observing no changes in the above.
   2. Log-in, then issue the reset command. Observe still no changes in system status / operation.
   3. exit Observe that the command hangs indefinitely and never returns.

5. Using a separate SSH or tty0 console (still open from above), attempt to repeat any of the above systemctl status commands. Observe that all queries to systemctl now fail after timing out:

   pi@raspberrypi:~ $ systemctl status --no-pager
   Failed to read server status: Connection timed out
   pi@raspberrypi:~ $ systemctl --no-pager
   Failed to list units: Connection timed out
   pi@raspberrypi:~ $ systemctl status serial-get[email protected]
   Failed to get properties: Connection timed out
   

   Also observe that any new login attempts also time out.

At this point, there is no agetty process left running on ttyS0, which explains why the serial console is now left unusable (short of a reboot).

/var/log/syslog shows a previous successful respawn of the Serial Getty service - but after the after the last reset/exit, there are no additional logs. It is almost as if something in systemd has hung, or is left unaware that the process has stopped:

Aug 25 05:17:48 raspberrypi systemd[1]: [email protected] holdoff time over, scheduling restart.
Aug 25 05:17:48 raspberrypi systemd[1]: Stopping Serial Getty on ttyS0...
Aug 25 05:17:48 raspberrypi systemd[1]: Starting Serial Getty on ttyS0...
Aug 25 05:17:48 raspberrypi systemd[1]: Started Serial Getty on ttyS0.
Aug 25 05:17:53 raspberrypi systemd[1]: [email protected] holdoff time over, scheduling restart.
Aug 25 05:17:53 raspberrypi systemd[1]: Stopping Serial Getty on ttyS0...
Aug 25 05:17:53 raspberrypi systemd[1]: Starting Serial Getty on ttyS0...
Aug 25 05:17:53 raspberrypi systemd[1]: Started Serial Getty on ttyS0.

/var/log/auth.log does report that the session has successfully closed:

Aug 25 05:17:46 raspberrypi login[624]: pam_unix(login:session): session opened for user pi by LOGIN(uid=0)
Aug 25 05:17:48 raspberrypi login[624]: pam_unix(login:session): session closed for user pi
Aug 25 05:17:52 raspberrypi login[686]: pam_unix(login:session): session opened for user pi by LOGIN(uid=0)
Aug 25 05:17:53 raspberrypi login[686]: pam_unix(login:session): session closed for user pi
Aug 25 05:17:57 raspberrypi login[710]: pam_unix(login:session): session opened for user pi by LOGIN(uid=0)
Aug 25 05:18:01 raspberrypi login[710]: pam_unix(login:session): session closed for user pi

sudo reboot doesn't even complete at this point. The system hangs for a number of seconds, and eventually returns:

Failed to start reboot.target: Connection timed out

Broadcast message from pi@raspberrypi on pts/0 (Thu 2016-08-25 05:22:34 UTC):

The system is going down for reboot NOW!

... but the system never actually halts, nor does it restart. A hard reset using the power plug seems to be the only successful method of recovery at this point. (Having done this repeatedly, I've managed to corrupt the filesystem beyond simple repairs by fsck, and have needed to re-image the SD card at least once.)

reset is documented at http://man7.org/linux/man-pages/man1/reset.1.html as:

reset calls tput(1) with the clear, rmacs, rmm, rmul, rs1, rs2, and rs3 arguments.

...

For good measure, stty(1) is called with the sane argument in an attempt to get cooked mode back.

So if I run the following in place of reset, I appear to receive the same functionality, but do not hang the system at logout:

tput clear rmacs rmm rmu1 rs1 rs2 rs3 ; stty sane

For reference:

pi@raspberrypi:~ $ uname -a
Linux raspberrypi 4.4.11-v7+ #888 SMP Mon May 23 20:10:33 BST 2016 armv7l GNU/Linux

pi@raspberrypi:~ $ systemd --version
systemd 215
+PAM +AUDIT +SELINUX +IMA +SYSVINIT +LIBCRYPTSETUP +GCRYPT +ACL +XZ -SECCOMP -APPARMOR

... and as of 2016-10-07 2017-02-07 2017-05-12 after applying all current updates, the problem still remains:

pi@raspberrypi:~ $ uname -a
Linux raspberrypi 4.9.24-v7+ #993 SMP Wed Apr 26 18:01:23 BST 2017 armv7l GNU/Linux

The output of systemd --version did not change, but /var/log/apt/history.log includes systemd-sysv:armhf (215-17+deb8u4, 215-17+deb8u5) (now at 215-17+deb8u7).

Why is this happening, and how can this be fixed? Sure, I could just refrain from running reset from a serial console - but I don't see any reason why this should be causing a problem, and it is rather disastrous to the system when executed (as demonstrated above). I'm not exactly sure what the next debugging steps would be for this, but will certainly provide any additional outputs or test results that may be requested.

Edit (2016-09-04): This has now also been reported as a Raspbian bug at https://bugs.launchpad.net/raspbian/+bug/1620117.

Answer 1

This is no longer reproducible with Raspbian Stretch, released 2017-08-16.

As this provides the first bump in the systemd version since I reported this (was previously held at version 215, now 232) - it seems pretty clear that this was an issue in systemd that is now resolved.

Current version outputs on a working system:

pi@raspberrypi:~$ uname -a
Linux raspberrypi 4.9.41-v7+ #1023 SMP Tue Aug 8 16:00:15 BST 2017 armv7l GNU/Linux

pi@raspberrypi:~$ systemd --version
systemd 232
+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN

pi@raspberrypi:~$ cat /etc/os-release
PRETTY_NAME="Raspbian GNU/Linux 9 (stretch)"
NAME="Raspbian GNU/Linux"
VERSION_ID="9"
VERSION="9 (stretch)"
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"

As also since noted by jojopi at https://www.raspberrypi.org/forums/viewtopic.php?p=1200446 :

Very interesting.

The specific thing that "reset" does that triggers the problem is "stty -clocal". You can wake systemd back up after the hang by running from another terminal "sudo stty -F /dev/ttyAMA0 clocal" (or your device name).

strace shows that after logout, systemd pid1 normally runs:

open("/dev/ttyAMA0", O_RDWR|O_NOCTTY|O_LARGEFILE|O_CLOEXEC) = 15
ioctl(15, TCGETS, {B115200 opost isig icanon echo ...}) = 0
ioctl(15, TIOCVHANGUP, 0)               = 0
close(15)                               = 0

But when the terminal is not clocal, the open never completes and systemd is hung. That agrees with the terminal documentation (info libc): Code: Select all

 -- Macro: tcflag_t CLOCAL
     If this bit is set, it indicates that the terminal is connected
     "locally" and that the modem status lines (such as carrier detect)
     should be ignored.

     On many systems if this bit is not set and you call 'open' without
     the 'O_NONBLOCK' flag set, 'open' blocks until a modem connection
     is established.

I have not tested stretch, but I presume that systemd now correctly opens terminals in non-blocking mode.

Incidentally when reboot also hangs, you can still boot using Alt+SysRq-b on console or Break-b on serial.