Arch Linux

ackalker

Member

Registered: 2012-11-27

Posts: 201

"Staircase pattern" of messages on shutdown, why? Just curious...

I've seen this for a long time, in several Linux setups:

On shutdown, the last couple of system messages are often written on the console in the characteristic "staircase pattern", where one message starts directly below and to the right of the previous one, like this:

foo
   bar
      baz

I know that this happens in other situations where terminal settings have gotten messed up, but I wonder: why does it happen so often on shutdown? Is there a way to fix this?

Last edited by ackalker (2015-05-13 09:10:14)

mouseman

Member

From: Outta nowhere

Registered: 2014-04-04

Posts: 291

Re: "Staircase pattern" of messages on shutdown, why? Just curious...

Funny I was thinking about this yesterday as well.

I think I noticed that with the nvidia blob this happens but with nouveau it didn't (I recently switched although I'm not even sure why).

In dmesg I get the following warning and I think it may be related:

[   11.079875] NVRM: Your system is not currently configured to drive a VGA console
[   11.079877] NVRM: on the primary VGA device. The NVIDIA Linux graphics driver
[   11.079878] NVRM: requires the use of a text-mode VGA console. Use of other console
[   11.079879] NVRM: drivers including, but not limited to, vesafb, may result in
[   11.079880] NVRM: corruption and stability problems, and is not supported.

I have no idea how to fix the staggering of messages on shutdown though and to be honest, it doesn't bother me as I can still see when or what fails, if any.

Gusar

Member

Registered: 2009-08-25

Posts: 3,605

Re: "Staircase pattern" of messages on shutdown, why? Just curious...

That Nvidia warning is completely unrelated. This staircase thing happens with any driver, I see it on intel. It's not about graphics, but about terminal handling. Something in systemd's shutdown routine screws up the terminal. While it doesn't look pretty, I never cared enough to try and figure something out.

drcouzelis

Member

From: Connecticut, USA

Registered: 2009-11-09

Posts: 4,092

Website

Re: "Staircase pattern" of messages on shutdown, why? Just curious...

I noticed my computer doing this when I started using two monitors (one large monitor and one small TV). The console output is mirrored onto both screens, so I just assumed systemd was trying to do "monitor length" on a "small TV", resulting in awkward line wrapping.

...but that's just a guess.

ackalker

Member

Registered: 2012-11-27

Posts: 201

Re: "Staircase pattern" of messages on shutdown, why? Just curious...

I wonder if it could be related to whether X was running or not. Perhaps the console settings are not restored correctly on X server exit (in particular if X got started as part of starting a display manager as a systemd service, not by running `startx` after logging in).
Does anyone running a system without X experience the same issue?

Last edited by ackalker (2015-05-14 19:46:02)

Gusar

Member

Registered: 2009-08-25

Posts: 3,605

Re: "Staircase pattern" of messages on shutdown, why? Just curious...

Yep, it's very much possible that it's related to X. Maybe it's particular display managers screwing up.

ackalker

Member

Registered: 2012-11-27

Posts: 201

Re: "Staircase pattern" of messages on shutdown, why? Just curious...

Thanks, I'll have a look into it. I'm using LightDM as display manager at the moment. Perhaps other display managers behave better in this regard.

I'll try dumping the current tty settings to a file using `stty -a` right before starting and right after stopping LightDM, using ExecStartPre= and ExecStopPost= directives in a drop-in snippet for lightdm.service.

Something like this (not tested!)

/etc/systemd/system/lightdm.service.d/log-tty-settings.conf

[Service]
ExecStartPre=/usr/bin/bash -c "/usr/bin/stty -F /dev/tty0 > /var/log/lightdm-tty-before.log"
ExecStopPost=/usr/bin/bash -c "/usr/bin/stty -F /dev/tty0 > /var/log/lightdm-tty-after.log"

I'll test and post my results as soon as I have some time.

[Edit: use bash -c just in case systemd's unit file parser doesn't grok redirections. Hopefully doing this doesn't (un-)mess the tty settings even more :-)]
[Edit2: corrected stty options: apparently when the service starts it has no controlling tty, so force stty to use the current virtual console]
[Eidt3: remove -a option, too much useless detail]

Last edited by ackalker (2015-05-15 16:41:23)

ackalker

Member

Registered: 2012-11-27

Posts: 201

Re: "Staircase pattern" of messages on shutdown, why? Just curious...

Test results are in: yes, it appears that something in the (systemd service, X, LightDM) combo messes up the terminal settings.

A `diff -u /var/log/lightdm-tty-{before,after}.log` says it all:

--- /var/log/lightdm-tty-before.log	2015-05-15 18:27:32.723326706 +0200
+++ /var/log/lightdm-tty-after.log	2015-05-15 18:27:02.459758897 +0200
@@ -1,2 +1,5 @@
 speed 38400 baud; line = 0;
--brkint -imaxbel iutf8
+min = 1; time = 0;
+ignbrk -brkint -icrnl -imaxbel
+-opost -onlcr
+-isig -icanon -iexten -echo -echoe -echok -echoctl -echoke

I'm curious if other display managers behave differently :-)

If anyone is in the mood for adventure, please test with your favorite display manager.

Assuming that the package for your display manager has a file named /usr/lib/systemd/system/<display-manager>.service:

- create a directory `/etc/systemd/system/<display-manager>.service.d/`
- place the drop-in snippet from my first post, the file log-tty-settings.conf,  in this directory
- run `systemctl daemon-reload` as root
- then reboot your system.

When you're back at your desktop, you should have a file /var/log/lightdm-tty-after.log from the reboot you just did, and a file /var/log/lightdm-tty-before.log from the current bootup. Compare these by whatever means you see fit.

[Edit: make a nice diff :-)]

