Bugzilla – Bug 1218618
systemd-vconsole-setup[827]: No usable source console found: Device or resource busy
Last modified: 2024-02-27 11:35:04 UTC
Hello, with the last update on Tumbleweed we've noticed the following issue after rebooting the server # systemctl is-system-running degraded # systemctl ● systemd-vconsole-setup.service loaded failed failed Virtual Console Setup # systemctl status systemd-vconsole-setup.service × systemd-vconsole-setup.service - Virtual Console Setup Loaded: loaded (/usr/lib/systemd/system/systemd-vconsole-setup.service; static) Active: failed (Result: exit-code) since Mon 2024-01-08 12:02:41 CET; 5min ago Duration: 9.112s Docs: man:systemd-vconsole-setup.service(8) man:vconsole.conf(5) Process: 827 ExecStart=/usr/lib/systemd/systemd-vconsole-setup (code=exited, status=1/FAILURE) Main PID: 827 (code=exited, status=1/FAILURE) CPU: 10ms Jan 08 12:02:41 tumbleweed systemd[1]: Starting Virtual Console Setup... Jan 08 12:02:41 tumbleweed systemd-vconsole-setup[827]: No usable source console found: Device or resource busy Jan 08 12:02:41 tumbleweed systemd[1]: systemd-vconsole-setup.service: Main process exited, code=exited, status=1/FAILURE Jan 08 12:02:41 tumbleweed systemd[1]: systemd-vconsole-setup.service: Failed with result 'exit-code'. Jan 08 12:02:41 tumbleweed systemd[1]: Failed to start Virtual Console Setup. a journalctl for the service did not provide useful details but a strace in the service file showed 824 access("/dev/vcs2", F_OK) = -1 ENOENT (No such file or directory) 824 access("/dev/vcs3", F_OK) = -1 ENOENT (No such file or directory) ... The service can be started manually because from the active session we can see # ls -l /dev/vcs* crw-rw---- 1 root tty 7, 0 Jan 8 12:18 /dev/vcs crw-rw---- 1 root tty 7, 1 Jan 8 12:18 /dev/vcs1 crw-rw---- 1 root tty 7, 2 Jan 8 12:18 /dev/vcs2 crw-rw---- 1 root tty 7, 3 Jan 8 12:18 /dev/vcs3 ... # systemctl list-dependencies systemd-vconsole-setup.service systemd-vconsole-setup.service ● ├─kbdsettings.service ● └─system.slice Would you please check and fix the issue. Kind regards Michael
Not the latest snapshot, but 20231221 has a related change for bug 1215282 https://build.opensuse.org/request/show/1134212 https://lists.opensuse.org/archives/list/factory@lists.opensuse.org/thread/NTKA4GBSLTG2GCFXWX3KESBJFSBARJZD/ ==== systemd ==== Subpackages: libsystemd0 libsystemd0-32bit libudev1 systemd-32bit systemd-boot systemd-container systemd-coredump systemd-lang udev - udev: only require kmod in the full flavor. udev-mini is only used inside OBS in a strictly defined setup and udev will never have to load device drivers there. - Import commit 071ac409a0564863657d8f8a5a35e6a4f914695f 071ac409a0 rules: set up tty permissions and group for /dev/hvc* nodes f693b3ed8a vconsole-setup: remember the correct error value when open_terminal() fails 963d838bad vconsole-setup: handle the case where the vc is in KD_GRAPHICS mode more gracefully (bsc#1215282) 6f53f71d2d vconsole-setup: simplify error handling
https://lists.opensuse.org/archives/list/factory@lists.opensuse.org/thread/QYOMXCP4YT2JXL424I3IQVGZWL3BYDLQ/
*** Bug 1218623 has been marked as a duplicate of this bug. ***
Workaround note from bug 1218623 > /usr/lib/systemd/system/plymouth-start.service > > 1) change "KillMode" from none to "mixed", > 2) add "IgnoreOnIsolate=true" to the "[Unit]" section, and > 3) run "dracut -f".
I see that Fedora (Rawhide) and Arch (Extra-Testing) have picked up Plymouth 24.004.60. Should that make it's way into Tumbleweed soon, I would be happy to help test. BTW, this is outside my area of expertise and new to openSUSE (I'm a longtime Debian user who flirted with RHEL and Fedora), but I am happy to learn (asking for patience).
Could anyone please provide the debug logs when the error is occuring ?
Created attachment 871726 [details] journal excerpt from my system Not exactly what you asked for I guess, but perhaps helpful nonetheless: You can see that systemd-vconsole-setup.service is started 7 times and stopped 4 times during a single boot. The first start (in initrd) seems to work. [ 1.218872] apollon systemd[1]: Starting Virtual Console Setup... [ 1.355556] apollon systemd[1]: Finished Virtual Console Setup. IMHO, this should be perfectly sufficient for setting up the VC, and no additional invocations of this unit would be necessary, neither in initramfs nor afterwards. Is that wrong? After that, plymouth starts, and we see various stop messages [ 2.370086] apollon systemd[1]: systemd-vconsole-setup.service: Deactivated successfully. [ 2.374073] apollon systemd[1]: Stopped Virtual Console Setup. [ 2.374364] apollon systemd[1]: Stopping Virtual Console Setup... [ 2.404866] apollon systemd[1]: Starting Virtual Console Setup... Then this: [ 2.681190] apollon systemd[1]: /usr/lib/systemd/system/plymouth-start.service:15: Unit uses KillMode=none. This is unsafe, ... I am assuming this is because plymouth wants to persist over the switch root step. Not sure if systemd nowadays provides cleaner methods to achieve this. systemd-vconsole-setup.service is started once more, and fails now: [ 4.340640] apollon systemd[1]: Starting Virtual Console Setup... [ 4.749467] apollon systemd-vconsole-setup[588]: KD_FONT_OP_GET failed while trying to get the font metadata: Invalid argument [ 4.749841] apollon systemd-vconsole-setup[588]: Fonts will not be copied to remaining consoles [ 4.750962] apollon systemd[1]: Finished Virtual Console Setup. System switches root, and we see the surviving plymouthd: [ 6.220795] apollon systemd[1]: Switching root. [ 7.333967] apollon systemd[1]: plymouth-start.service: Unit process 402 (plymouthd) remains running after unit stopped. [ 7.354857] apollon systemd[1]: Stopped Show Plymouth Boot Screen. [ 7.355152] apollon systemd[1]: Dispatch Password Requests to Console Directory Watch was skipped because of an unmet condition check (ConditionPathExists=!/run/plymouth/pid). More vconsole weirdness: [ 10.449820] apollon systemd[1]: systemd-vconsole-setup.service: Deactivated successfully. [ 10.521052] apollon systemd[1]: Stopped Virtual Console Setup. [ 10.521179] apollon systemd[1]: Stopping Virtual Console Setup... [ 10.531692] apollon systemd[1]: Starting Virtual Console Setup... [ 10.542832] apollon systemd-vconsole-setup[972]: No usable source console found: Device or resource busy [ 10.609910] apollon systemd[1]: systemd-vconsole-setup.service: Main process exited, code=exited, status=1/FAILURE [ 10.610049] apollon systemd[1]: systemd-vconsole-setup.service: Failed with result 'exit-code'. [ 10.662732] apollon systemd[1]: Failed to start Virtual Console Setup. This is the actual error reported here; my guess is that it happens because the surviving plymouth process with PID 402 has the console grabbed. This pattern repeats until plymouth finally exits. [ 52.646923] apollon systemd[1]: Finished Hold until boot process finishes up. I started systemd-vconsole-setup.service manually, and now it succeeds, just like the first time: [93288.606387] apollon systemd[1]: Starting Virtual Console Setup... [93288.846104] apollon systemd[1]: Finished Virtual Console Setup.
Created attachment 871728 [details] system log
Created attachment 871729 [details] plymouth-debug
Created attachment 871730 [details] plymouth-shutdown-debug
Sorry for the delay. I have attached the system log (edited) and the Plymouth debug logs. Again, I'm happy to learn and help.
(In reply to Tony Walker from comment #11) > Sorry for the delay. I have attached the system log (edited) and the > Plymouth debug logs. Again, I'm happy to learn and help. Sorry for the delay too and thanks for the log. Unfortunately the way the logs are formatted is hard to read. Could you please provide the same debug logs but with the format obtained with "-oshort-monotonic" switch. IOW run `journalctl -b -oshort-monotonic" and attach the output. Thanks.
Created attachment 872108 [details] 2024-01-23-syslog
The problem seems to have also reached SLES 15 SP6 with the recent update to udev-254.5-150600.2.8 (Snapshot-202401-1).
(In reply to Tony Walker from comment #13) > Created attachment 872108 [details] > 2024-01-23-syslog Unfortunately the debug logs were left disabled. Can you please do it again after appending "debug" to the kernel command line ?
I found something suspicious in the debug logs on my workstation; systemd finds some conflicts in the (arguably weird) plymouth startup logic: [ 52.000281] apollon systemd[1]: Switching root. [ 53.646897] apollon systemd[1]: plymouth-quit.service: Looking at job plymouth-quit.service/stop conflicted_by=yes [ 53.646943] apollon systemd[1]: plymouth-quit.service: Looking at job plymouth-quit.service/start conflicted_by=no [ 53.646978] apollon systemd[1]: plymouth-quit.service: Fixing conflicting jobs plymouth-quit.service/stop,plymouth-quit.service/star t by deleting job plymouth-quit.service/start [ 53.647014] apollon systemd[1]: plymouth-start.service: Looking at job plymouth-start.service/stop conflicted_by=yes [ 53.647048] apollon systemd[1]: plymouth-start.service: Looking at job plymouth-start.service/start conflicted_by=no [ 53.647081] apollon systemd[1]: plymouth-start.service: Fixing conflicting jobs plymouth-start.service/stop,plymouth-start.service/s tart by deleting job plymouth-start.service/start
Created attachment 872316 [details] 2024-01-30 debug log (Tony)
Like Martin, I see a few interesting journal entries... I see some entries where the log source is mangled as if there is a pointer arithmetic error or memory corruption somewhere in systemd, for example: => Jan 30 10:40:37 **REDACTED** (les-[317]: systemd-modules-load.service: Executing: /usr/lib/systemd/systemd-modules-load => Jan 30 10:40:37 **REDACTED** (le-s[318]: systemd-vconsole-setup.service: Executing: /usr/lib/systemd/systemd-vconsole-setup I have grepped my journal entries without the debug kernel parameter and found no entries like the above, so I can't say if this is really a bug or even related to the bug report at hand. The logs also remind me that I am using: 1) SELinux, 2) SDDM/Plasma, and 3) TPM2 to unlock my disk. I doubt any of these matter, but...full disclosure. I don't know enough to know if these entries are significant: => Jan 30 10:40:39 **REDACTED** systemd[1]: run-credentials-systemd\x2dvconsole\x2dsetup.service.mount: Failed to load configuration: No such file or directory => Jan 30 10:40:39 **REDACTED** systemd[1]: var.mount: Failed to load configuration: No such file or directory => Jan 30 10:40:39 **REDACTED** systemd[1]: var-tmp.mount: Failed to load configuration: No such file or directory => Jan 30 10:40:39 **REDACTED** systemd[1]: tmp.mount: Failed to load configuration: No such file or directory I will say that I created subvolumes for several directories (e.g., /var/tmp). There is this entry, which has been reported elsewhere: => Jan 30 10:40:39 **REDACTED** systemd[1]: /usr/lib/systemd/system/plymouth-start.service:15: Unit uses KillMode=none. This is unsafe, as it disables systemd's process lifecycle management for the service. Please update the service to use a safer KillMode=, such as 'mixed' or 'control-group'. Support for KillMode=none is deprecated and will eventually be removed. Then, the first real sign of a problem is: => Jan 30 10:40:46 **REDACTED** systemd[1]: Starting Load Kernel Module efi_pstore... => Jan 30 10:40:46 **REDACTED** systemd[1]: plymouth-read-write.service: ConditionPathExists=!/etc/initrd-release succeeded. => Jan 30 10:40:46 **REDACTED** systemd[1]: plymouth-read-write.service: Will spawn child (service_enter_start): /usr/bin/plymouth => Jan 30 10:40:46 **REDACTED** (modprobe)[1093]: Found cgroup2 on /sys/fs/cgroup/, full unified hierarchy => Jan 30 10:40:46 **REDACTED** (modprobe)[1093]: modprobe@efi_pstore.service: Executing: /sbin/modprobe -abq efi_pstore => ... => Jan 30 10:40:46 **REDACTED** systemd[1]: plymouth-read-write.service: Passing 0 fds to service => Jan 30 10:40:46 **REDACTED** systemd[1]: plymouth-read-write.service: About to execute: /usr/bin/plymouth update-root-fs --read-write => ... => Jan 30 10:40:46 **REDACTED** systemd-vconsole-setup[1086]: Failed to check VC /dev/tty1 display mode: Device or resource busy => Jan 30 10:40:46 **REDACTED** systemd-vconsole-setup[1086]: VC 2 existance check failed, skipping: No such file or directory => ... => Jan 30 10:40:46 **REDACTED** systemd[1]: plymouth-read-write.service: Forked /usr/bin/plymouth as 1094 => ... => Jan 30 10:40:46 **REDACTED** systemd[1]: plymouth-read-write.service: Changed dead -> start => Jan 30 10:40:46 **REDACTED** systemd[1]: Starting Tell Plymouth To Write Out Runtime Data... => ... => Jan 30 10:40:46 **REDACTED** systemd[1]: plymouth-start.service: starting held back, waiting for: systemd-vconsole-setup.service There are several attempts to start systemd-vconsole-setup.service, but it will not start once marked as failed. That is, I (and my logs) agree with Martin. What is curious is the Plymouth forks and then waits for systemd-vconsole-setup.service, but systemd-vconsole-setup.service is marked as failed because seems to still won the console. BTW, my understanding is that systemd-vconsole-setup.service is used anytime there is an attempt to configure the console (e.g., for keymaps and fonts). That seems like a perfectly reasonable thing for Plymouth to do, BUT it appears to be competing with systemd-vconsole-setup.service. Fedora applies a few patches to their Plymouth packages, but I can't tell if any of them are relevant. I did not look at the Tumbleweed packages. To see if there is a difference. I wish I could be more helpful.
From your logs, it seems that systemd-vconsole-setup can find /dev/tty1, the only allocated console (dev/vcs2+ don't exist yet), but it's already taken by plymouth, which has set it to graphic mode: > Jan 30 10:40:46 **REDACTED** systemd-vconsole-setup[1086]: Failed to check VC /dev/tty1 display mode: Device or resource busy > Jan 30 10:40:46 **REDACTED** systemd-vconsole-setup[1086]: VC 2 existance check failed, skipping: No such file or directory > Jan 30 10:40:46 **REDACTED** systemd-vconsole-setup[1086]: VC 3 existance check failed, skipping: No such file or directory > ... > Jan 30 10:40:46 **REDACTED** systemd-vconsole-setup[1086]: VC 63 existance check failed, skipping: No such file or directory In this situation systemd-vconsole-setup complains that it can't find any other free source console to setup and fails. Note that a bunch of VCs is pre-allocated by logind hence if systemd-vconsole-setup is run again after logind is activated (but tty1 is still busy), s-v-s will be happy this time to find a VC (tty2 for example) to configure. On my setup, the problem doesn't occur because when systemd-vconsole-setup is launched, after switching root and plymouth was started again, the boot process is fast enough (or plymouth slow enough) to make plymouth not show the boot splash at all. And in this case s-v-s finds tty1 in text mode. Anyway I think that in this specific case s-v-s should not return a failure when it's asked to configure any potential free tty it may find but all allocated ttys are already busy, just logging a message should be fine. I'll send a patch to upstream that does that.
Since your PR 31156 [1] still seems to be in discussion, I would like to mention that currently all our automated tests fail on those versions affected since the systems start in 'degraded' mode. [1] https://github.com/systemd/systemd/pull/31156
(In reply to Alexander Hass from comment #21) > Since your PR 31156 [1] still seems to be in discussion, I would like to > mention that currently all our automated tests fail on those versions > affected since the systems start in 'degraded' mode. Which versions exactly are you seeing this issue ? I'm asking because this report is against TW however I'm not sure that all your tests are running on this version.
We see this in Tumbleweed and since Snapshot-202401-1 also in SLES 15 SP6 (comment #14), which is of course even more critical than Tumbleweed.
Let's change the components to SP6 then.
This is an autogenerated message for OBS integration: This bug (1218618) was mentioned in https://build.opensuse.org/request/show/1147539 Factory / systemd
Since this was an openSUSE report, changing to Public SLES - so that it's open.
The fix has been submitted and will be released hopefully shortly hence I'm closing the bug. Feel free to reopen if you still face it with the update containing the fix. `rpm -q --changelog systemd | grep 1218618` should tell you whether the version of systemd installed on your system has the fix or not.
Thank you, the fix has reached Tumbleweed already. Still waiting for SLES 15 SP6.
A SR mentioning this bug was successfully integrated into Build 58.1. Please, if needed, set it to RESOLVED FIXED for QE to verify it.
This is an autogenerated message for OBS integration: This bug (1218618) was mentioned in https://build.opensuse.org/request/show/1152118 Factory / systemd