Bug 1801272 - systemd-vconsole-setup having problem to start in the installation environment
Summary: systemd-vconsole-setup having problem to start in the installation environment
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: kbd
Version: 32
Hardware: Unspecified
OS: Linux
unspecified
urgent
Target Milestone: ---
Assignee: Vitezslav Crhonek
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks: F32BetaBlocker
TreeView+ depends on / blocked
 
Reported: 2020-02-10 14:32 UTC by Jiri Konecny
Modified: 2020-02-24 12:29 UTC (History)
12 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Regression
Last Closed: 2020-02-22 23:25:06 UTC
Type: Bug


Attachments (Terms of Use)
journal.log (5.03 MB, text/plain)
2020-02-10 14:49 UTC, Jiri Konecny
no flags Details

Description Jiri Konecny 2020-02-10 14:32:58 UTC
Description of problem:

When running installation with inst.text on Rawhide the input is not taken all the time and when pressing up-arrow I'll get Plymouth screen.

When I look to journal in the installation I'll find out plenty lines like this:

Feb 10 14:01:24 jk_test systemd-vconsole-setup[1690]: Input/output error

And also these:

Feb 10 14:01:24 jk_test systemd-vconsole-setup[1672]: /usr/bin/loadkeys failed with exit status 1.
Feb 10 14:01:24 jk_test systemd-vconsole-setup[1690]: Input/output error 
Feb 10 14:01:24 jk_test systemd-vconsole-setup[1690]: KDSKBENT: Input/output error: could not deallocate keymap 128
Feb 10 14:01:24 jk_test systemd-vconsole-setup[1672]: KD_FONT_OP_GET failed while trying to get the font metadata: Input/output error
Feb 10 14:01:24 jk_test systemd-vconsole-setup[1672]: Fonts will not be copied to remaining consoles
Feb 10 14:01:24 jk_test systemd[1]: systemd-vconsole-setup.service: Main process exited, code=exited, status=1/FAILURE
Feb 10 14:01:24 jk_test systemd[1]: systemd-vconsole-setup.service: Failed with result 'exit-code'.
Feb 10 14:01:24 jk_test systemd[1]: Failed to start Setup Virtual Console.


Version-Release number of selected component (if applicable):
systemd-245~rc1-1.fc32.x86_64
systemd-libs-245~rc1-1.fc32.x86_64

How reproducible:
Always (at least in x86_64 VM)

Steps to Reproduce:
1. Download newest Rawhide boot.iso
2. Add inst.text to the kernel command line
3. Try to type something

Actual results:
Not all characters are echoed in the console.
Up-arrow will switch to Plymouth screen.

Expected results:
Typed characters should echoed as usually.

Additional info:
Not sure if this is problem in Plymouth which is starting console or because of the  systemd-vconsole-setup.service unit. However, there is no change in the Anaconda configuration or systemd units we provide there.

When I started to type more and more then a few services failed with error:
Start request repeated too quickly.
Failed with result 'start-limit-hit'.

Services failed this way were at least:
Setup Virtual Console
Plymouth
DMRaid
Anaconda Text Console

Comment 1 Jiri Konecny 2020-02-10 14:49:23 UTC
Created attachment 1662160 [details]
journal.log

Comment 2 Jiri Konecny 2020-02-11 10:24:05 UTC
From the systemd I've got a recommendation to switch this to component who owns the binary which is failing.

Switching to kdb for further triaging.

Comment 3 Fedora Blocker Bugs Application 2020-02-11 15:51:44 UTC
Proposed as a Blocker for 32-beta by Fedora user jkonecny using the blocker tracking app because:

 When using a dedicated installer image, the installer must be able to complete an installation using the text, graphical and VNC installation interfaces.

Comment 4 Ben Cotton 2020-02-11 16:30:25 UTC
This bug appears to have been reported against 'rawhide' during the Fedora 32 development cycle.
Changing version to 32.

Comment 5 Adam Williamson 2020-02-12 18:24:53 UTC
Can you check if this is actually kernel related? I'm seeing something similar (bootsplash showing when it shouldn't and weirdness with keypresses) on tty1 in an installed Rawhide VM, and I think it may be happening only with kernel 5.6...can you try it with a 5.5 kernel?

