Description of problem: plymouth-quit-wait.service seems to add significant time to boot for no reason. Version-Release number of selected component (if applicable): plymouth-0.9.4-11.20191022git32c097c.fc32.x86_64 How reproducible: Always, every boot Steps to Reproduce: 1. Clean install Fedora Workstation 32/Rawhide, reboot 2. 3. Actual results: plymouth-quit-wait.service unmasked Startup finished in 1.887s (kernel) + 2.593s (initrd) + 10.872s (userspace) = 15.353s plymouth-quit-wait.service masked Startup finished in 1.846s (kernel) + 2.445s (initrd) + 3.868s (userspace) = 8.160s $ systemd-analyze blame 8.328s plymouth-quit-wait.service Expected results: I expect it shouldn't increase boot time. Additional info:
plymouth-quit-wait.service does not increase boot time, it waits for plymouth to be told by gdm to quit, so it runs beyond when gdm starts and once gdm starts you get your login screen, so although systemd-analyze counts plymouth-quit-wait.service as part of boot time, you win nothing by masking it, except that it drops from the statistics. Try using a stopwatch to time the time from say pressing enter in the grub menu till the login screen shows and you will see that masking plymouth-quit-wait.service does not change a thing.
Using the stopwatch method, unmasked plymouth-quit-wait.service boots ~3.5s faster. Sample size is 3 boots each.
Created attachment 1655588 [details] unmasked plymouth-quit-wait, systemd-analyze plot
Created attachment 1655589 [details] masked plymouth-quit-wait, systemd-analyze plot
>unmasked plymouth-quit-wait.service boots ~3.5s faster s/unmasked/masked
(In reply to Chris Murphy from comment #2) > Using the stopwatch method, unmasked plymouth-quit-wait.service boots ~3.5s > faster. Sample size is 3 boots each. Thank you for testing that, that is really weird though, looking at the systemd-analyze outputs in both cases gdm starts at around the 9.5 second mark and there really is no reason why it showing the login screen should wait for plymouth-quit-wait.service. I guess that gdm is waiting for login's to be ok according to account-manager or some such and that that only happens once systemd believes the graphical target has been reached...
I coincidentally ran into a related user report. They're disabling plymouth by boot parameter, not merely the wait systemd service unit. They found a significant delay with systemd-analyze, but I followed up with a request that they use a stop watch. They reported back finding a 3s delay with and without plymouth. https://ask.fedoraproject.org/t/disabling-plymouth-reduces-boot-time-by-50-percent/5160/4?u=chrismurphy
Thank you for pointing out the other bug / https://ask.fedoraproject.org/t/disabling-plymouth-reduces-boot-time-by-50-percent/5160/ to me. I've been investigating why plymouth-quit-wait.service might be making the login screen showing take 3 seconds longer for you, but I've been unable to reproduce this. gdm will tell plymouth to quit when it gets a connection from the greeter, iow when the login screen shows. So theoretically the systemd-analyze time with plymouth-quit-wait.service included should be a good indication of the boot time, but clearly it isn't. What might be interesting is if you can add "plymouth.debug=stream:/dev/null" to your kernel commandline, this will make plymouth write out a debug log to /var/log/plymouth-debug.log including timestamps. plymouth will quit when told to by gdm independent of the masking of plymouth-quit-wait.service, so it would be interesting to see if masking / unmasking it results in a significantly different end-time in the /var/log/plymouth-debug.log .
Created attachment 1656074 [details] debug log quit-wait masked stopwatch 18s
Created attachment 1656076 [details] debug log quit-wait unmasked stopwatch 19s
Thanks, so in both cases plymouth gets told to deactivate at 10.5 seconds or to be precise at 00:00:10.496 to the millisecond exactly on both cases (coincidence much?). And in both cases plymouth gets told to quit around the same time, at 00:00:16.779 (unmasked) resp. 00:00:16.543 (masked) and then actually quits at 00:00:16.790 (masked) resp. 00:00:16.554 (masked). So I do not really see much if any difference between the two.
While working on another bug (bug 1794333) I did notice that plymouth does cause a boot delay, unrelated to plymouth-quit-wait.service. When asked by gdm to deactivate gdm finishes the current throbber animation which is on a cycle of 2 seconds; and then also plays an end animation which takes 1 second. Plymouth tries to predict the boot time using a measurement of the previous boot and then starts the end-sequence described above at 90%, but that is not reliable and with modern boot times of say 5 seconds, the 10% used as margin is only 0.5 seconds where as the end sequence may last up to 3 seconds (if we are unlucky). I've prepared a plymouth patch which adds an option to immediately deactivate when requested to deactivate, skipping the wait (which may last up to 3 seconds), this comes at the cost of the transition to gdm being somewhat more abrupt (no more one last fading out circling round of the spinner). I've done a scratch-build of plymouth with this patch added, please give it a try and: a) Check if it reduces boot time b) Let me know what you think of the new transition to gdm vs the old transition. You can find the scratch-build here: https://koji.fedoraproject.org/koji/taskinfo?taskID=41654795
p.s. To install the plymouth from koji do the following: 1) Run "rpm -qa | grep plymouth | sort" 2) Download the rpms from the link for the plymouth (sub)packages which you have installed 3) In a folder with the downloaded rpms run: "sudo rpm -Uvh plymouth*" 4) Run "sudo dracut -f" to regenerate the initrd for your currently running kernel so that the new plymouth gets added to it 5) Run "uname -a" note the kernel version 6) reboot 7) Run "uname -a" again, if the kernel version is different the kernel was upgraded since you last rebooted, go to step 4.
plymouth-0.9.4-12.20191022git32c097c.fc32.x86_64 $ systemd-analyze Startup finished in 1.453s (kernel) + 2.806s (initrd) + 8.411s (userspace) = 12.671s graphical.target reached after 8.401s in userspace stop watch: grub press enter, to appearance of gdm (gray) 13.69s plymouth-0.9.4-13.20191224gitd7c737d.fc31.x86_64 $ systemd-analyze Startup finished in 1.425s (kernel) + 2.923s (initrd) + 7.940s (userspace) = 12.288s graphical.target reached after 7.924s in userspace stop watch: grub press enter, to appearance of gdm (gray) 13.22s I'm offhand not noticing a difference in time or the transition. But I applied that update to an f32 laptop. I did do 'dracut -f' and it's a one kernel system so, I'm not sure.
(different laptop, running f31) plymouth-0.9.4-11.20191022git32c097c.fc31.x86_64 $ systemd-analyze Startup finished in 1.212s (kernel) + 1.380s (initrd) + 3.819s (userspace) = 6.412s graphical.target reached after 3.810s in userspace stop watch: grub press enter, to appearance of gdm (gray) 11.73s plymouth-0.9.4-13.20191224gitd7c737d.fc31.x86_64 $ systemd-analyze Startup finished in 1.204s (kernel) + 1.350s (initrd) + 4.115s (userspace) = 6.670s graphical.target reached after 3.935s in userspace stop watch: grub press enter, to appearance of gdm (gray) 11.03
Chris, thank you for testing I guess you are not using full disk encryption ? That (fd encryption) causes us to get the boot time estimate significantly wrong which causes the biggest delay. Note that the max theoretical improvement from the patches is 3 seconds, so seeing you get 0.5 seconds improvement on the stopwatch times is ok, even though that is somewhat in the error margin of how accurate our measurements are... Anyways I'm happy to see that at least there are no regressions for you and that you do not notice any change in then transation. My biggest worry with this change is that people would find the new faster transition ugkly.
(In reply to Hans de Goede from comment #16) > Chris, thank you for testing I guess you are not using full disk encryption ? No encryption. However, sysroot is btrfs with zstd compression. > My biggest worry with this change is that people would find the new faster > transition ugkly. I'm not seeing a difference so I can't assess.