Hide Forgot
Created attachment 481687 [details] Screenshot Description of problem: `init 5` does nothing Version-Release number of selected component (if applicable): http://alt.fedoraproject.org/pub/alt/stage/15-Alpha.RC2/Live/i686/Fedora-15-Alpha-i686-Live-Desktop.iso How reproducible: 100% Steps to Reproduce: 0. Download Fedora-15-Alpha-i686-Live-Desktop.iso 1. Boot with "3" in kernel paremeters 2. Log in as root and run: init 5 Actual results: Nothing happens Expected results: gdm should start and show login screen See screenshot...
What does "dmesg" show in this case? If it shows nothing of interest in this case, could you reboot and pass "systemd.log_level=debug" and "systemd.log_target=kmsg" on the kernel command line? Then please check dmesg again and paste the output here that is generated when you enter "init 5"
Created attachment 481698 [details] /var/log/messages Sorry forgot to attach logs. Note: times in logs and times in "screenshot" are same, that's what I made that PS1='`date +%H:%M:%S` '$PS1 on the screenshot for.
Hmm, there are quite a few SELinux issues. Could you please redo this with "systemd.log_level=debug" and "systemd.log_target=kmsg" on the kernel command line? Unfortunately this output shows no problem at all.
Created attachment 481716 [details] Screenshot 2 Screenshot with new times
Created attachment 481717 [details] /var/log/messages 2 Logs for the "Screenshot 2" scenario with: systemd.log_level=debug systemd.log_target=kmsg Times in logs and screenshot are same again. PS: just curious, doesn't same thing happens with everyone when booting from Fedora-15-Alpha-i686-Live-Desktop.iso?
hmm, so can you paste "systemctl list-jobs" when this happens? And also "systemctl status graphical.target"? The logs look completely fine.
(In reply to comment #5) > PS: just curious, doesn't same thing happens with everyone when booting from > Fedora-15-Alpha-i686-Live-Desktop.iso? No, it worked fine for me with this iso in a KVM guest. Both in the live system itself and after installation. [resetting needinfo]
Created attachment 481837 [details] Screenshot 3 One more screenshot. Includes `systemctl list-jobs` and `systemctl status graphical.target`, kernel params include systemd.log_level=debug systemd.log_target=kmsg
Created attachment 481838 [details] /var/log/messages 3 Logs for the "Screenshot 3" scenario Times in logs and screenshot are same again. > The logs look completely fine. A bunch of "audispd[861]: queue is full - dropping event" in logs every time at exactly same second I'm running `init 5` look very suspicious to me.
> No, it worked fine for me with this iso in a KVM guest. > Both in the live system itself and after installation. I'm testing it live, without installing. Checked 3 different real machines. The bug always reproduces itself on each of them. BTW, just noticed: `init 5` works if initially I run it from tty1. But when I'm trying from tty2 (see each of my screenshots), tty3, etc. - I get the bug.
Hmm, so it does switch to runlevel 5 initially? And if you are in runlevel 5 it doesn't switch anymore? That is hardly surprising? What's the problem here?
The screenshot shows the job firstboot-graphical.service is running. Have you tried switching to a different tty afterwards? The firstboot application may be waiting somewhere on your input. Until firstboot ends, the runlevel will not be reached. If the firstboot process is running, but you don't see it on any tty, try killing it. Is the runlevel 5 reached then?
(In reply to comment #11) > Hmm, so it does switch to runlevel 5 initially? Maybe it does, but I don't see that. There's no GDM on any tty, I scrolled them all (press Alt+Right and hold), just text. Does it switch runlevel in some way, that is invisible to user? > And if you are in runlevel 5 it doesn't switch anymore? > That is hardly surprising? Well, but I'm not in runlevel 5. And I cannot get to runlevel 5. As I wrote in bug description, and as you could see in logs, I booted with "3" in kernel params. And as you can see on a screenshot the `runlevel` command also reports "N 3". > What's the problem here? No GDM, no graphical login screen...
(In reply to comment #12) > The screenshot shows the job firstboot-graphical.service is running. > Have you tried switching to a different tty afterwards? Yes, checked them all with Alt+Left/Alt+Right. tty1 is dead after I run `init 5` on tty2, but tty2-tty6 are all working. I can login and get bash there. > Until firstboot ends, the runlevel will not be reached. If the firstboot > process is running, but you don't see it on any tty, try killing it. Is the > runlevel 5 reached then? Nothing to kill: # ps ax | grep first 1338 tty2 S+ 0:00 grep --color=auto first # NOTE: if after I boot I don't switch to tty2, and try logging in on tty1 and run `init 5` there - it works. But if I switch to tty2... see bug description. PS: I had just reproduced the same problem with: $ qemu -cdrom Fedora-15-Alpha-i686-Live-Desktop.iso
The tty 'init 5' is run from is indeed important. I can indeed reproduce this on tty2. It can be reproduced on latest F15 + updates-testing: 1) systemctl enable firstboot-graphical.service 2) reboot into runlevel 3 3) switch to tty2 4) init 5 Then I see: # systemctl list-jobs --full 295 graphical.target start waiting 406 prefdm.service start waiting 395 systemd-update-utmp-runlevel.service start waiting 403 firstboot-graphical.service start running 411 systemd-readahead-done.timer start waiting # systemctl status firstboot-graphical.service firstboot-graphical.service - firstboot configuration program (graphical mode) Loaded: loaded (/lib/systemd/system/firstboot-graphical.service) Active: activating (start-pre) since Thu, 03 Mar 2011 09:05:52 +0100; 6min ago Control: 871 (sd:exec) CGroup: name=systemd:/system/firstboot-graphical.service └ 871 sd:exec 3 The process 871 is sleeping forever, blocked on reading from the inotify fd. Backtrace of PID 871: #0 0x0000003becc0e5f0 in __read_nocancel () at ../sysdeps/unix/syscall-template.S:82 No locals. #1 0x0000000000461310 in read (__nbytes=4112, __buf=0x7fff47d00c10, __fd=3) at /usr/include/bits/unistd.h:45 No locals. #2 acquire_terminal (name=0x4717e6 "/dev/console", fail=false, force=false, ignore_tiocstty_eperm=false) at src/util.c:2284 inotify_buffer = "OlG", '\000' <repeats 13 times>, "a\006H\000\000\000\000\000\304\071H\000\000\000\000\000\360\020D\000\000\000\000\000OlG", '\000' <repeats 13 times>, "a\006H\000\000\000\000\000ZlG\000\000\000\000\000\360\020D\000\000\000\000\000OlG\000\000\000\000\000Ь\372\000\000\000\000\000a\006H\000\000\000\000\000\332\071H\000\000\000\000\000\360\020D\000\000\000\000\000OlG", '\000' <repeats 13 times>, "a\006H\000\000\000\000\000\251fG\000\000\000\000\000\360\020D\000\000\000\000\000OlG\000\000\000\000\000@\n\370\000\000\000\000\000a\006H\000\000\000\000\000\342\071H\000\000\000\000\000\360\020D\000\000\000\000\000OlG\000\000\000\000\000`\276\367\000\000\000\000\000a\006H\000\000\000\000\000\263"... l = <optimized out> e = <optimized out> fd = 4 notify = 3 r = <optimized out> wd = 1 __PRETTY_FUNCTION__ = "acquire_terminal" __func__ = "acquire_terminal" #3 0x0000000000437bf1 in setup_input (apply_tty_stdin=true, socket_fd=<optimized out>, context=0xf83c48) at src/execute.c:278 fd = <optimized out> r = <optimized out> i = EXEC_INPUT_TTY #4 exec_spawn (command=0xf81710, argv=0x1086f70, context=0xf83c48, fds=0x0, n_fds=0, environment=0x1d94300, apply_permissions=true, apply_chroot=true, apply_tty_stdin=true, confirm_spawn=false, cgroup_bondings=0xf79a20, ret=0x7fff47d01f78) at src/execute.c:1057 i = <optimized out> ss = {__val = {0 <repeats 16 times>}} keep_stdout = <optimized out> gid = 4294967295 our_env = 0x0 pam_env = 0x0 final_argv = 0x0 username = 0x0 keep_stdin = <optimized out> home = 0x0 uid = 4294967295 final_env = 0x0 n_env = 0 saved_stdout = -1 saved_stdin = -1 pid = <optimized out> r = <optimized out> line = <optimized out> socket_fd = -1 __PRETTY_FUNCTION__ = "exec_spawn" __func__ = "exec_spawn" #5 0x000000000041fee9 in service_spawn (s=<optimized out>, c=<optimized out>, timeout=<optimized out>, pass_fds=<optimized out>, apply_permissions=true, apply_chroot=true, apply_tty_stdin=true, set_notify_socket=false, _pid=0xf83df0) at src/service.c:1677 pid = <optimized out> r = <optimized out> fds = 0x0 fdsbuf = 0x0 n_fds = 0 n_env = <optimized out> argv = 0x1086f70 final_env = 0x1d94300 our_env = 0x1d8a170 __PRETTY_FUNCTION__ = "service_spawn" #6 0x00000000004224f1 in service_enter_start_pre (s=0xf83a60) at src/service.c:2074 r = <optimized out> #7 service_start (u=0xf83a60) at src/service.c:2271 s = 0xf83a60 __PRETTY_FUNCTION__ = "service_start" __func__ = "service_start" #8 0x000000000046d0ad in job_run_and_invalidate (j=0x1d93be0) at src/job.c:391 r = <optimized out> id = 403 m = 0xec7950 __PRETTY_FUNCTION__ = "job_run_and_invalidate" #9 0x000000000040ef74 in manager_dispatch_run_queue (m=0xec7950) at src/manager.c:1842 j = <optimized out> n = <optimized out> __PRETTY_FUNCTION__ = "manager_dispatch_run_queue" #10 0x0000000000410555 in manager_loop (m=0xec7950) at src/manager.c:2341 event = {events = 1, data = {ptr = 0x1d8a820, fd = 30976032, u32 = 30976032, u64 = 30976032}} n = <optimized out> r = <optimized out> rl = {interval = 1000000, begin = 176367520, burst = 1000, num = 11} __PRETTY_FUNCTION__ = "manager_loop" __func__ = "manager_loop" #11 0x00000000004088b4 in main (argc=<optimized out>, argv=<optimized out>) at src/main.c:1229 m = 0xec7950 r = <optimized out> retval = 1 fds = 0x0 reexecute = false shutdown_verb = 0x0 initrd_timestamp = {realtime = 1299139376631545, monotonic = 793278} systemd = "systemd" __func__ = "main" __PRETTY_FUNCTION__ = "main"
... and doing 'systemctl stop firstboot-graphical.service' allows the runlevel switch to complete.
/lib/systemd/system/firstboot-graphical.service has: StandardInput=tty This means systemd will wait for /dev/console to become available. We're switched to tty2, so /dev/console is redirected to /dev/tty2. The console will not become available, because our interactive session is running there. firstboot really wants to run on tty1 - it is hardcoded in xfrontend.py, and we also make sure to quit the getty on tty1 when we're going to graphical.target. So adding this to firstboot-graphical.service fixes it: TTYPath=/dev/tty1
Ah, thanks a ton Michal for tracking this down! Hmm, if firstboot fights against the getty on tty1 and if firstboot wants to take advantage of the X11 screen fading from Plymouth, then it probably should have lines like the following in the .service file: Conflicts=plymouth-quit.service Before=getty After=plymouth-quit.service Hmm, one more question, before I reassign this to firstboot: why precisely does the graphical firstboot service file actually need a tty assigned from systemd? If it spawns X, then X will acquire the tty anyway on its own? Hence we probably should remove StandardInput=tty from firstboot-graphical.service. The result would then be for firstboot-graphical.service: <snip> [Unit] Description=firstboot Configuration Program (Graphical Mode) After=livesys.service plymouth-quit.service Before=prefdm.service getty Conflicts=firstboot-text.service plymouth-quit.service [Service] Environment=RUNLEVEL=5 ExecStart=/etc/init.d/firstboot start TimeoutSec=0 RemainAfterExit=yes Type=oneshot SysVStartPriority=99 [Install] WantedBy=graphical.target </snip> And for firstboot-text.service: <snip> [Unit] Description=firstboot Configuration Program (Text Mode) After=livesys.service plymouth-quit.service Before=prefdm.service getty [Service] Environment=RUNLEVEL=3 ExecStart=/etc/init.d/firstboot start TimeoutSec=0 RemainAfterExit=yes Type=oneshot SysVStartPriority=99 StandardInput=tty TTYPath=/dev/tty1 [Install] WantedBy=multi-user.target </snip>
(Also, as an optimization, /etc/init.d/firstboot should execute a single "/bin/systemctl disable firstboot-graphical.service firstboot-text.service" instead of two separate ones, since that allows us to issue a single reload request to systemd only, which is a lot cheaper)
OK, reassigning to firstboot now. firstboot maintainers, please look into the suggestions from comment 18!
Lennart, why do we need the "SysVStartPriority=99" ? I had it there and firstboot exited when I pressed enter, I talked to you about it a while ago. Also if you remember, we found out the plymouth-quit.service doesn't work (because of gdm or something), I had to add "ExecStartPre=-/bin/plymouth quit" to the firstboot service file.
(In reply to comment #21) > Lennart, why do we need the "SysVStartPriority=99" ? I had it there and > firstboot exited when I pressed enter, I talked to you about it a while ago. SysVStartPriority= is usefult to order a service relative to SysV services which have no LSB header and hence are sorted only and exclusively by their priority value in /etc/rc?.d/ or the chkconfig header. SysVStartPriority=99 hence means "run this after all SysV services which have no proper ordering information" > Also if you remember, we found out the plymouth-quit.service doesn't work > (because of gdm or something), I had to add "ExecStartPre=-/bin/plymouth quit" > to the firstboot service file. Hmm, no? i don't remember this? plymouth-quit.service should work, at least as soon as bug 679503 is fixed which right now is buggy an sometimes freezes your machine.