Bug#916398: sddm: Wayland autologin sometimes fails - probable tty1 race

Rebecca N. Palmer rebecca_palmer at zoho.com
Thu Dec 13 22:52:20 GMT 2018 

Package: sddm
Version: 0.14.0-4+deb9u1
X-Debbugs-Cc: pkg-systemd-maintainers at lists.alioth.debian.org

With this /etc/sddm.conf:
[Autologin]
User=rnpalmer
Session=plasmawayland.desktop

autologin works only ~80% of the time; failures usually drop to a text 
login prompt (which works but leads to a text shell, not KDE), but 
occasionally to an sddm graphical login screen (which works).

The system log contains "Jumping to VT 2" on success and "Jumping to VT 
1" on failure (plus "Failed to take control of the tty: Operation not 
permitted" on failure to graphical login screen), which suggests the 
problem is sddm trying to start a desktop and getty at tty1.service trying 
to start a text terminal on the same VT.

This implies the problem is Wayland-specific (sddm only switches VTs 
under Wayland, not X [0]) and also Debian-specific (as the upstream 
configuration disables getty at tty1.service and runs sddm itself on tty1 
[1]), but I have *not* explicitly tested either of these.

Adding systemd-logind.service (like 0.18 has) and getty at tty1.service to 
After= of sddm.service does *not* fix this, probably because 
getty at tty1.service is Type=idle (immediately mark it as "done", but 
don't actually start it until the end of boot [2]) and TTYVTDisallocate=yes.

I hence believe the order of events on failure to be
- systemd "starts" getty at tty1.service
- systemd starts sddm.service
* sddm sees that tty1 is free, and opens it
- systemd really starts getty at tty1.service, and in doing so forcibly 
takes tty1 away from sddm
- sddm tries to use "its" tty1, and hits an error because it no longer 
has it
On success, * is instead reached after getty starts, sees that tty1 
isn't free, and uses tty2 instead.

(systemd maintainers: does this imply that _anything_ that takes the 
first available VT during boot and expects to keep it will have a 
similar problem?  I don't know of any other than sddm, but haven't looked)

Possible solutions (I have *not* tried them yet):
- Patch sddm (at [3]) to assume VT 1 is never free
- or, add a Conflicts=getty at tty1.service (and After= ?) to sddm.service

[0] 
https://sources.debian.org/src/sddm/0.14.0-4+deb9u1/src/daemon/Display.cpp/#L324
[1] 
https://sources.debian.org/src/sddm/0.14.0-4+deb9u1/services/sddm.service.in/
[2] man systemd.service
[3] 
https://sources.debian.org/src/sddm/0.18.0-1/src/daemon/VirtualTerminal.cpp/#L118 
- would need to look at vtState.v_state instead of using VT_OPENQRY

success:

Dec  4 20:55:14 rnpalmer-laptop sddm[843]: Initializing...
Dec  4 20:55:14 rnpalmer-laptop sddm[843]: Starting...
Dec  4 20:55:14 rnpalmer-laptop sddm[843]: Adding new display on vt 7 ...
Dec  4 20:55:14 rnpalmer-laptop sddm[843]: Display server starting...
Dec  4 20:55:14 rnpalmer-laptop sddm[843]: Running: /usr/bin/X -nolisten 
tcp -auth /var/run/sddm/{e8af3b0e-d914-4859-8325-863b144b07f8} 
-background none -noreset -displayfd 18 vt7
Dec  4 20:55:17 rnpalmer-laptop sddm[843]: Running display setup script 
"/usr/share/sddm/scripts/Xsetup"
Dec  4 20:55:17 rnpalmer-laptop sddm[843]: Display server started.
Dec  4 20:55:17 rnpalmer-laptop sddm[843]: Reading from 
"/usr/share/wayland-sessions/plasmawayland.desktop"
Dec  4 20:55:17 rnpalmer-laptop sddm[843]: Reading from 
"/usr/share/wayland-sessions/plasmawayland.desktop"
Dec  4 20:55:17 rnpalmer-laptop sddm[843]: Session 
"/usr/share/wayland-sessions/plasmawayland.desktop" selected, command: 
"dbus-launch --exit-with-session /usr/bin/startplasmacompositor"
Dec  4 20:55:17 rnpalmer-laptop sddm[843]: Adding cookie to 
"/var/run/sddm/{e8af3b0e-d914-4859-8325-863b144b07f8}"
Dec  4 20:55:17 rnpalmer-laptop sddm-helper[863]: [PAM] Starting...
Dec  4 20:55:17 rnpalmer-laptop sddm-helper[863]: [PAM] Authenticating...
Dec  4 20:55:17 rnpalmer-laptop sddm-helper[863]: [PAM] returning.
Dec  4 20:55:17 rnpalmer-laptop sddm[843]: Authenticated successfully
Dec  4 20:55:17 rnpalmer-laptop sddm[843]: Jumping to VT 2
Dec  4 20:55:17 rnpalmer-laptop sddm[843]: VT mode didn't need to be fixed
Dec  4 20:55:17 rnpalmer-laptop sddm-helper[863]: Starting: 
"/usr/share/sddm/scripts/wayland-session dbus-launch --exit-with-session 
/usr/bin/startplasmacompositor"
Dec  4 20:55:17 rnpalmer-laptop sddm[843]: Session started

fail to text prompt:

Dec  4 20:52:09 rnpalmer-laptop sddm[852]: Initializing...
Dec  4 20:52:10 rnpalmer-laptop sddm[852]: Starting...
Dec  4 20:52:10 rnpalmer-laptop sddm[852]: Adding new display on vt 7 ...
Dec  4 20:52:10 rnpalmer-laptop sddm[852]: Display server starting...
Dec  4 20:52:10 rnpalmer-laptop sddm[852]: Running: /usr/bin/X -nolisten 
tcp -auth /var/run/sddm/{55773eae-98a2-43a8-904c-acea6cf1be7e} 
-background none -noreset -displayfd 18 vt7
Dec  4 20:52:12 rnpalmer-laptop sddm[852]: Running display setup script 
"/usr/share/sddm/scripts/Xsetup"
Dec  4 20:52:12 rnpalmer-laptop sddm[852]: Display server started.
Dec  4 20:52:12 rnpalmer-laptop sddm[852]: Reading from 
"/usr/share/wayland-sessions/plasmawayland.desktop"
Dec  4 20:52:12 rnpalmer-laptop sddm[852]: Reading from 
"/usr/share/wayland-sessions/plasmawayland.desktop"
Dec  4 20:52:12 rnpalmer-laptop sddm[852]: Session 
"/usr/share/wayland-sessions/plasmawayland.desktop" selected, command: 
"dbus-launch --exit-with-session /usr/bin/startplasmacompositor"
Dec  4 20:52:12 rnpalmer-laptop sddm[852]: Adding cookie to 
"/var/run/sddm/{55773eae-98a2-43a8-904c-acea6cf1be7e}"
Dec  4 20:52:13 rnpalmer-laptop sddm-helper[870]: [PAM] Starting...
Dec  4 20:52:13 rnpalmer-laptop sddm-helper[870]: [PAM] Authenticating...
Dec  4 20:52:13 rnpalmer-laptop sddm-helper[870]: [PAM] returning.
Dec  4 20:52:13 rnpalmer-laptop sddm[852]: Authenticated successfully
Dec  4 20:52:13 rnpalmer-laptop sddm[852]: Jumping to VT 1
Dec  4 20:52:13 rnpalmer-laptop sddm[852]: VT mode didn't need to be fixed
Dec  4 20:52:13 rnpalmer-laptop sddm-helper[870]: Starting: 
"/usr/share/sddm/scripts/wayland-session dbus-launch --exit-with-session 
/usr/bin/startplasmacompositor"
Dec  4 20:52:13 rnpalmer-laptop sddm[852]: Session started
Dec  4 20:52:14 rnpalmer-laptop sddm-helper[870]: [PAM] Closing session
Dec  4 20:52:14 rnpalmer-laptop sddm-helper[870]: [PAM] Ended.
Dec  4 20:52:14 rnpalmer-laptop sddm[852]: Auth: sddm-helper exited with 1
Dec  4 20:54:18 rnpalmer-laptop sddm[852]: Signal received: SIGTERM
Dec  4 20:54:18 rnpalmer-laptop sddm[852]: Display server stopping...

fail to graphical prompt:

Dec  8 20:36:36 rnpalmer-laptop sddm[753]: Initializing...
Dec  8 20:36:36 rnpalmer-laptop sddm[753]: Starting...
Dec  8 20:36:36 rnpalmer-laptop sddm[753]: Adding new display on vt 7 ...
Dec  8 20:36:36 rnpalmer-laptop sddm[753]: Display server starting...
Dec  8 20:36:36 rnpalmer-laptop sddm[753]: Running: /usr/bin/X -nolisten 
tcp -auth /var/run/sddm/{f98a6e44-c6db-4c0e-a513-96fc8f6c7562} 
-background none -noreset -displayfd 18 vt7
Dec  8 20:36:39 rnpalmer-laptop sddm[753]: Running display setup script 
"/usr/share/sddm/scripts/Xsetup"
Dec  8 20:36:39 rnpalmer-laptop sddm[753]: Display server started.
Dec  8 20:36:39 rnpalmer-laptop sddm[753]: Reading from 
"/usr/share/wayland-sessions/plasmawayland.desktop"
Dec  8 20:36:39 rnpalmer-laptop sddm[753]: Reading from 
"/usr/share/wayland-sessions/plasmawayland.desktop"
Dec  8 20:36:39 rnpalmer-laptop sddm[753]: Session 
"/usr/share/wayland-sessions/plasmawayland.desktop" selected, command: 
"dbus-launch --exit-with-session /usr/bin/startplasmacompositor"
Dec  8 20:36:39 rnpalmer-laptop sddm[753]: Adding cookie to 
"/var/run/sddm/{f98a6e44-c6db-4c0e-a513-96fc8f6c7562}"
Dec  8 20:36:39 rnpalmer-laptop sddm-helper[872]: [PAM] Starting...
Dec  8 20:36:39 rnpalmer-laptop sddm-helper[872]: [PAM] Authenticating...
Dec  8 20:36:39 rnpalmer-laptop sddm-helper[872]: [PAM] returning.
Dec  8 20:36:39 rnpalmer-laptop sddm[753]: Authenticated successfully
Dec  8 20:36:39 rnpalmer-laptop sddm[753]: Jumping to VT 1
Dec  8 20:36:39 rnpalmer-laptop sddm[753]: VT mode didn't need to be fixed
Dec  8 20:36:40 rnpalmer-laptop sddm-helper[872]: Starting: 
"/usr/share/sddm/scripts/wayland-session dbus-launch --exit-with-session 
/usr/bin/startplasmacompositor"
Dec  8 20:36:40 rnpalmer-laptop sddm-helper[878]: Failed to take control 
of the tty: Operation not permitted
Dec  8 20:36:40 rnpalmer-laptop sddm[753]: Session started
Dec  8 20:36:40 rnpalmer-laptop sddm-helper[872]: [PAM] Closing session
Dec  8 20:36:40 rnpalmer-laptop sddm-helper[872]: [PAM] Ended.
Dec  8 20:36:40 rnpalmer-laptop sddm[753]: Auth: sddm-helper exited with 3
Dec  8 20:36:40 rnpalmer-laptop sddm[753]: Display server stopping...
Dec  8 20:36:45 rnpalmer-laptop sddm[753]: Removing display ":0" ...
Dec  8 20:36:45 rnpalmer-laptop sddm[753]: Adding new display on vt 7 ...
Dec  8 20:36:45 rnpalmer-laptop sddm[753]: Display server starting...
Dec  8 20:36:45 rnpalmer-laptop sddm[753]: Running: /usr/bin/X -nolisten 
tcp -auth /var/run/sddm/{bdbe6563-8be5-418d-80a2-3a021af7deaf} 
-background none -noreset -displayfd 18 vt7
Dec  8 20:36:46 rnpalmer-laptop sddm[753]: Running display setup script 
"/usr/share/sddm/scripts/Xsetup"
Dec  8 20:36:46 rnpalmer-laptop sddm[753]: Display server started.
Dec  8 20:36:46 rnpalmer-laptop sddm[753]: Socket server starting...
Dec  8 20:36:46 rnpalmer-laptop sddm[753]: Socket server started.
Dec  8 20:36:46 rnpalmer-laptop sddm[753]: Greeter starting...
Dec  8 20:36:46 rnpalmer-laptop sddm[753]: Adding cookie to 
"/var/run/sddm/{bdbe6563-8be5-418d-80a2-3a021af7deaf}"
Dec  8 20:36:46 rnpalmer-laptop sddm[753]: Display server stopping...
Dec  8 20:36:46 rnpalmer-laptop sddm[753]: Display server stopped.
Dec  8 20:36:46 rnpalmer-laptop sddm[753]: Running display stop script 
"/usr/share/sddm/scripts/Xstop"
Dec  8 20:36:46 rnpalmer-laptop sddm-helper[984]: [PAM] Starting...
Dec  8 20:36:46 rnpalmer-laptop sddm-helper[984]: [PAM] Authenticating...
Dec  8 20:36:46 rnpalmer-laptop sddm-helper[984]: [PAM] returning.
Dec  8 20:36:46 rnpalmer-laptop systemd[1]: Created slice User Slice of 
sddm.
Dec  8 20:36:46 rnpalmer-laptop systemd[1]: Started Session 3 of user sddm.
Dec  8 20:36:46 rnpalmer-laptop sddm[753]: Greeter session started 
successfully
Dec  8 20:36:46 rnpalmer-laptop sddm-greeter[991]: High-DPI autoscaling 
Not Enabled
Dec  8 20:36:48 rnpalmer-laptop sddm-greeter[991]: Reading from 
"/usr/share/xsessions/plasma.desktop"
Dec  8 20:36:48 rnpalmer-laptop sddm-greeter[991]: Reading from 
"/usr/share/wayland-sessions/plasmawayland.desktop"
Dec  8 20:36:48 rnpalmer-laptop sddm-greeter[991]: Connected to the daemon.
Dec  8 20:36:48 rnpalmer-laptop sddm[753]: Message received from 
greeter: Connect
Dec  8 20:36:49 rnpalmer-laptop sddm-greeter[991]: Loading 
file:///usr/share/sddm/themes/debian-theme/Main.qml...
Dec  8 20:36:50 rnpalmer-laptop sddm-greeter[991]: Adding view for 
"LVDS-1" QRect(0,0 1366x768)
Dec  8 20:36:50 rnpalmer-laptop sddm-greeter[991]: Message received from 
daemon: Capabilities
Dec  8 20:36:50 rnpalmer-laptop sddm-greeter[991]: Message received from 
daemon: HostName
Dec  8 20:37:20 rnpalmer-laptop sddm-greeter[991]: Reading from 
"/usr/share/wayland-sessions/plasmawayland.desktop"
Dec  8 20:37:20 rnpalmer-laptop sddm[753]: Message received from 
greeter: Login
Dec  8 20:37:20 rnpalmer-laptop sddm[753]: Reading from 
"/usr/share/wayland-sessions/plasmawayland.desktop"
Dec  8 20:37:20 rnpalmer-laptop sddm[753]: Reading from 
"/usr/share/wayland-sessions/plasmawayland.desktop"
Dec  8 20:37:20 rnpalmer-laptop sddm[753]: Session 
"/usr/share/wayland-sessions/plasmawayland.desktop" selected, command: 
"dbus-launch --exit-with-session /usr/bin/startplasmacompositor"
Dec  8 20:37:20 rnpalmer-laptop sddm-helper[1006]: [PAM] Starting...
Dec  8 20:37:20 rnpalmer-laptop sddm-helper[1006]: [PAM] Authenticating...
Dec  8 20:37:20 rnpalmer-laptop sddm-helper[1006]: [PAM] Preparing to 
converse...
Dec  8 20:37:20 rnpalmer-laptop sddm-helper[1006]: [PAM] Conversation 
with 1 messages
Dec  8 20:37:21 rnpalmer-laptop sddm-helper[1006]: [PAM] returning.
Dec  8 20:37:21 rnpalmer-laptop sddm[753]: Authenticated successfully
Dec  8 20:37:21 rnpalmer-laptop sddm[753]: Jumping to VT 2
Dec  8 20:37:21 rnpalmer-laptop sddm[753]: VT mode didn't need to be fixed
Dec  8 20:37:21 rnpalmer-laptop sddm-greeter[991]: Message received from 
daemon: LoginSucceeded
Dec  8 20:37:21 rnpalmer-laptop sddm-helper[1006]: Starting: 
"/usr/share/sddm/scripts/wayland-session dbus-launch --exit-with-session 
/usr/bin/startplasmacompositor"
Dec  8 20:37:21 rnpalmer-laptop sddm[753]: Session started

More information about the Pkg-systemd-maintainers mailing list