Created attachment 1759616 [details]
screenshot of the bug

This does not seem to happen if the configured Plymouth theme (e.g. the default theme) is installed. It only happens if the configured theme is not installed, and so the fallback-y 'grey screen with two blobs on it' thing is used.

(In reply to Adam Williamson from comment #2)
> This does not seem to happen if the configured Plymouth theme (e.g. the
> default theme) is installed. It only happens if the configured theme is not
> installed, and so the fallback-y 'grey screen with two blobs on it' thing is
> used.

Right, so I guess this has to do with the flavor of Fedora which is being tested? I would expect e.g. Fedora Workstation to always have the default theme installed.

The fallback "text" theme has not seen any serious work done on it for ages; and I personally have never touched that code.

I think it would be better for spins / flavors which don't install the default-theme to just disable plymouth altogether, either by removing "rhgb" from the kernel commandline, or by just not installing any parts of plymouth at all...

Default Server install doesn't install the default theme. So I'm having lots of fun because the Server tests in openQA fail unpredictably due to this. I can hack around that in openQA, but people just running a default Server install are going to run into this in real life.

In comps, plymouth is 'mandatory' in the 'core' group, but 'plymouth-system-theme' is only in the 'base-x' group. I guess this is because installing a graphical theme pulls in quite a lot more dependencies than just the core of plymouth and the text theme, but if it's going to cause problems like this, I guess we can maybe move plymouth itself to base-x (so only graphical installs that likely include all the deps anyway will pull it in)?

Proposing this as a BetaFE as it looks ugly and unpolished when it happens, and it'll happen in many important cases (Server, minimal...)

Ah, hmm, well, there'd potentially be a problem with not installing plymouth: we may not get a decryption prompt on boot, if a system partition is encrypted. That is actually why we put plymouth in core (base at the time) way back in F17:

https://bugzilla.redhat.com/show_bug.cgi?id=794899

I guess we'd need to test an encrypted install without plymouth and see how it behaves.

(In reply to Adam Williamson from comment #6)
> I guess we'd need to test an encrypted install without plymouth and see how
> it behaves.

Yes, I believe that systemd should handle asking for a password just fine without having plymouth installed.

So if you can test that and then move plymouth out of the core group that would seem best. It is sort of weird to have plymouth in the core group anyways. It is only supposed to be a bootsplash, not a core component.

I've sent a mail to devel@ and server@ summarizing the situation and asking for opinions. I gotta be honest, I would be happiest if we could just fix the actual bug...

CCing Bill to see if he remembers any more detail about why specifically we wanted plymouth in @core back then.

I don't really remember; the logic referenced (it was used for passphrase entering, and this was before systemd handled this more natively) certainly sounds correct.

I think at the time there was a base text screen that had a text progress bar, and this may predate FB/KMS/etc everywhere?

https://pagure.io/fedora-comps/pull-request/631 would address this by dropping plymouth from @core and @standard (though the bug would still *exist*).

(In reply to Adam Williamson from comment #11)
> https://pagure.io/fedora-comps/pull-request/631 would address this by
> dropping plymouth from @core and @standard (though the bug would still
> *exist*).

I agree that the bug would still exist, can you perhaps file an issue for this upstream:
https://gitlab.freedesktop.org/plymouth/plymouth/-/issues/

And also attach the screenshot of the issue there ?

plymouth serves three purposes:

1) boot messages logger
2) disk encryption password
3) splash screen

the boot messages logger is a bit silly at this point, the journal is so much more useful than a bunch of "Starting foo.... [OK]" messages or whatever ends up in there now.
system.