Comment 6 Adam Williamson 2020-02-12 19:04:32 UTC
Well...the Plymouth thing and the kbd issue may be unrelated. But it seems to me that for the Plymouth thing, what happens is that on boot, plymouth-start.service runs, then plymouth-quit.service runs, then plymouth-start.service runs *again*. I'm not sure what's triggering that second run of plymouth-start.service exactly, but it does happen right after one of *five* runs of systemd-vconsole-setup.service.

Comment 7 Jiri Konecny 2020-02-14 13:28:50 UTC
I would be glad to test it but creating boot.iso with the old kernel is a realy pain :(.

Just in case Adam, don't you have such boot.iso somewhere?

Comment 8 Adam Williamson 2020-02-15 02:12:28 UTC
I have some older ISOs around, but not one with current other packages and an older kernel, no :/ I could probably hack one up for you, though.

I filed https://bugzilla.redhat.com/show_bug.cgi?id=1803293 for the plymouth issue.

Comment 9 Adam Williamson 2020-02-15 02:21:32 UTC
heh, there was a typo in the package - 'kdb' is a KDE thing, we want 'kbd' :)

Comment 10 Vitezslav Crhonek 2020-02-17 13:18:50 UTC
I'm not able to reproduce the error ('KDSKBENT: Input/output error: could not deallocate keymap 128' caused by running '/usr/bin/loadkeys -q -C /dev/tty1 -u us') on x86_64 f32 VM (upgraded from 31). loadkeys seems to work as expected.

$ rpm -q kbd
kbd-2.2.0-1.fc32.x86_64

Jirko, could you please run loadkeys/setfont manually in the VC after the system startup? Do the commands work?

I think I've seen this issue in the past already... see discussion at:
https://github.com/systemd/systemd/issues/6689
https://github.com/systemd/systemd/issues/10019
https://bugzilla.opensuse.org/show_bug.cgi?id=1055834

Comment 11 Geoffrey Marr 2020-02-17 19:35:17 UTC
Discussed during the 2020-02-17 blocker review meeting: [0]

The decision to delay the classification of this as a blocker bug was made as if this is indeed preventing text installs from working it will definitely be a blocker, but we're just not 100% sure of that at this time, so we are punting so a few people can try it and confirm whether that's the case.

[0] https://meetbot.fedoraproject.org/fedora-blocker-review/2020-02-17/f32-blocker-review.2020-02-17-17.02.txt

Comment 12 Chris Murphy 2020-02-17 23:53:42 UTC
Bug 1408878 may be a dup.

