Bug 1034414
My attempt at testing did not go well either, here's journalctl -la output from: 1. attempt to login 2. attempt: systemctl restartsddm (waiting approx 2 minutes to finish) 3. attempt to login again Nov 25 13:35:02 localhost.localdomain chronyd[368]: System clock wrong by 0.795586 seconds, adjustment started Nov 25 13:35:07 localhost.localdomain sddm[388]: DAEMON: Message received from greeter: Login Nov 25 13:35:07 localhost.localdomain sddm[388]: DAEMON: Starting authentication for user "rdieter1" Nov 25 13:35:07 localhost.localdomain sddm[388]: AUTH: Message received 0 Nov 25 13:35:07 localhost.localdomain sddm[388]: Command 1 Nov 25 13:35:07 localhost.localdomain sddm[388]: AUTH: PAM: Starting... Nov 25 13:35:07 localhost.localdomain sddm[388]: AUTH: requestDisplay start Nov 25 13:35:07 localhost.localdomain sddm[388]: AUTH: Requesting Display Nov 25 13:35:07 localhost.localdomain sddm[388]: DAEMON: Received message 11 from the authenticator Nov 25 13:35:07 localhost.localdomain sddm[388]: AUTH: requestDisplay end Nov 25 13:35:07 localhost.localdomain sddm[388]: AUTH: Authenticated for user "rdieter1" Nov 25 13:35:07 localhost.localdomain sddm[388]: AUTH: requestSessionId start Nov 25 13:35:20 localhost.localdomain systemd[1]: Starting Stop Read-Ahead Data Collection... Nov 25 13:35:20 localhost.localdomain systemd[1]: Started Stop Read-Ahead Data Collection. Nov 25 13:36:27 localhost.localdomain systemd[1]: Cannot add dependency job for unit dmraid-activation.service, ignoring: Unit dmraid-activation.service failed to load: No such file or directory. Nov 25 13:36:27 localhost.localdomain systemd[1]: Starting Getty on tty2... Nov 25 13:36:27 localhost.localdomain systemd[1]: Started Getty on tty2. Nov 25 13:36:30 localhost.localdomain login[1110]: pam_systemd(login:session): Asking logind to create session: uid=0 pid=1110 service=login type=tty class=user seat= vtnr=0 tty=tty2 display= remote=no remote_user= remote_host= Nov 25 13:36:30 localhost.localdomain systemd[1]: Starting user-0.slice. Nov 25 13:36:30 localhost.localdomain systemd[1]: Created slice user-0.slice. Nov 25 13:36:30 localhost.localdomain systemd[1]: Cannot add dependency job for unit dmraid-activation.service, ignoring: Unit dmraid-activation.service failed to load: No such file or directory. Nov 25 13:36:30 localhost.localdomain systemd[1]: Starting User Manager for 0... Nov 25 13:36:30 localhost.localdomain systemd-logind[348]: New session 1 of user root. Nov 25 13:36:30 localhost.localdomain systemd[1]: Starting Session 1 of user root. Nov 25 13:36:30 localhost.localdomain systemd[1]: Started Session 1 of user root. Nov 25 13:36:30 localhost.localdomain login[1110]: pam_systemd(login:session): Reply from logind: id=1 object_path=/org/freedesktop/login1/session/_31 runtime_path=/run/user/0 session_fd=6 seat=seat0 vtnr=2 Nov 25 13:36:30 localhost.localdomain login[1110]: pam_unix(login:session): session opened for user root by LOGIN(uid=0) Nov 25 13:36:30 localhost.localdomain login[1110]: ROOT LOGIN ON tty2 Nov 25 13:36:30 localhost.localdomain systemd[1114]: pam_unix(systemd-user:session): session opened for user root by (uid=0) Nov 25 13:36:30 localhost.localdomain systemd[1114]: Failed to open private bus connection: Failed to connect to socket /run/user/0/dbus/user_bus_socket: No such file or directory Nov 25 13:36:30 localhost.localdomain systemd[1114]: Mounted /sys/kernel/config. Nov 25 13:36:30 localhost.localdomain systemd[1114]: Stopped target Sound Card. Nov 25 13:36:30 localhost.localdomain systemd[1114]: Stopped target Bluetooth. Nov 25 13:36:30 localhost.localdomain systemd[1114]: Starting Default. Nov 25 13:36:30 localhost.localdomain systemd[1114]: Reached target Default. Nov 25 13:36:30 localhost.localdomain systemd[1114]: Startup finished in 89ms. Nov 25 13:36:30 localhost.localdomain systemd[1]: Started User Manager for 0. Nov 25 13:37:26 localhost.localdomain systemd[1]: Cannot add dependency job for unit dmraid-activation.service, ignoring: Unit dmraid-activation.service failed to load: No such file or directory. Nov 25 13:37:26 localhost.localdomain systemd[1]: Stopping Simple Desktop Display Manager... Nov 25 13:38:56 localhost.localdomain systemd[1]: sddm.service stopping timed out. Killing. Nov 25 13:38:56 localhost.localdomain systemd[1]: sddm.service: main process exited, code=killed, status=9/KILL Nov 25 13:38:56 localhost.localdomain systemd[1]: Unit sddm.service entered failed state. Nov 25 13:38:56 localhost.localdomain systemd[1]: Starting Simple Desktop Display Manager... Nov 25 13:38:56 localhost.localdomain systemd[1]: Started Simple Desktop Display Manager. Nov 25 13:38:56 localhost.localdomain sddm[1186]: DAEMON: Initializing... Nov 25 13:38:56 localhost.localdomain sddm[1186]: DAEMON: Starting... Nov 25 13:38:56 localhost.localdomain sddm[1186]: DAEMON: Adding new display : 0 on vt 1 ... Nov 25 13:38:56 localhost.localdomain sddm[1186]: DAEMON: Started the authenticator process. Nov 25 13:38:56 localhost.localdomain sddm[1186]: DAEMON: Adding cookie to "/var/run/sddm//A:0-YUxhKn" Nov 25 13:38:56 localhost.localdomain sddm[1186]: /usr/bin/xauth: file /var/run/sddm//A:0-YUxhKn does not exist Nov 25 13:38:56 localhost.localdomain sddm[1186]: DAEMON: Display server starting... Nov 25 13:38:56 localhost.localdomain sddm[1186]: DAEMON: Display server started. Nov 25 13:38:56 localhost.localdomain sddm[1186]: DAEMON: Socket server starting... Nov 25 13:38:56 localhost.localdomain sddm[1186]: DAEMON: Socket server started. Nov 25 13:38:56 localhost.localdomain sddm[1186]: DAEMON: Greeter starting... Nov 25 13:38:56 localhost.localdomain sddm[1186]: DAEMON: Greeter started. Nov 25 13:38:56 localhost.localdomain sddm[1186]: AUTH: Started Nov 25 13:38:59 localhost.localdomain sddm[1186]: DAEMON: Message received from greeter: Connect Nov 25 13:39:18 localhost.localdomain sddm[1186]: DAEMON: Message received from greeter: Login Nov 25 13:39:18 localhost.localdomain sddm[1186]: DAEMON: Starting authentication for user "rdieter1" Nov 25 13:39:18 localhost.localdomain sddm[1186]: AUTH: Message received 0 Nov 25 13:39:18 localhost.localdomain sddm[1186]: Command 1 Nov 25 13:39:18 localhost.localdomain sddm[1186]: AUTH: PAM: Starting... Nov 25 13:39:18 localhost.localdomain sddm[1186]: AUTH: requestDisplay start Nov 25 13:39:18 localhost.localdomain sddm[1186]: AUTH: Requesting Display Nov 25 13:39:18 localhost.localdomain sddm[1186]: DAEMON: Received message 11 from the authenticator Nov 25 13:39:18 localhost.localdomain sddm[1186]: AUTH: requestDisplay end Nov 25 13:39:18 localhost.localdomain sddm[1186]: AUTH: Authenticated for user "rdieter1" Nov 25 13:39:18 localhost.localdomain sddm[1186]: AUTH: requestSessionId start ... stuck rex, unless your issue looks to have the same root cause as mine, could you file it separately, for clarity? these bugs tend to get messy. thanks! Created attachment 829189 [details]
journalctl successful boot
Tried this with a fresh image of Fedora Jam (kde based) and these packages:
kde-settings-20-7.fc20.noarch
sddm-0.2.0-0.20.20130914git50ca5b20.fc20.x86_64
and (I think) heisenbug-kde-theme-19.90.5-1.fc20.noarch
Live image boots to desktop okay both on hardware and VM, not sure what the difference is with yours. I'm attaching my journalctl from a successful boot in VM and the date-stripped diff with yours in case it helps find the cause.
I've tried booting without the threadirqs option and with two processors, neither of those seem to change the behaviour.
Created attachment 829190 [details]
date-stripped diff journalctl outputs
Ian: how many times did you try? I did say 'often'. I see a successful boot with such images _sometimes_. It's a time-sensitive condition of some kind, so it's not unexpected that its occurrence will depend on the system it's running on. *** Bug 1071057 has been marked as a duplicate of this bug. *** Created attachment 869269 [details] /var/log/messages Got this booting Fedora-Live-Jam-KDE-i686-rawhide-20140228.iso in basic graphics mode. Here is a grep sddm /var/log/messages. I took the snapshot of that file by opening a text screen with CTRL-ALT-F2. grep -n sddm of that file gives: "1592:Feb 28 16:47:11 localhost sddm: DAEMON: Initializing... 1663:Feb 28 16:47:37 localhost sddm: DAEMON: Starting... 1664:Feb 28 16:47:37 localhost sddm: DAEMON: Adding new display : 0 on vt 1 ... 1665:Feb 28 16:47:37 localhost sddm: DAEMON: Adding cookie to "/var/run/sddm//A:0-CNskot" 1666:Feb 28 16:47:37 localhost sddm: /usr/bin/xauth: file /var/run/sddm//A:0-CNskot does not exist 1667:Feb 28 16:47:37 localhost sddm: DAEMON: Display server starting... 1668:Feb 28 16:47:38 localhost sddm: DAEMON: Display server started. 1689:Feb 28 16:48:07 localhost sddm: DAEMON: Failed to start user session." Also saw bug 956482 in this file. I'll get a fresh dmesg and also the contents of /proc/lock_stats, as requested there. Created attachment 869522 [details]
/var/log/messages
Got this bug booting Fedora-Live-Jam-KDE-x86_64-rawhide-20140301.iso.
Also got bug 1056180. sddm version is sddm-0.2.0-0.24.20131125git7a008602.fc21.x86_64 Created attachment 869804 [details]
/var/log/messages
Bug still in Fedora-Live-Jam-KDE-x86_64-rawhide-20140301.iso. Booted it and selected Troubleshooting, edited basic graphics to remove rhgb and quiet.
Messages similar to comment 7 are at https://bugzilla.redhat.com/show_bug.cgi?id=984700#c15 . Created attachment 869805 [details]
Xorg.0.log file
Shows screen 0 is never assigned, hence dark screen.
Hi Peter, According to the log, the session is not started at all in this case - could you please see if the LastSession option in /etc/sddm.conf matches an actual session desktop file? Also please check if the desktop file points to a valid executable and if starting it from the terminal will work. Thanks, Martin I don't have that information any more, as this was a boot was from a live CD. I'll try again today with a more recent live CD and answer the first question. I don"t understand what you mean by "if the desktop file points to a valid executable". In past trials, CTRL-ALT-Fn, login as liveuser and startx results in a session startup. If there will be LastSession=kde-plasma.desktop line in the config, there should be a /usr/share/xsessions/kde-plasma.desktop file in the image. In the desktop file, there will be an Exec line, for example Exec=/usr/bin/startkde To try that, switch to another VT (for example vt2) and write these two commands: X vt6 :0 & #this will require you to switch back to vt2 DISPLAY=:0 /usr/bin/startkde #or what you find in the desktop file... this will start a KDE session on vt6 Please report any deviation from what I wrote. Thank you. Created attachment 869949 [details]
kde-plasma.kdesktop file
Found kde-plasma.desktop
Good. Please check if it's pointed to by the LastSession line in the SDDM config. If it is, please try running it by the two commands I supplied in Comment 16. Created attachment 869950 [details]
sddm.conf
sddm.conf points to kde-plasna.kdesktop
Created attachment 869951 [details]
tried the X commands suggested
When I tried the X vt6:0 comnand in CTRL-ALT-F2, I got a message the X server was already running.
I forgot the & at the end of the command. I'll remember next time. Does the 6 have to correspond to the screen I am using? I have a dark screen in CTRL-ALT-F1.
Created attachment 869952 [details]
/var/log/messages to point just after screen went dark
Created attachment 869965 [details]
Xorg.0.log file
I recommend not using the first one as you probably still have SDDM there. If you switch to vt2 (by using ctrl+alt+f2), it's best to choose a completely other one, 3, 6, doesn't really matter at this time. Beware of correct usage of whitespace, you have to separate the VT and the X display number. If you got the message about Xserver already running, please try for example this: X vt6 :1 DISPLAY=:1 /usr/bin/startkde Created attachment 870008 [details]
result of X vt6
Tried the first command, and ended with VTSETMODE input/output errors, as shown in the attachment. So, I didn't try the startkde command.
Please try it with different VT numbers and DISPLAY variables (the second parameter of X will change accordingly, too). It seems there could already be something on VT6... Created attachment 870109 [details]
X command starting a server on vt5
Tried Fedora-Live-Jam-KDE-i686-rawhide-20140303.iso
The lsof command showed tty6 is indeed busy:
"# lsof /dev/tty*
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME
systemd-l 688 root 18u CHR 4,6 0t0 6378 /dev/tty6
X 1391 root 14u CHR 4,1 0t0 6373 /dev/tty1
bash 1409 root 0u CHR 4,2 0t0 6374 /dev/tty2
bash 1409 root 1u CHR 4,2 0t0 6374 /dev/tty2
bash 1409 root 2u CHR 4,2 0t0 6374 /dev/tty2
bash 1409 root 255u CHR 4,2 0t0 6374 /dev/tty2
script 1452 root 0u CHR 4,2 0t0 6374 /dev/tty2
script 1452 root 1u CHR 4,2 0t0 6374 /dev/tty2
script 1452 root 2u CHR 4,2 0t0 6374 /dev/tty2
script 1454 root 1u CHR 4,2 0t0 6374 /dev/tty2
script 1454 root 2u CHR 4,2 0t0 6374 /dev/tty2"
Created attachment 870110 [details]
startkde in liveuser
Starting X gave a dark screen on 5, and still on 1. Used CTRL-ALT-F3 to run startkde. Got KDE startup screen; saw hard disk icon, didn't let run very long as I was getting error messages.
Created attachment 870111 [details]
Xorg.0.log (initial dark screen)
Created attachment 870112 [details]
Xorg.1.log (dark screen from KDE startup)
Created attachment 870114 [details]
/var/log/messages, just for the record
Today, I tried Fedora-Live-Jam-KDE-x86_64-rawhide-20140305.iso. I did the following steps: 1. Boot the DVD 2. On the Start line, hit TAB and add a 3 to the end, to start in mode 3 (text mode, no display) 3. Hit Enter to boot. 4. When the login line appears, use CTRL-ALT-F2 to get a fresh login, and login as root (no password needed). 5. Type sddm. 6. System starts up sucessfully on CTRL-ALT-F1. If I log in as liveuser in Step 4, I get the blank screen on CTRL-ALT-F1 instead. My diagnosis: on the system as distributed, sddm is being invoked under a normal user account instead of root. Indeed, if I CTRL-C in CTRL-ALT-F2, the display server shuts down. Indeed, if I use the su command before the sddm command while that session was logged in as a normal user, the systemm boots normally! Tried Fedora-Live-Jam-KDE-x86_64-rawhide-20140305.iso to get messages from sddm. Booted in mode 3. Logged in as liveuser on tty1 (default) and typed "sddm >liveone 2>livetwo &" Screen went dark. From tty2, did a "ps -e | grep sddm" and killed the sddm process. On tty1, line mode session reappeared. File liveone was empty. File livetwo contained: "DAEMON: Initializing... DAEMON: Starting... DAEMON: Adding new display : 0 on vt 1 ... DAEMON: Adding cookie to "/var/run/sddm//A:0-AiMZwf" /usr/bin/xauth: timeout in locking authority file /var/run/sddm//A:0-AiMZwf DAEMON: Display server starting... DAEMON: Display server started. DAEMON: Signal received: SIGTERM DAEMON: Display server stopping... DAEMON: Display server stopped." Still on tty1, did su, then a similar command: "sddm > rootone 2>roottwo &" Normal display appeared. I was able to kill the sddm process from tty2, but the graphical session on tty1 continued to run. Saved the root* files. After restarting, rootone was empty, and roottwo contained: "DAEMON: Initializing... DAEMON: Starting... DAEMON: Adding new display : 0 on vt 1 ... DAEMON: Adding cookie to "/var/run/sddm//A:0-SrAkbW" /usr/bin/xauth: file /var/run/sddm//A:0-SrAkbW does not exist DAEMON: Display server starting... DAEMON: Display server started. DAEMON: User session started. DAEMON: Signal received: SIGTERM DAEMON: User session stopping... DAEMON: User session ended." So the significant change is: "/usr/bin/xauth: timeout in locking authority file /var/run/sddm//A:0-AiMZwf" (dark screen) vs "/usr/bin/xauth: file /var/run/sddm//A:0-SrAkbW does not exist" (works normally). I hope this information helps pinpoint the problem. Thanks for the help in comment 23 suggesting I try the X and startkde commands. Thanks for the extensive report Peter, it's very helpful. I'll try myself in the following days to see where is the issue and try to compare with the new SDDM that I have in development currently to see if there are any differences to resolve them eventually. See also bug 1074137. Created attachment 872274 [details]
/var/log/messages for Fedora-Live-Jam-KDE-x86_64-rawhide-20140308.iso
Tried Fedora-Live-Jam-KDE-x86_64-rawhide-20140308.iso. To get a successful startup, I removed threadirqs in the boot line, boot in basic graphics mode and use mode 3, login as root and use the sddm command. In mode 5, I got a white bar across the bottom of the screen, and was unable to use CTRL-ALT-Fn to collect error messages.
I note that the sddm on koji still dates from January. I'll keep watching for new versions to try.
Was able to run edora-Live-Jam-KDE-x86_64-rawhide-20140308.iso by doing the following: 1. Boot the DVD. 2. In normal startup, use TAB to remove threadirqs and add 3 to start in mode 3. 3. CTRL-ALT-F2, login as root, and type sddm. 4. CTRL-ALT-F1 to see display. With trreadirqs, I can't seem to get error messages. Created attachment 872735 [details]
contents of ~liveuser after successfull screen start
Got a successful start of Fedora-Live-Jam-KDE-x86_64-rawhide-20140309.iso as follows:
1. Boot Fedora-Live-Jam-KDE-x86_64-rawhide-20140309.iso
2. Use TAB to add 3 to the boot line
3. Hit Enter to boot
4. When login prompt appears, CTRL-ALT-F2 to get tty2 prompt, and login as root.
5. Type sddm. Screen is replaced by tty1 login, then KDE/Jam display.
Although Jam appears to work, I note a number of .xsession-errors in the liveuser home directory, starting at line 88 of the current attachment.
When I try a normal boot, without editing the boot line, the ~liveuser/.xsession-erors contains only the line:
' DAEMON: Adding cookie to "/home/liveuser/.Xauthority"'
Created attachment 874256 [details]
/var/log/messages
Tried booting Fedora-Live-Jam-KDE-x86_64-rawhide-20140313.iso. Waited for the screen to go dark, then used TTY2 to get /var/log/messages and dmesg output. I note the following messages containing the string "tmpfs":
"dmesg.txt:210:[ 0.180253] devtmpfs: initialized
dmesg.txt:765:[ 22.091930] SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs
dmesg.txt:766:[ 22.092397] SELinux: initialized (dev devtmpfs, type devtmpfs), uses transition SIDs
dmesg.txt:778:[ 22.139902] SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs
dmesg.txt:779:[ 22.139953] SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs
dmesg.txt:780:[ 22.140583] SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs
dmesg.txt:806:[ 27.362258] SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs
dmesg.txt:879:[ 55.973522] SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs
dmesg.txt:880:[ 56.220049] SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs
messages:156:Mar 13 23:08:10 localhost kernel: [ 0.180253] devtmpfs: initialized
messages:761:Mar 13 23:07:22 localhost kernel: devtmpfs: initialized
messages:1797:Mar 14 03:09:02 localhost systemd-logind: Failed to mount per-user tmpfs directory /run/user/1000: Operation not permitted
messages:1801:Mar 14 03:09:22 localhost systemd-logind: Failed to mount per-user tmpfs directory /run/user/0: Operation not permitted"
Created attachment 874258 [details]
dmesg output
That's most likely the separate selinux bug https://bugzilla.redhat.com/show_bug.cgi?id=1075835 . Booted http://kojipkgs.fedoraproject.org//work/tasks/7808/6647808/Fedora-Live-Jam-KDE-x86_64-rawhide-20140318.iso successfully. I did a Media Check and Start, without any modification of the boot command line, and the system booted. sddm version is sddm-0.2.0-0.24.20131125git7a008602.fc21.x86_64 . Thanks for the help. I tried Fedora-Live-Jam-KDE-x86_64-rawhide-20140317.iso and got the dark screen. So the correction appeared between '0317 and '0318. I tried Fedora-Live-Jam-KDE-x86_64-rawhide-20140317.iso and got the dark screen. So the correction appeared between '0317 and '0318. As F21 has sddm instead of kdm again, and this is an approved Change, I'm proposing this as an Alpha blocker. Currently downloading today's nightly to see if the bug seems to be fixed for me or not. well, I booted today's nightly KDE a few times, verified it has sddm, and it booted correctly each time. bug may be fixed, but let's keep an eye on it for a bit. I think you were just lucky. :-) We are aware that the current SDDM in Rawhide is not reliable enough, but there are 2 months left until the Alpha change deadline. There's a new SDDM in mbriza's Copr repository that we will be trying to get into Rawhide ASAP (the new QAuth library needs to go through review, but that should be an easy one): https://copr.fedoraproject.org/coprs/mbriza/sddm/ sddm-0.2.0-0.29.20140623gitdb1d7381.fc20 has been submitted as an update for Fedora 20. https://admin.fedoraproject.org/updates/sddm-0.2.0-0.29.20140623gitdb1d7381.fc20 sddm-0.2.0-0.29.20140623gitdb1d7381.fc19 has been submitted as an update for Fedora 19. https://admin.fedoraproject.org/updates/sddm-0.2.0-0.29.20140623gitdb1d7381.fc19 Package sddm-0.2.0-0.29.20140623gitdb1d7381.fc19: * should fix your issue, * was pushed to the Fedora 19 testing repository, * should be available at your local mirror within two days. Update it with: # su -c 'yum update --enablerepo=updates-testing sddm-0.2.0-0.29.20140623gitdb1d7381.fc19' as soon as you are able to. Please go to the following url: https://admin.fedoraproject.org/updates/FEDORA-2014-7749/sddm-0.2.0-0.29.20140623gitdb1d7381.fc19 then log in and leave karma (feedback). sddm-0.2.0-0.31.20140627gitf49c2c79.fc20 has been pushed to the Fedora 20 stable repository. If problems still persist, please make note of it in this bug report. sddm-0.9.0-1.20141007git6a28c29b.fc19 has been submitted as an update for Fedora 19. https://admin.fedoraproject.org/updates/sddm-0.9.0-1.20141007git6a28c29b.fc19 |
Created attachment 828819 [details] journalctl from a failed boot I've been testing live images with more recent sddm builds - intended to help fix #1004621 - since late Beta time. In my testing in a standard qxl/SPICE KVM, they often fail to boot successfully, they just boot to a black screen, not a working desktop. ctrl-alt-F2 gets you a tty. This is obviously a show-stopping issue. Attaching journalctl output from a failed boot. This is with sddm-0.2.0-0.21.20131125git7a008602.fc20 (apparently the changes from 21 to 22 are not relevant to this).