systemd did indeed grow support for asking for a password without plymouth involved, so it's not too useful either, if the message is going to show up as a text prompt anyway.
(of course plymouth is still useful for showing a "pretty" disk encryption password screen, but that's not relevant for users using the fallback splash)

The splash screen will be graphical by default, but it can fall back to "text" even if graphical is enabled.  Say the user puts "nomodeset" on the kernel command line or something.

plymouth probably should clear the screen when its quit without --retain-splash, I suppose, but on the other handy, the agetty should be getting started with VTDisallocate=TRUE in 
the service file so it should get cleared on its own.  Did the service file change?

The other possibility is the "plymouth --wait" call in plymouth-quit-wait service is returning early for some reason so plymouth is still running when agetty is starting up.

adamw, can you try adding a 

ExecStartPost=/usr/bin/sleep 5

to plymouth-quit-wait.service and see if the problem vanishes ?

hmm, the text splash has this:

static void•
destroy_plugin (ply_boot_splash_plugin_t *plugin)•
{•
...
        /* It doesn't ever make sense to keep this plugin on screen•
         * after exit•
         */•
        hide_splash_screen (plugin, plugin->loop);•
...
}• 

where hide_splash_screen calls view_hide which does this:

static void•
view_hide (view_t *view)•
{•              
        if (view->display != NULL) {•
                ply_terminal_t *terminal;•
•       
                terminal = ply_text_display_get_terminal (view->display);•
...
                ply_text_display_clear_screen (view->display);•
...
        }•
}•      

So things should be working, unless it's a case of getty starting before plymouth quits.

so i think what we need is to see the boot with with verbose logging turned on to see the order of things.  I think the kernel command line should be something like:

systemd.log_target=kmsg systemd.log_level=debug plymouth.debug=stream:/dev/kmsg log_buf_len=1M printk.devkmsg=on

to get full logs to dmesg.

This will hopefully show us what systemd is doing, what plymouth is doing, and show if things are happening out of order.

adamw is this something you can inject into your reproduction environment?

+3 in https://pagure.io/fedora-qa/blocker-review/issue/280 , marking accepted.

Ray, I'll get to your notes later today, thanks!

I've merged the comps PR now, which should address the FE element of this. Let's keep the report open for the actual bug, though.

Note, changing this has (further) exposed another issue on aarch64: without plymouth installed, we don't get boot messages (and the decryption prompt) on the monitor on aarch64 systems, even booting with console=tty0. See https://bugzilla.redhat.com/show_bug.cgi?id=1940163 .

While working on another kernel/plymouth integration issue (bug 1941329) I think I have figured out the problem here.

The tribar and text plugins both clear the screen from hide_views (), which calls ply_text_display_clear_screen () for each registered text-terminal/view (the console and a serial console can be 2 separate terminals/views).

This should be called on exit through this call tree:

quit_splash () -> ply_boot_splash_free () -> ply_boot_splash_unload () -> destroy_plugin() -> hide_splash_screen () -> hide_views ()

But ply_boot_splash_free () calls remove_pixel_displays () which unregisters all the terminals/views before calling ply_boot_splash_unload (), so when hide_views () runs and iterates over all the registered terminals to clear them, there are no registered terminals to clear.

Fixing this should be easy. I'll prepare a patch for this.

Nevermind, main.c always calls hide_splash () before calling quit_splash () so that is not it.

One interesting observation, to reproduce I had to not just do:

sudo rm /lib64/plymouth/renderers/*
sudo dracut -f

But I also had to edit /lib/systemd/system/getty@.service and change the following 2 lines:

TTYReset=yes
TTYVTDisallocate=yes

From yes to no. I wonder if the server spin is somehow using a different getty configuration then workstation?

Note, the problem doesn't happen every time, it's not even 50% of the time, IIRC. We got a handful of failures on this out of dozens of tests.

So unless you tried many times after each change, you may just have been seeing randomness and the changes may not have mattered.

Sorry, I never did get back to Ray's notes on debugging this after the comps change, but we should really fix this properly. I'll try and do them soon.

(In reply to Adam Williamson from comment #24)
> Note, the problem doesn't happen every time, it's not even 50% of the time,
> IIRC. We got a handful of failures on this out of dozens of tests.

Interesting, I guess that the tty-clearing done by systemd sometimes failed. After I edited the getty service to disable the tty clearing done by systemd I can 100% reproduce this issue.

I've also found an easier reproducer which is to switch between the "text" splash and detailed mode while a diskcrypt password is shown, in this case the details mode will also show the background with plymouths "grey" background color except for the parts which are overwritten with actual details text, which do get a black background.

This reproduces has also allowed me to prepare a fix, which fixes both the detailed-screen and the login/getty screen grey background issue for me.

> Sorry, I never did get back to Ray's notes on debugging this after the comps
> change, but we should really fix this properly. I'll try and do them soon.

Actually specifying plymouth.debug=stream:... on the kernel commandline turns ply_text_display_clear_screen () into a no-op for debugging, breaking both the "text" splash, as well as details <-> text splash switching and also makes a mess of the login/getty screen (with systemd's tty clearing disabled).

Fixing the plymouth.debug=stream:... issue is the first thing which I ended up doing, as I was using that for debugging myself too.

I'll post a merge-req upstream with a bunch of fixes for this soon.

Here is the promised merge-request which fixes both my reproducers for this:

https://gitlab.freedesktop.org/plymouth/plymouth/-/merge_requests/137

Adam, do you want a plymouth build to check if this also fixes the openQA tests issue you were seeing?  I'm pretty sure that I've got this fixed, but if you want to double check let me know.

If you're pretty sure about it, I'm fine with just pulling the fix in. Then we might want to put plymouth back into at least ARM base installs, because of https://bugzilla.redhat.com/show_bug.cgi?id=1940163 ...

A quick status update on this:

I've been also working on another plymouth fix for bug 1941329. I wanted to also get that bug fixed in the next Fedora plymouth build because the root-cause of it worries me a bit:

What I believe is happening here is that the "gracefully shutdown" of displays which the kernel's i915 driver recently introduced in commit fe0f1e3bfdfe ("drm/i915: Shut down displays gracefully on reboot") is getting undone. Because of being "unkillable" plymouthd keeps running and showing the spinner animation to the very end, this results in a drmModeSetCrtc () call after the i915 display driver has turned off the displays. This causes 2 issues:

1. This causes the screen to go black for 1-2 seconds and then show the plymouth screen again for 1-2 seconds on poweroff/reboot which looks ugly, this is bug 1941329.

2. This may cause issues with the attached monitors on reboot, since it undoes the gracefull shutdown which the i915 driver does, this is the bit with has me worried a bit and why I've been working on a fix for this.

I've now completed the fix for this, based on earlier work on a related shutdown issue from Ray:
https://gitlab.freedesktop.org/plymouth/plymouth/-/merge_requests/138

This related shutdown issue is the rootfs sometimes not being cleanly unmounted on shutdown/reboot and this is also resolved by this new merge-request. Which is another reason why I wanted to this fix included in the next Fedora plymouth build, the system sometimes not cleanly unmounting the rootfs is also something which really needs (needed) to be fixed.

I'm currently preparing a new plymouth build for F34+ which includes both fixes.

The second fix is not really trivial (but it should be ok / safe), so I will disable auto-pushing to stable for the F34 update because I'm not 100% sure if we want this in F34 final, or if it would be better as a 0 day update. I expect this to be fine for F34 final, but I want to wait till at least coming Sunday before pushing this to stable.

Ugh, the build is stuck waiting for a backlog on the s390x builders.

Adam, if you want to get a head-start with testing this, you can find rpms for all arches except s390x here:

https://koji.fedoraproject.org/koji/taskinfo?taskID=64933897

(assuming you can somehow inject these in OpenQA through some local repo)

> Then we might want to put plymouth back into at least ARM base installs, because of https://bugzilla.redhat.com/show_bug.cgi?id=1940163 ...

I've no strong preference for pulling plymouth back in, or not. AFAIK plymouth does have the advantage of asking for the LUKS password on all available text displays (so both console + a serial tty) which the systemd replacement seems to not do.

FEDORA-2021-cbe477064d has been submitted as an update to Fedora 34. https://bodhi.fedoraproject.org/updates/FEDORA-2021-cbe477064d

Unfortunately the fix for bug 1941329 does not fully work when selinux is in enforcing mode, I've filed a bug against selinux-polciy for this, see bug 1945585.

selinux policy blocks plymouthd from executing the new plymouthd-drm-escrow helper which is there to keep the /dev/dri/card# fds open during shutdown. This means that when the system is ready to shutdown (or transfers control back to the initramfs if the rootfs storage needs some extra work for a clean shutdown), the text-console will be shown with the last couple of messages which is not the smooth shutdown/reboot look we want, but it is not really a big problem either.

Note the 2 initial issues which the fix for bug 1941329 targets are still fixed even with selinux in enforcing mode, all the selinux issue does is make the shutdown somewhat less pretty to look at.

IMHO the bugs fixed in the FEDORA-2021-cbe477064d plymouth update are more important to fix then this not-pretty but otherwise completely harmless shutdown/reboot problem; and hopefully we will be able to get a selinux fix for this as a 0-day update.

I definitely want to get a new selinux-policy build in before release, so we may get it fixed for the release if Zdenek picks it up quickly.

Thanks for this, I'll see what I can do to test it before we push it stable; right now plymouth is still removed from comps so openQA will not really test the fix for the issue, but I should be able to hack things up a bit and test it out.

(In reply to Adam Williamson from comment #32)
> I definitely want to get a new selinux-policy build in before release, so we
> may get it fixed for the release if Zdenek picks it up quickly.

Good news, I've been working on this with Zdenek and a fix is available now,
this should make the last pre-GA selinux-policy build.

> Thanks for this, I'll see what I can do to test it before we push it stable;
> right now plymouth is still removed from comps so openQA will not really
> test the fix for the issue, but I should be able to hack things up a bit and
> test it out.

Great, thank you.

FEDORA-2021-cbe477064d has been pushed to the Fedora 34 testing repository.
Soon you'll be able to install the update with the following command:
`sudo dnf upgrade --enablerepo=updates-testing --advisory=FEDORA-2021-cbe477064d`
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2021-cbe477064d

See also https://fedoraproject.org/wiki/QA:Updates_Testing for more information on how to test updates.

The update just got its first positive karma and in my own somewhat intensive testing on multiple machines everything works well too. So I would like to push this to stable before the freeze.

But before I hit the push-to-stable button I wanted to double check if that is ok here. Adam is pushing the plymouth update for this to stable ok with you ?

sorry, I did not get to this before the weekend, and I'm actually supposed to be off monday and tuesday. um. but honestly I can't see any reason why not - there's no indication it breaks anything. it gives us the option to put plymouth back in by default, or we can just not. so, I'm gonna say fine by me.

Pushed.

Thank you for the quick answer during the weekend and enjoy your time off.

p.s. The selinux fix is now available here: https://bodhi.fedoraproject.org/updates/FEDORA-2021-e221a38cfe and I can confirm that that fixes the mentioned selinux issue.

FEDORA-2021-cbe477064d has been pushed to the Fedora 34 stable repository.
If problem still persists, please make note of it in this bug report.

https://pagure.io/fedora-comps/pull-request/642 is a PR to put plymouth back in core now this is (we hope) fixed.

Well, bad news:

https://openqa.fedoraproject.org/tests/874504#step/_console_wait_login/6

still happening. That's from today's Rawhide.

(In reply to Adam Williamson from comment #41)
> Well, bad news:
> 
> https://openqa.fedoraproject.org/tests/874504#step/_console_wait_login/6
> 
> still happening. That's from today's Rawhide.

So looking at the screenshot, this is different from the case which I've fixed. The case which I could reproduce and which I fixed had the entire background set to gray, which is the 3-dot text splash background color.

But on your screenshot the 3 text-dots are also still being shown, suggesting that plymouth either crashes or never quits.

Can you ssh into a test-vm running this test once it has booted (regardless of this happening) and check the journal for plymouth crashing; and also do a "ps aux | grep plymouth" and see if any plymouth processes are still running. I would also like to see the output of "systemctl status plymouth-quit.service"

oh, yes, you're right. I'll try and grab those logs for you today.

https://openqa.fedoraproject.org/tests/877856/file/role_deploy_domain_controller_check-var_log.tar.gz is a /var/log tarball from a run of another test in the same group (that starts out identically) where the bug didn't happen; journal shows no indication of Plymouth crashing that I can see. I'll tweak the test to also upload the other two things you wanted and run it again...

This is what we get from `systemctl status plymouth-quit.service` (first) and `ps aux | grep plymouth` (second) run shortly after boot (this is from a test where the bug didn't happen). Nothing looks out of line. The service exited successfully and there's no plymouth process hanging around.

● plymouth-quit.service - Terminate Plymouth Boot Screen
     Loaded: loaded (/usr/lib/systemd/system/plymouth-quit.service; static)
     Active: active (exited) since Tue 2021-05-04 19:12:02 EDT; 14s ago
    Process: 754 ExecStart=/usr/bin/plymouth quit (code=exited, status=0/SUCCESS)
   Main PID: 754 (code=exited, status=0/SUCCESS)
        CPU: 8ms

May 04 19:12:02 fedora systemd[1]: Starting Terminate Plymouth Boot Screen...
May 04 19:12:02 fedora systemd[1]: Finished Terminate Plymouth Boot Screen.



root         809  0.0  0.0   6132   844 tty1     S+   19:12   0:00 grep --color=auto plymouth

Adam, thank you for the logs. Unfortunately I still have no clue what is going on here.

This is esp. weird because the systemd getty handling will also clear the console itself, as I mentioned earlier to reproduce the problem at all I had to edit /lib/systemd/system/getty@.service and change the following 2 lines:

TTYReset=yes
TTYVTDisallocate=yes

From yes to no.

So for some reason the clearing by systemd also does not seem to happen, maybe because plymouth is hanging and has some level of ownership which systemd tries to honor ?  If plymouth was doing a draw after the systemd-clear then its background should not be gray but black, since plymouth does not reset the palette to its own palette/colors on each draw; and the background of the getty drawn text is black so something has reset the palette to the defaults before getty outputs the login banner.

All in all this is very weird.

Gotcha. I don't think it's happening as often as the previous case; that one from #c41 is I think the only case I've seen so far, actually. I'll try to keep an eye out for it happening again, but the previous case we were seeing it happen several times for each compose tested.

it has happened a few more times :/ here's one from today's Rawhide:

https://openqa.fedoraproject.org/tests/898115#step/_console_wait_login/6