Public bug reported:
Booting some Bionic instances in Azure (gen1 machines), I see some large
delays during kernel/userspace boot that it would be good to understand
what's going on. Additionally, there areas during boot that see delays
is different for an image that's been created from a template vs. stock
images.
I'm attaching some data, 10 runs of the same image in a scaling set that
run the initial boot. Processing the journal output, looking at delays
of over 2.0 shows some concern.
[ 1.788581] localhost.localdomain kernel: * Found PM-Timer Bug on the
chipset. Due to workarounds for a bug,
* this clock source is slow.
Consider trying other clock sources
[ 3.545974] localhost.localdomain kernel: Unstable clock detected, switching
default tracing clock to "global"
If you want to keep using the
local clock, then add:
"trace_clock=local"
on the kernel command line
[ 6.401684] localhost.localdomain kernel: EXT4-fs (sda1): mounted filesystem
with ordered data mode. Opts: (null)
[ 15.280390] localhost.localdomain kernel: EXT4-fs (sda1): re-mounted. Opts:
discard
After capturing bionic image as a template, and creating a new VM, we see new
hot spots we didn't see before.
# HotSpot maximum delta between kernel messages: 2.00000
# [ 2.846188] localhost.localdomain kernel: AES CTR mode by8 optimization
enabled
# [ 5.919313] localhost.localdomain kernel: raid6: avx2x4 gen() 21512 MB/s
#
# [ 6.591530] localhost.localdomain kernel: EXT4-fs (sda1): mounted
filesystem with ordered data mode. Opts: (null)
# [ 9.031051] localhost.localdomain systemd[1]: systemd 237 running in
system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP
+LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD
-IDN2 +IDN -PCRE2 default-hierarchy=hybrid)
#
# [ 13.773554] localhost.localdomain sh[871]: + exit 0
# [ 21.625467] localhost.localdomain kernel: UDF-fs: INFO Mounting volume
'UDF Volume', timestamp 2019/12/17 00:00 (1000)
#
# [ 24.919359] bugbif2be000001 systemd-timesyncd[771]: Synchronized to time
server 91.189.89.198:123 (ntp.ubuntu.com).
# [ 29.787339] bugbif2be000001 cloud-init[1026]: Cloud-init v.
19.2-36-g059d049c-0ubuntu2~18.04.1 running 'init' at Mon, 16 Dec 2019 18:14:47
+0000. Up 25.20 seconds.
The easiest comparison kernel-side is the systemd-analyze value:
Grepping in the debug data:
% grep "Startup finished.*kernel" bug-bionic-baseline-no*.debug/*/journal.log |
cut -d" " -f 7-
Startup finished in 3.209s (kernel) + 49.305s (userspace) = 52.515s.
Startup finished in 3.355s (kernel) + 51.732s (userspace) = 55.088s.
Startup finished in 3.287s (kernel) + 51.747s (userspace) = 55.035s.
Startup finished in 3.129s (kernel) + 50.066s (userspace) = 53.195s.
Startup finished in 3.350s (kernel) + 50.682s (userspace) = 54.032s.
Startup finished in 3.355s (kernel) + 49.322s (userspace) = 52.678s.
Startup finished in 3.219s (kernel) + 51.124s (userspace) = 54.343s.
Startup finished in 3.128s (kernel) + 49.226s (userspace) = 52.354s.
Startup finished in 3.193s (kernel) + 53.197s (userspace) = 56.390s.
Startup finished in 3.118s (kernel) + 46.203s (userspace) = 49.322s.
foofoo % grep "Startup finished.*kernel"
bug-bionic-baseline-after*.debug/*/journal.log | cut -d" " -f 7-
Startup finished in 7.685s (kernel) + 32.463s (userspace) = 40.148s.
Startup finished in 7.041s (kernel) + 35.998s (userspace) = 43.040s.
Startup finished in 7.808s (kernel) + 35.444s (userspace) = 43.253s.
Startup finished in 7.206s (kernel) + 37.952s (userspace) = 45.159s.
Startup finished in 8.426s (kernel) + 36.976s (userspace) = 45.403s.
Startup finished in 6.731s (kernel) + 35.484s (userspace) = 42.216s.
Startup finished in 7.152s (kernel) + 32.664s (userspace) = 39.817s.
Startup finished in 7.429s (kernel) + 36.177s (userspace) = 43.606s.
Startup finished in 9.075s (kernel) + 32.494s (userspace) = 41.570s.
Startup finished in 7.281s (kernel) + 32.732s (userspace) = 40.013s.
ProblemType: Bug
DistroRelease: Ubuntu 18.04
Package: linux-image-5.0.0-1027-azure 5.0.0-1027.29~18.04.1
ProcVersionSignature: User Name 5.0.0-1027.29~18.04.1-azure 5.0.21
Uname: Linux 5.0.0-1027-azure x86_64
ApportVersion: 2.20.9-0ubuntu7.9
Architecture: amd64
Date: Mon Jan 6 18:44:10 2020
ProcEnviron:
TERM=xterm-256color
PATH=(custom, no user)
XDG_RUNTIME_DIR=<set>
LANG=C.UTF-8
SHELL=/bin/bash
SourcePackage: linux-signed-azure
UpgradeStatus: No upgrade log present (probably fresh install)
** Affects: linux-signed-azure (Ubuntu)
Importance: Undecided
Status: New
** Tags: amd64 apport-bug bionic bootspeed uec-images
--
You received this bug notification because you are a member of Ubuntu
Bugs, which is subscribed to Ubuntu.
https://bugs.launchpad.net/bugs/1858495
Title:
multiple long delays during kernel and userspace boot
To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/linux-signed-azure/+bug/1858495/+subscriptions
--
ubuntu-bugs mailing list
[email protected]
https://lists.ubuntu.com/mailman/listinfo/ubuntu-bugs
