Public bug reported:

I've instrumented a kernel so I can clearly see when processes start and
exit, this allows me to see when exactly the kernel has handed off
control to userspace.  The time the kernel actually takes to initialize
compared to the time systemd-analyze reports are different.

$ systemd-analyze 
Startup finished in 16.878s (kernel) + 43.152s (userspace) = 1min 30ms

For example:

[    2.286330] Freeing unused kernel memory: 1532K (ffffffffb1755000 - 
ffffffffb18d4000)
[    2.296300] Write protecting the kernel read-only data: 12288k
[    2.304356] Freeing unused kernel memory: 1872K (ffff9d9c6e42c000 - 
ffff9d9c6e600000)
[    2.317659] Freeing unused kernel memory: 1208K (ffff9d9c6e8d2000 - 
ffff9d9c6ea00000)
[    2.344896] x86/mm: Checked W+X mappings: passed, no W+X pages found.
[    2.368095] exec: 1 (swapper/0) -> /init
[    2.377284] _do_fork: 1 init
[    2.381933] exit 53 init
[    2.386444] _do_fork: 1 init
[    2.390741] exit 54 init
[    2.394899] _do_fork: 1 init

and we have the initramfs initialization occurring, and then finally
systemd starts:

[   16.571630] exec: 1 (run-init) -> /sbin/init
[   17.287342] systemd[1]: systemd 229 running in system mode. (+PAM +AUDIT 
+SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS 
+ACL +XZ -LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD -IDN)
[   17.307892] systemd[1]: Detected virtualization microsoft.
[   17.314765] systemd[1]: Detected architecture x86-64.
[   17.421589] systemd[1]: Set hostname to <boottest>.

So it seems that systemd is accounting initramfs time in the kernel time
stats.  It would be preferable to be able to report the kernel init
time, the initramfs time and the userspace time rather just kernel +
userspace.

As it stands, the kernel passed off control to systemd at 16.571630
seconds, so I have no no idea why systemd is reporting 16.878 seconds.

** Affects: systemd (Ubuntu)
     Importance: Undecided
         Status: New

-- 
You received this bug notification because you are a member of Ubuntu
Touch seeded packages, which is subscribed to systemd in Ubuntu.
https://bugs.launchpad.net/bugs/1615685

Title:
  systemd-analyze stats for kernel startup time looks suspect

Status in systemd package in Ubuntu:
  New

Bug description:
  I've instrumented a kernel so I can clearly see when processes start
  and exit, this allows me to see when exactly the kernel has handed off
  control to userspace.  The time the kernel actually takes to
  initialize compared to the time systemd-analyze reports are different.

  $ systemd-analyze 
  Startup finished in 16.878s (kernel) + 43.152s (userspace) = 1min 30ms

  For example:

  [    2.286330] Freeing unused kernel memory: 1532K (ffffffffb1755000 - 
ffffffffb18d4000)
  [    2.296300] Write protecting the kernel read-only data: 12288k
  [    2.304356] Freeing unused kernel memory: 1872K (ffff9d9c6e42c000 - 
ffff9d9c6e600000)
  [    2.317659] Freeing unused kernel memory: 1208K (ffff9d9c6e8d2000 - 
ffff9d9c6ea00000)
  [    2.344896] x86/mm: Checked W+X mappings: passed, no W+X pages found.
  [    2.368095] exec: 1 (swapper/0) -> /init
  [    2.377284] _do_fork: 1 init
  [    2.381933] exit 53 init
  [    2.386444] _do_fork: 1 init
  [    2.390741] exit 54 init
  [    2.394899] _do_fork: 1 init

  and we have the initramfs initialization occurring, and then finally
  systemd starts:

  [   16.571630] exec: 1 (run-init) -> /sbin/init
  [   17.287342] systemd[1]: systemd 229 running in system mode. (+PAM +AUDIT 
+SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS 
+ACL +XZ -LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD -IDN)
  [   17.307892] systemd[1]: Detected virtualization microsoft.
  [   17.314765] systemd[1]: Detected architecture x86-64.
  [   17.421589] systemd[1]: Set hostname to <boottest>.

  So it seems that systemd is accounting initramfs time in the kernel
  time stats.  It would be preferable to be able to report the kernel
  init time, the initramfs time and the userspace time rather just
  kernel + userspace.

  As it stands, the kernel passed off control to systemd at 16.571630
  seconds, so I have no no idea why systemd is reporting 16.878 seconds.

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/systemd/+bug/1615685/+subscriptions

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

Reply via email to