Comment 13 Vitezslav Crhonek 2020-02-18 07:24:12 UTC
(In reply to Chris Murphy from comment #12)
> Bug 1408878 may be a dup.

I don't think so.
In bug #1408878 kbd is not installed at all and thus systemd-vconsole-setup calls binaries that are not available (setfont, loadkeys).
Here we have kbd installed, but it's unable to do its work.

Comment 14 Jiri Konecny 2020-02-18 10:46:23 UTC
(In reply to Vitezslav Crhonek from comment #10)
> I'm not able to reproduce the error ('KDSKBENT: Input/output error: could
> not deallocate keymap 128' caused by running '/usr/bin/loadkeys -q -C
> /dev/tty1 -u us') on x86_64 f32 VM (upgraded from 31). loadkeys seems to
> work as expected.
> 
> $ rpm -q kbd
> kbd-2.2.0-1.fc32.x86_64
> 
> Jirko, could you please run loadkeys/setfont manually in the VC after the
> system startup? Do the commands work?
> 
> I think I've seen this issue in the past already... see discussion at:
> https://github.com/systemd/systemd/issues/6689
> https://github.com/systemd/systemd/issues/10019
> https://bugzilla.opensuse.org/show_bug.cgi?id=1055834

Unfortunately, I can't really run any commands in the tty1. Half of the input is "stolen" so I can't even switch to next tmux pane :(. On other tty or ssh session this seems to be working correctly or I guess it is because loadkeys will just keep running, not sure what should be the correct output.


So or so, I'm not really sure if this is the correct component. In my check now, it seems that only failing service is anaconda-tmux@tty1.service. However, I don't think this is the root cause really.

Any idea what could be the correct component here? Maybe the bug 1803293 is the problem here?

Comment 15 Adam Williamson 2020-02-18 18:08:51 UTC
So yeah, after digging into https://bugzilla.redhat.com/show_bug.cgi?id=1803293 some more today, I suspect this and that really *are* the same bug. But I'll keep them separate for now just in case. If they are the same, systemd-245~rc1-3.fc32 and systemd-245~rc1-3.fc33 should fix this too: they should be in the next F32 and Rawhide composes, so please let me know.

Comment 16 Adam Williamson 2020-02-21 19:10:22 UTC
Jiri, can you check if this is fixed in current composes? I believe it should be.

Comment 17 Chris Murphy 2020-02-21 20:13:05 UTC
I still see a lot of confusion in the journal...

Feb 21 13:08:55 localhost.localdomain systemd[1]: systemd-vconsole-setup.service: Succeeded.
Feb 21 13:08:56 localhost.localdomain systemd[1]: systemd-vconsole-setup.service: Succeeded.
Feb 21 13:08:58 vm.local systemd[1]: systemd-vconsole-setup.service: Succeeded.
Feb 21 13:08:59 vm.local systemd[1]: systemd-vconsole-setup.service: Succeeded.
Feb 21 13:08:59 vm.local systemd[1]: systemd-vconsole-setup.service: Succeeded.
Feb 21 13:09:01 vm.local systemd[1]: systemd-vconsole-setup.service: Succeeded.
Feb 21 13:09:01 vm.local systemd[1]: systemd-vconsole-setup.service: Succeeded.
Feb 21 13:09:02 vm.local systemd[1]: systemd-vconsole-setup.service: Start request repeated too quickly.
Feb 21 13:09:02 vm.local systemd[1]: systemd-vconsole-setup.service: Failed with result 'start-limit-hit'.
Feb 21 13:09:04 vm.local systemd[1]: systemd-vconsole-setup.service: Start request repeated too quickly.
Feb 21 13:09:04 vm.local systemd[1]: systemd-vconsole-setup.service: Failed with result 'start-limit-hit'.
Feb 21 13:09:05 vm.local systemd[1]: systemd-vconsole-setup.service: Start request repeated too quickly.
Feb 21 13:09:05 vm.local systemd[1]: systemd-vconsole-setup.service: Failed with result 'start-limit-hit'.
Feb 21 13:09:05 vm.local systemd[1]: systemd-vconsole-setup.service: Start request repeated too quickly.
Feb 21 13:09:05 vm.local systemd[1]: systemd-vconsole-setup.service: Failed with result 'start-limit-hit'.
Feb 21 13:09:06 vm.local systemd[1]: systemd-vconsole-setup.service: Start request repeated too quickly.
Feb 21 13:09:06 vm.local systemd[1]: systemd-vconsole-setup.service: Failed with result 'start-limit-hit'.
Feb 21 13:09:20 vm.local systemd[1]: systemd-vconsole-setup.service: Succeeded.

But ultimately it succeeds, I guess?

    Process: 1352 ExecStart=/usr/lib/systemd/systemd-vconsole-setup (code=exited, status=0/SUCCESS)
   Main PID: 1352 (code=exited, status=0/SUCCESS)
        CPU: 69ms

Comment 18 Chris Murphy 2020-02-21 20:23:02 UTC
OK, nevermind, I wasn't paying attention. Helps to update to systemd-245~rc1-3.fc32.x86_64 before testing...

$ journalctl -b | grep vconsole
Feb 21 13:20:05 localhost.localdomain systemd[1]: systemd-vconsole-setup.service: Succeeded.
Feb 21 13:20:06 localhost.localdomain systemd-vconsole-setup[427]: KD_FONT_OP_GET failed while trying to get the font metadata: Function not implemented
Feb 21 13:20:06 localhost.localdomain systemd-vconsole-setup[427]: Fonts will not be copied to remaining consoles
Feb 21 13:20:06 localhost.localdomain systemd[1]: systemd-vconsole-setup.service: Succeeded.
Feb 21 13:20:06 localhost.localdomain audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-vconsole-setup comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Feb 21 13:20:06 localhost.localdomain audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-vconsole-setup comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Feb 21 13:20:07 vm.local systemd[1]: systemd-vconsole-setup.service: Succeeded.
Feb 21 13:20:07 vm.local audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-vconsole-setup comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Feb 21 13:20:07 vm.local audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-vconsole-setup comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'

Comment 19 Adam Williamson 2020-02-22 23:25:06 UTC
ok, so let's figure this is fixed. jkonecny, please reopen if you still have issues.

Comment 20 Jiri Konecny 2020-02-24 12:29:29 UTC
Works great now. Thanks for handling this everyone!


Note You need to log in before you can comment on or make changes to this bug.