Last edited by ackalker (2015-05-15 18:24:28)

ackalker

Member

Registered: 2012-11-27

Posts: 201

Re: "Staircase pattern" of messages on shutdown, why? Just curious...

Just did a test with the most brain-dead "display manager" I could come up with at short notice:

/etc/systemd/system/justx.service

[Unit]
Description="Just X, ma'am"
Conflicts=getty@tty1.service
After=systemd-user-sessions.service getty@tty1.service plymouth-quit.service

[Service]
ExecStart=/usr/bin/startx /usr/bin/xterm
Restart=always
IgnoreSIGPIPE=no

[Install]
Alias=display-manager.service

After installing the drop-in snippet for this "display manager", disabling LightDM, enabling justx, rebooting, then switching the whole shebang back to what it was, I found no difference in the terminal settings.
This leads me to believe that LightDM is to blame for all of this.

Comments and suggestions are very welcome :-)

Last edited by ackalker (2015-05-15 19:37:37)

Gusar

Member

Registered: 2009-08-25

Posts: 3,605

Re: "Staircase pattern" of messages on shutdown, why? Just curious...

Not just LightDM, I'm using slim. Could be it's display managers in general.

skottish

Forum Fellow

From: Here

Registered: 2006-06-16

Posts: 7,942

Re: "Staircase pattern" of messages on shutdown, why? Just curious...

startx here and this has been happening for a long time on both my workstation and laptop.

ackalker

Member

Registered: 2012-11-27

Posts: 201

Re: "Staircase pattern" of messages on shutdown, why? Just curious...

Thanks for your quick replies! :-)

startx showing this too means I'll try and look more closely, maybe use sysdig to figure out just which process is changing terminal settings.

scryan

Member

Registered: 2014-07-01

Posts: 50

Re: "Staircase pattern" of messages on shutdown, why? Just curious...

I get it too on my OLD laptop with an i686 version of Arch, No DM just i3. Bios booting with syslinux.
Fairly standard install, can't think of any special flags/parameters/unique settings.

ackalker

Member

Registered: 2012-11-27

Posts: 201

Re: "Staircase pattern" of messages on shutdown, why? Just curious...

Moar testing :-)

I didn't succeed in making sysdig produce the output I needed, so I switched to strace.
After undoing all of the stuff from my comments above, I put the following drop-in snippet in:

/etc/systemd/system/lightdm.service.d/dm-ioctls.conf

[Service]
ExecStart=
ExecStart=/usr/bin/strace -o /tmp/dm-ioctls.log -Dfvy -e trace=process,ioctl /usr/bin/lightdm
ExecStopPost=/usr/bin/bash -c "/usr/bin/grep -v '\(/dev/snd\|/nvidia\)' /tmp/dm-ioctls.log > /var/log/dm-ioctls.log"

Long story short: after some filtering of dm-ioctls.log using:

$ grep " ioctl.*/dev/tty.*TC[GS]ETS" dm-ioctls.log

I ended up with:

377   ioctl(9</dev/tty1>, TCGETS, {c_iflags=0x4500, c_oflags=0x5, c_cflags=0x4bf, c_lflags=0x8a3b, c_line=0, c_cc="\x03\x1c\x7f\x15\x04\x00\x01\x00\x11\x13\x1a\x00\x12\x0f\x17\x16\x00\x00\x00"}) = 0
377   ioctl(9</dev/tty1>, SNDCTL_TMR_START or TCSETS, {c_iflags=0x5, c_oflags=0, c_cflags=0xb0, c_lflags=0, c_line=0, c_cc[VMIN]=1, c_cc[VTIME]=0, c_cc="\x03\x1c\x7f\x15\x04\x00\x01\x00\x11\x13\x1a\x00\x12\x0f\x17\x16\x00\x00\x00"}) = 0
377   ioctl(9</dev/tty1>, SNDCTL_TMR_START or TCSETS, {c_iflags=0x4500, c_oflags=0x5, c_cflags=0x4bf, c_lflags=0x8a3b, c_line=0, c_cc="\x03\x1c\x7f\x15\x04\x00\x01\x00\x11\x13\x1a\x00\x12\x0f\x17\x16\x00\x00\x00"}) = 0

So something changes terminal settings, but it does take care to restore them to their original values. Neat.

Getting the process name for PID 377:

$ grep "377 *execve(" dm-ioctls.log

I get:

377   execve("/usr/sbin/X", ["/usr/sbin/X", ":0", "-seat", "seat0", "-auth", "/run/lightdm/root/:0", "-nolisten", "tcp", "vt1", "-novtswitch"], [0] <unfinished ...>
377   execve("/usr/lib/xorg-server/Xorg.wrap", ["/usr/lib/xorg-server/Xorg.wrap", ":0", "-seat", "seat0", "-auth", "/run/lightdm/root/:0", "-nolisten", "tcp", "vt1", "-novtswitch"], ["PWD=/", "SHLVL=0"]) = 0
377   execve("/usr/lib/xorg-server/Xorg", ["/usr/lib/xorg-server/Xorg", ":0", "-seat", "seat0", "-auth", "/run/lightdm/root/:0", "-nolisten", "tcp", "vt1", "-novtswitch"], ["PWD=/", "SHLVL=0"]) = 0

Yup, X. Well, that leaves startx or display managers as the possible culprits, or perhaps a crazy race condition during systemd service stop or the killing of some other processes. Hairy.

(I used `man tty_ioctl` to get some of the gory details of these terminal ioctls.)

Last edited by ackalker (2015-05-16 17:14:02)

ackalker

Member

Registered: 2012-11-27

Posts: 201

Re: "Staircase pattern" of messages on shutdown, why? Just curious...

I managed to dig up an old Debian bug report on this, with a workaround.