** Changed in: linux-signed-azure (Ubuntu)
     Assignee: (unassigned) => Colin Ian King (colin-king)

-- 
You received this bug notification because you are a member of Kernel
Packages, which is subscribed to linux-signed-azure in Ubuntu.
https://bugs.launchpad.net/bugs/1858495

Title:
  multiple long delays during kernel and userspace boot

Status in linux-signed-azure package in Ubuntu:
  New

Bug description:
  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)

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/linux-signed-azure/+bug/1858495/+subscriptions

-- 
Mailing list: https://launchpad.net/~kernel-packages
Post to     : kernel-packages@lists.launchpad.net
Unsubscribe : https://launchpad.net/~kernel-packages
More help   : https://help.launchpad.net/ListHelp

Reply via email to