[Bug 1874453] Re: ubuntu/focal64 very slow to boot and reboots once
John Chittum
1874453 at bugs.launchpad.net
Tue Sep 22 19:01:14 UTC 2020
** Description changed:
+ SRU
+
+ [IMPACT]
+
+ * Users are unable to boot a vagrant image, as the boot time without a serial console connection exceeds the vagrant timeout
+ * bug is focal as well as latest devel devel release.
+ * Upload fixes the bug by creating a serial console connection to a null file
+
+ [TEST CASE]
+
+ * run livecd-rootfs from focal branch with vagrant target
+ * download and add the create vagrant box (vagrant box add <PATH TO BOX> --name focal-test-image
+ * vagrant init
+ * update Vagrant file to use focal-test-image as the image
+ * observe that image successfully boots (should boot in < 60s)
+ * vagrant halt
+ * update vagrant file to have a new serial connection and send to a log (this shows that the default NULL connection can be overridden by a local user. an example is in box Vagrantfile, findable in ~/.vagrant.d/boxes/focal-test-image/0/virtualbox/Vagrantfile)
+ * vagrant up and observe that a serial connection has been established, and a log is written
+
+ [Regression Potential]
+
+ * possibility of incorrect configuration, leading to either the serial
+ console not engaging properly, or a file being written instead of sent
+ to a NULL file.
+
+
Using `ubuntu/focal64` version `20200423.0.0`, the boot process is
extremely slow and the box always reboots once before completing a
successful boot. With default settings, this causes a timeout in
Vagrant waiting for SSH to be available. Setting a long enough timeout
it does eventually boot successfully. For comparison, `ubuntu/bionic64`
boots successfully in roughly 10 seconds on my machine.
This appears to be the big hang-up:
Apr 23 14:00:12 ubuntu-focal kernel: [ 0.219784] printk: console [tty1] enabled
Apr 23 14:00:12 ubuntu-focal kernel: [ 76.448371] printk: console [ttyS0] enabled
I have a hard time telling where exactly it reboots because my
/var/log/syslog only ends up with the second boot. I can watch it in
Virtualbox though and it suddenly reboots, then the second boot process
runs to completion. The long delay shown above happens both times
making the total time to a successful boot very long. Here is the head
of my /var/log/syslog:
Apr 23 14:00:12 ubuntu-focal systemd[1]: Finished Remount Root and Kernel File Systems.
Apr 23 14:00:12 ubuntu-focal systemd[1]: Finished Uncomplicated firewall.
Apr 23 14:00:12 ubuntu-focal systemd[1]: Mounting FUSE Control File System...
Apr 23 14:00:12 ubuntu-focal systemd[1]: Mounting Kernel Configuration File System...
Apr 23 14:00:12 ubuntu-focal systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped.
Apr 23 14:00:12 ubuntu-focal systemd[1]: Starting Flush Journal to Persistent Storage...
Apr 23 14:00:12 ubuntu-focal systemd[1]: Condition check resulted in Platform Persistent Storage Archival being skipped.
Apr 23 14:00:12 ubuntu-focal systemd[1]: Starting Load/Save Random Seed...
Apr 23 14:00:12 ubuntu-focal systemd[1]: Starting Apply Kernel Variables...
Apr 23 14:00:12 ubuntu-focal systemd[1]: Starting Create System Users...
Apr 23 14:00:12 ubuntu-focal systemd-sysctl[434]: Not setting net/ipv4/conf/all/promote_secondaries (explicit setting exists).
Apr 23 14:00:12 ubuntu-focal systemd-sysctl[434]: Not setting net/ipv4/conf/default/promote_secondaries (explicit setting exists).
Apr 23 14:00:12 ubuntu-focal systemd[1]: Finished udev Coldplug all Devices.
Apr 23 14:00:12 ubuntu-focal systemd[1]: Mounted FUSE Control File System.
Apr 23 14:00:12 ubuntu-focal systemd[1]: Mounted Kernel Configuration File System.
Apr 23 14:00:12 ubuntu-focal systemd[1]: Finished Flush Journal to Persistent Storage.
Apr 23 14:00:12 ubuntu-focal systemd[1]: Finished Load/Save Random Seed.
Apr 23 14:00:12 ubuntu-focal systemd[1]: Finished Apply Kernel Variables.
Apr 23 14:00:12 ubuntu-focal systemd-sysusers[435]: Creating group systemd-coredump with gid 999.
Apr 23 14:00:12 ubuntu-focal systemd-sysusers[435]: Creating user systemd-coredump (systemd Core Dumper) with uid 999 and gid 999.
Apr 23 14:00:12 ubuntu-focal systemd[1]: Starting udev Wait for Complete Device Initialization...
Apr 23 14:00:12 ubuntu-focal systemd[1]: Finished Create System Users.
Apr 23 14:00:12 ubuntu-focal systemd[1]: Starting Create Static Device Nodes in /dev...
Apr 23 14:00:12 ubuntu-focal systemd[1]: Finished Create Static Device Nodes in /dev.
Apr 23 14:00:12 ubuntu-focal systemd[1]: Starting udev Kernel Device Manager...
Apr 23 14:00:12 ubuntu-focal systemd[1]: Started udev Kernel Device Manager.
Apr 23 14:00:12 ubuntu-focal kernel: [ 0.000000] Linux version 5.4.0-26-generic (buildd at lcy01-amd64-029) (gcc version 9.3.0 (Ubuntu 9.3.0-10ubuntu2)) #30-Ubuntu SMP Mon Apr 20 16:58:30 UTC 2020 (
Ubuntu 5.4.0-26.30-generic 5.4.30)
Apr 23 14:00:12 ubuntu-focal kernel: [ 0.000000] Command line: BOOT_IMAGE=/boot/vmlinuz-5.4.0-26-generic root=PARTUUID=fac6339f-01 ro console=tty1 console=ttyS0
-
Subsequent boots are also slow but don't seem to have the extra reboot.
- ---
+ ---
ProblemType: Bug
AlsaDevices:
- total 0
- crw-rw---- 1 root audio 116, 1 May 7 16:02 seq
- crw-rw---- 1 root audio 116, 33 May 7 16:02 timer
+ total 0
+ crw-rw---- 1 root audio 116, 1 May 7 16:02 seq
+ crw-rw---- 1 root audio 116, 33 May 7 16:02 timer
AplayDevices: Error: [Errno 2] No such file or directory: 'aplay'
ApportVersion: 2.20.11-0ubuntu27
Architecture: amd64
ArecordDevices: Error: [Errno 2] No such file or directory: 'arecord'
AudioDevicesInUse: Error: command ['fuser', '-v', '/dev/snd/seq', '/dev/snd/timer'] failed with exit code 1:
CRDA: N/A
CasperMD5CheckResult: skip
DistroRelease: Ubuntu 20.04
IwConfig: Error: [Errno 2] No such file or directory: 'iwconfig'
Lsusb: Error: command ['lsusb'] failed with exit code 1:
Lsusb-t:
-
+
Lsusb-v: Error: command ['lsusb', '-v'] failed with exit code 1:
MachineType: innotek GmbH VirtualBox
Package: linux (not installed)
ProcEnviron:
- TERM=xterm-256color
- PATH=(custom, no user)
- LANG=C.UTF-8
- SHELL=/bin/bash
+ TERM=xterm-256color
+ PATH=(custom, no user)
+ LANG=C.UTF-8
+ SHELL=/bin/bash
ProcFB: 0 vboxvideodrmfb
ProcKernelCmdLine: BOOT_IMAGE=/boot/vmlinuz-5.4.0-29-generic root=PARTUUID=ff8ca6a0-01 ro console=tty1 console=ttyS0
ProcVersionSignature: Ubuntu 5.4.0-29.33-generic 5.4.30
RelatedPackageVersions:
- linux-restricted-modules-5.4.0-29-generic N/A
- linux-backports-modules-5.4.0-29-generic N/A
- linux-firmware N/A
+ linux-restricted-modules-5.4.0-29-generic N/A
+ linux-backports-modules-5.4.0-29-generic N/A
+ linux-firmware N/A
RfKill: Error: [Errno 2] No such file or directory: 'rfkill'
Tags: focal uec-images
Uname: Linux 5.4.0-29-generic x86_64
UpgradeStatus: No upgrade log present (probably fresh install)
UserGroups:
-
+
_MarkForUpload: True
dmi.bios.date: 12/01/2006
dmi.bios.vendor: innotek GmbH
dmi.bios.version: VirtualBox
dmi.board.name: VirtualBox
dmi.board.vendor: Oracle Corporation
dmi.board.version: 1.2
dmi.chassis.type: 1
dmi.chassis.vendor: Oracle Corporation
dmi.modalias: dmi:bvninnotekGmbH:bvrVirtualBox:bd12/01/2006:svninnotekGmbH:pnVirtualBox:pvr1.2:rvnOracleCorporation:rnVirtualBox:rvr1.2:cvnOracleCorporation:ct1:cvr:
dmi.product.family: Virtual Machine
dmi.product.name: VirtualBox
dmi.product.version: 1.2
dmi.sys.vendor: innotek GmbH
--
You received this bug notification because you are a member of Ubuntu
Foundations Bugs, which is subscribed to livecd-rootfs in Ubuntu.
https://bugs.launchpad.net/bugs/1874453
Title:
ubuntu/focal64 very slow to boot and reboots once
Status in cloud-images:
Fix Released
Status in cloud-images focal series:
Confirmed
Status in cloud-images groovy series:
Fix Released
Status in livecd-rootfs package in Ubuntu:
Fix Released
Bug description:
SRU
[IMPACT]
* Users are unable to boot a vagrant image, as the boot time without a serial console connection exceeds the vagrant timeout
* bug is focal as well as latest devel devel release.
* Upload fixes the bug by creating a serial console connection to a null file
[TEST CASE]
* run livecd-rootfs from focal branch with vagrant target
* download and add the create vagrant box (vagrant box add <PATH TO BOX> --name focal-test-image
* vagrant init
* update Vagrant file to use focal-test-image as the image
* observe that image successfully boots (should boot in < 60s)
* vagrant halt
* update vagrant file to have a new serial connection and send to a log (this shows that the default NULL connection can be overridden by a local user. an example is in box Vagrantfile, findable in ~/.vagrant.d/boxes/focal-test-image/0/virtualbox/Vagrantfile)
* vagrant up and observe that a serial connection has been established, and a log is written
[Regression Potential]
* possibility of incorrect configuration, leading to either the serial
console not engaging properly, or a file being written instead of sent
to a NULL file.
Using `ubuntu/focal64` version `20200423.0.0`, the boot process is
extremely slow and the box always reboots once before completing a
successful boot. With default settings, this causes a timeout in
Vagrant waiting for SSH to be available. Setting a long enough
timeout it does eventually boot successfully. For comparison,
`ubuntu/bionic64` boots successfully in roughly 10 seconds on my
machine.
This appears to be the big hang-up:
Apr 23 14:00:12 ubuntu-focal kernel: [ 0.219784] printk: console [tty1] enabled
Apr 23 14:00:12 ubuntu-focal kernel: [ 76.448371] printk: console [ttyS0] enabled
I have a hard time telling where exactly it reboots because my
/var/log/syslog only ends up with the second boot. I can watch it in
Virtualbox though and it suddenly reboots, then the second boot
process runs to completion. The long delay shown above happens both
times making the total time to a successful boot very long. Here is
the head of my /var/log/syslog:
Apr 23 14:00:12 ubuntu-focal systemd[1]: Finished Remount Root and Kernel File Systems.
Apr 23 14:00:12 ubuntu-focal systemd[1]: Finished Uncomplicated firewall.
Apr 23 14:00:12 ubuntu-focal systemd[1]: Mounting FUSE Control File System...
Apr 23 14:00:12 ubuntu-focal systemd[1]: Mounting Kernel Configuration File System...
Apr 23 14:00:12 ubuntu-focal systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped.
Apr 23 14:00:12 ubuntu-focal systemd[1]: Starting Flush Journal to Persistent Storage...
Apr 23 14:00:12 ubuntu-focal systemd[1]: Condition check resulted in Platform Persistent Storage Archival being skipped.
Apr 23 14:00:12 ubuntu-focal systemd[1]: Starting Load/Save Random Seed...
Apr 23 14:00:12 ubuntu-focal systemd[1]: Starting Apply Kernel Variables...
Apr 23 14:00:12 ubuntu-focal systemd[1]: Starting Create System Users...
Apr 23 14:00:12 ubuntu-focal systemd-sysctl[434]: Not setting net/ipv4/conf/all/promote_secondaries (explicit setting exists).
Apr 23 14:00:12 ubuntu-focal systemd-sysctl[434]: Not setting net/ipv4/conf/default/promote_secondaries (explicit setting exists).
Apr 23 14:00:12 ubuntu-focal systemd[1]: Finished udev Coldplug all Devices.
Apr 23 14:00:12 ubuntu-focal systemd[1]: Mounted FUSE Control File System.
Apr 23 14:00:12 ubuntu-focal systemd[1]: Mounted Kernel Configuration File System.
Apr 23 14:00:12 ubuntu-focal systemd[1]: Finished Flush Journal to Persistent Storage.
Apr 23 14:00:12 ubuntu-focal systemd[1]: Finished Load/Save Random Seed.
Apr 23 14:00:12 ubuntu-focal systemd[1]: Finished Apply Kernel Variables.
Apr 23 14:00:12 ubuntu-focal systemd-sysusers[435]: Creating group systemd-coredump with gid 999.
Apr 23 14:00:12 ubuntu-focal systemd-sysusers[435]: Creating user systemd-coredump (systemd Core Dumper) with uid 999 and gid 999.
Apr 23 14:00:12 ubuntu-focal systemd[1]: Starting udev Wait for Complete Device Initialization...
Apr 23 14:00:12 ubuntu-focal systemd[1]: Finished Create System Users.
Apr 23 14:00:12 ubuntu-focal systemd[1]: Starting Create Static Device Nodes in /dev...
Apr 23 14:00:12 ubuntu-focal systemd[1]: Finished Create Static Device Nodes in /dev.
Apr 23 14:00:12 ubuntu-focal systemd[1]: Starting udev Kernel Device Manager...
Apr 23 14:00:12 ubuntu-focal systemd[1]: Started udev Kernel Device Manager.
Apr 23 14:00:12 ubuntu-focal kernel: [ 0.000000] Linux version 5.4.0-26-generic (buildd at lcy01-amd64-029) (gcc version 9.3.0 (Ubuntu 9.3.0-10ubuntu2)) #30-Ubuntu SMP Mon Apr 20 16:58:30 UTC 2020 (
Ubuntu 5.4.0-26.30-generic 5.4.30)
Apr 23 14:00:12 ubuntu-focal kernel: [ 0.000000] Command line: BOOT_IMAGE=/boot/vmlinuz-5.4.0-26-generic root=PARTUUID=fac6339f-01 ro console=tty1 console=ttyS0
Subsequent boots are also slow but don't seem to have the extra reboot.
---
ProblemType: Bug
AlsaDevices:
total 0
crw-rw---- 1 root audio 116, 1 May 7 16:02 seq
crw-rw---- 1 root audio 116, 33 May 7 16:02 timer
AplayDevices: Error: [Errno 2] No such file or directory: 'aplay'
ApportVersion: 2.20.11-0ubuntu27
Architecture: amd64
ArecordDevices: Error: [Errno 2] No such file or directory: 'arecord'
AudioDevicesInUse: Error: command ['fuser', '-v', '/dev/snd/seq', '/dev/snd/timer'] failed with exit code 1:
CRDA: N/A
CasperMD5CheckResult: skip
DistroRelease: Ubuntu 20.04
IwConfig: Error: [Errno 2] No such file or directory: 'iwconfig'
Lsusb: Error: command ['lsusb'] failed with exit code 1:
Lsusb-t:
Lsusb-v: Error: command ['lsusb', '-v'] failed with exit code 1:
MachineType: innotek GmbH VirtualBox
Package: linux (not installed)
ProcEnviron:
TERM=xterm-256color
PATH=(custom, no user)
LANG=C.UTF-8
SHELL=/bin/bash
ProcFB: 0 vboxvideodrmfb
ProcKernelCmdLine: BOOT_IMAGE=/boot/vmlinuz-5.4.0-29-generic root=PARTUUID=ff8ca6a0-01 ro console=tty1 console=ttyS0
ProcVersionSignature: Ubuntu 5.4.0-29.33-generic 5.4.30
RelatedPackageVersions:
linux-restricted-modules-5.4.0-29-generic N/A
linux-backports-modules-5.4.0-29-generic N/A
linux-firmware N/A
RfKill: Error: [Errno 2] No such file or directory: 'rfkill'
Tags: focal uec-images
Uname: Linux 5.4.0-29-generic x86_64
UpgradeStatus: No upgrade log present (probably fresh install)
UserGroups:
_MarkForUpload: True
dmi.bios.date: 12/01/2006
dmi.bios.vendor: innotek GmbH
dmi.bios.version: VirtualBox
dmi.board.name: VirtualBox
dmi.board.vendor: Oracle Corporation
dmi.board.version: 1.2
dmi.chassis.type: 1
dmi.chassis.vendor: Oracle Corporation
dmi.modalias: dmi:bvninnotekGmbH:bvrVirtualBox:bd12/01/2006:svninnotekGmbH:pnVirtualBox:pvr1.2:rvnOracleCorporation:rnVirtualBox:rvr1.2:cvnOracleCorporation:ct1:cvr:
dmi.product.family: Virtual Machine
dmi.product.name: VirtualBox
dmi.product.version: 1.2
dmi.sys.vendor: innotek GmbH
To manage notifications about this bug go to:
https://bugs.launchpad.net/cloud-images/+bug/1874453/+subscriptions
More information about the foundations-bugs
mailing list