No progress indication for minutes while booting subiquity

Bug #1922392 reported by Patricia Domingues
18
This bug affects 3 people
Affects Status Importance Assigned to Milestone
The Ubuntu-power-systems project
Fix Released
Medium
Ubuntu on IBM Power Systems Bug Triage
Ubuntu on IBM z Systems
Fix Released
Undecided
Skipper Bug Screeners
subiquity
Invalid
Undecided
Unassigned
debian-cd (Ubuntu)
Fix Released
Undecided
Canonical Foundations Team

Bug Description

Installing 21.04 .ISO via Virtual Media on a ppc64le (Power9 - 9006-12C) server has a long time delay without any new messages/logs.
It almost led me to think hirsute was broken on ppc64le.
Also see the same delay installing hirsute on a Power8 (8001-22C).

on the petitboot menu, selecting :
`
 [CD/DVD: sr0 / 2021-04-02-11-08-37-00]
 * Ubuntu Server
`
it shows these logs and during four minutes there's nothing more until subiquity screen appears:

```
Performing kexec load
The system is going down NOW!
Sent SIGTERM to all processes
Sent SIGKILL to all processes
[ 147.420260] kexec_core: Starting new kernel
[ 175.374096319,5] OPAL: Switch to big-endian OS
[ 177.416854069,5] OPAL: Switch to little-endian OS
[ 1.329905] Driver 'hvc_console' was unable to register with bus_type 'vio' because the bus was not initialized.
[ 1.332312] Driver 'tpm_ibmvtpm' was unable to register with bus_type 'vio' because the bus was not initialized.passwd: password expiry information changed.
[ 20.583588] /dev/loop2: Can't open blockdev

Related branches

Revision history for this message
Patricia Domingues (patriciasd) wrote :

attaching installer logs from hostname `dryden` - Power8 (8001-22C)

Revision history for this message
Frank Heimes (fheimes) wrote :

'+1' on this, since I see a similar behavior on s390x system.
It looks like the boot messages / boot log is no longer entirely printed at the console - is that by intention ?!
Especially system with only few resources that require quite some time for booting, will not show any progress for several minutes (like Patricia mentioned) and nervous admins/users may think that the the system (the boot process) hangs.

tags: added: installer ppc64el s390x
Changed in ubuntu-power-systems:
assignee: nobody → Canonical Foundations Team (canonical-foundations)
tags: added: 21.04 hirsute
summary: - four minutes without progress indication
+ No progress indication while booting subiquity four minutes
Revision history for this message
Michael Hudson-Doyle (mwhudson) wrote : Re: No progress indication while booting subiquity four minutes

Yes, we deliberately made the boot process quieter... perhaps we overdid it though!

Revision history for this message
Michael Hudson-Doyle (mwhudson) wrote :

Also, four minutes is really silly long. Can we tell what it's doing? Maybe dmesg has something?

Revision history for this message
Michael Hudson-Doyle (mwhudson) wrote :

Oh it's cloud-init being slow:

2021-04-02 18:52:08,344 DEBUG subiquity.server.server:417 waited 314.8463509082794s for cloud-init\

Can you dig out the cloud-init logs?

Revision history for this message
Frank Heimes (fheimes) wrote :
Download full text (3.2 KiB)

Please see attached the curtin-init log of a s390x installation as z/VM guests.

While re-doing some installs I faced the following situation:

I got the following 3270 console output:

Configuring networking...
QETH device 0.0.0600:0.0.0601:0.0.0602 already configured
IP-Config: enc600 hardware address 02:33:0a:00:00:0b mtu 1500
IP-Config: enc600 guessed broadcast address 10.245.223.255
IP-Config: enc600 complete:
 address: 10.245.208.11 broadcast: 10.245.223.255 netmask: 255.255.240.0

 gateway: 10.245.208.1 dns0 : 10.245.208.1 dns1 : 0.0.0.0

 rootserver: 0.0.0.0 rootpath:
 filename :
Connecting to 10.13.0.2:80 (10.13.0.2:80)
hirsute-live-server- 7% |** | 56.9M 0:00:12 ETA
hirsute-live-server- 21% |****** | 168M 0:00:07 ETA
hirsute-live-server- 35% |*********** | 280M 0:00:05 ETA
hirsute-live-server- 49% |*************** | 392M 0:00:04 ETA
hirsute-live-server- 63% |******************** | 503M 0:00:02 ETA
hirsute-live-server- 77% |************************ | 615M 0:00:01 ETA
hirsute-live-server- 92% |***************************** | 727M 0:00:00 ETA
hirsute-live-server- 100% |********************************| 790M 0:00:00 ETA
passwd: password expiry information changed.
QETH device 0.0.0600:0.0.0601:0.0.0602 already configured
no search or nameservers found in /run/net-enc600.conf /run/net-*.conf /run/net6
-*.conf
Ý 146.652699¨ /dev/loop3: Can't open blockdev
Ý 148.114590¨ systemdÝ1¨: getty.target: Job <email address hidden>/start de
leted to break ordering cycle starting with getty.target/start
Ý Ý0;1;31m SKIP Ý0m¨ Ordering cycle found, skipping Ý0;1;39mSerial Getty on tt
yS0 Ý0m

And the output stopped here, with no further output at this stage!

But the installer responded on ssh:

fheimes@T570:~$ ssh installer@10.245.208.11
The authenticity of host '10.245.208.11 (10.245.208.11)' can't be established.
ECDSA key fingerprint is SHA256:r5mLgWy15/Bgh2TsWJ1kn9TDx8+kfTQgQdBoK3+igPw.
Are you sure you want to continue connecting (yes/no/[fingerprint])? yes
Warning: Permanently added '10.245.208.11' (ECDSA) to the list of known hosts.
installer@10.245.208.11's password:

But no way to get the temp installer password.

With having the _full_ boot log of the starting installation (like we had in the past), there would have been a chance to find the installer password in the output (if not at the end - as usual, maybe a little bit earlier in the logs - from the curtin output), now this chance is gone.

Tbh I don't really see the point on limiting the output of the installer booting, since an installation is done only one time in the live cycle of a (installed and running) system - and many things can go wrong, like problems with hardware devices and drivers, with the network specification (on s390x, casper), network connectivity issues to the archive, no temp. password output (see above), etc.
Therefore I think the output that is provided in the console during boot-up of the installer is the ONLY information one may get (for troubleshootin...

Read more...

Revision history for this message
Frank Heimes (fheimes) wrote :

So with the latest ISO and having the kernel arg 'quiet' removed from the parm file, I get a lot of msgs back (even if I think not all the previous cloud-init output - can't really say yet if these are relevant ...).

For s390x and probably also for ppc64el I vote for changing the default and having it verbose rather than quiet shipped by default.

Revision history for this message
Frank Heimes (fheimes) wrote :

mp for debian-cd submitted to remove 'quiet' as default

Changed in subiquity:
status: New → Invalid
Changed in debian-cd (Ubuntu):
status: New → In Progress
Changed in subiquity:
status: Invalid → New
Changed in ubuntu-z-systems:
status: New → In Progress
Changed in ubuntu-power-systems:
status: New → In Progress
Changed in debian-cd (Ubuntu):
assignee: nobody → Canonical Foundations Team (canonical-foundations)
Changed in ubuntu-power-systems:
assignee: Canonical Foundations Team (canonical-foundations) → Ubuntu on IBM Power Systems Bug Triage (ubuntu-power-triage)
Changed in ubuntu-z-systems:
assignee: nobody → Skipper Bug Screeners (skipper-screen-team)
Revision history for this message
Frank Heimes (fheimes) wrote :
Frank Heimes (fheimes)
summary: - No progress indication while booting subiquity four minutes
+ No progress indication for minutes while booting subiquity
Frank Heimes (fheimes)
Changed in ubuntu-power-systems:
status: In Progress → Fix Released
importance: Undecided → Medium
Frank Heimes (fheimes)
Changed in ubuntu-power-systems:
status: Fix Released → In Progress
Revision history for this message
Frank Heimes (fheimes) wrote :

I recently tested the updated livecd-rootfs that is part of the new live-server image that Łukasz created and put here: http://cdimage.ubuntu.com/ubuntu-server/focal/daily-live/20210805.1/

The tests were fine so far, but I observed that the default kernel arguments (as shipped with the ISO images for booting the installer) are different.
It's "quiet ---" on 21.10, but looks like 20.04 daily has "--- quiet".

I think, if we stay with the arguments that are provided today, the Impish args should be changed to "--- quiet" (since I believe the idea here is that arguments that are specified after '---' are added to the bootloader config of the installed system too (that was the case for d-i, and I think it also applies to subiquity).

---

BUT this ticket is about making the boot-up of the install system (on s390x only) again more 'chatty', so that people who do console based installation, get more messages as feedback, and don't become nervous if no messages are written to the console during boot for up to one or two minutes.
Hence I think especially for s390x we should have "---" as kernel args in file "parmfile.ubuntu".
And that is what the above MP changes:
https://code.launchpad.net/~mwhudson/debian-cd/live-server-cmdline-s390x/+merge/402231
But I didn't saw that changed in the focal daily.

Revision history for this message
Michael Hudson-Doyle (mwhudson) wrote :

OK, the next focal daily should have a better command line.

Changed in debian-cd (Ubuntu):
status: In Progress → Fix Committed
Frank Heimes (fheimes)
Changed in ubuntu-z-systems:
status: In Progress → Fix Committed
Frank Heimes (fheimes)
Changed in subiquity:
status: New → Invalid
Revision history for this message
Frank Heimes (fheimes) wrote :

With the 20.04.3 testing done in the last days this looks good now on focal, too.

Revision history for this message
Frank Heimes (fheimes) wrote :

With the release of 20.04.3 I'm updating the IBM Z entry as Fix Released.

Changed in ubuntu-z-systems:
status: Fix Committed → Fix Released
Changed in debian-cd (Ubuntu):
status: Fix Committed → Fix Released
Changed in ubuntu-power-systems:
status: In Progress → Fix Committed
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.