Trying to understand boot time reported by systemd-analyze

mcloaked · 2014-09-11 07:39:41

For some time I have been a bit puzzled by the reported boot time using systemd-analyze. For example on the machine that I am using to write this post I have:

$ sudo systemd-analyze
Startup finished in 6.924s (firmware) + 1.075s (loader) + 383ms (kernel) + 597ms (initrd) + 12.315s (userspace) = 21.296s

Yet if I measure the elapsed time from the moment that the rEFInd screen appears with the Arch Linux icon that is about to boot I find that it takes about 7 seconds from that moment to getting the KDM login greeter on the screen.

Can someone explain why there is such a big difference between the elapsed time to boot from the start of the uefi process in rEFInd to the reported 21 seconds from systemd-analyze?

I suppose it is not a big deal but it would be nice to know what I am not understanding about this.

Thanks

Last edited by mcloaked (2014-09-11 07:40:09)

ooo · 2014-09-11 08:12:27

My guess is that KDM starts in paraller with some other services, and even when you've reached your login screen, there are still some service starting in background.

You can generate detailed graph of your boot process with:

systemd-analyze plot > plot.svg

It will probably give you a better idea of what's happening.

stevenhoneyman · 2014-09-11 17:32:23

ooo wrote:

My guess is that KDM starts in paraller with some other services, and even when you've reached your login screen, there are still some service starting in background.
You can generate detailed graph of your boot process with:
systemd-analyze plot > plot.svg
It will probably give you a better idea of what's happening.

I'd guess the same (it adds up right based on your timings)

plot doesnt work for me for some reason:

$ systemd-analyze plot
(code 1)

(1 being the return value) nothing even outputted, or logged!

systemd-analyze critical-chain

might tell you some more useful info. shows a confusing tree of stuff it starts up, with some nonsensical red highlighting!

mcloaked · 2014-09-11 18:59:46

I am still confused since looking at the output of

$ sudo systemd-analyze critical-chain
The time after the unit is active or started is printed after the "@" character.
The time the unit takes to start is printed after the "+" character.

graphical.target @12.315s
└─multi-user.target @12.315s
  └─postfix.service @12.029s +285ms
    └─network.target @12.026s
      └─NetworkManager.service @3.926s +221ms
        └─basic.target @3.916s
          └─timers.target @3.915s
            └─systemd-tmpfiles-clean.timer @3.915s
              └─sysinit.target @3.911s
                └─systemd-backlight@backlight:intel_backlight.service @3.908s +3ms
                  └─system-systemd\x2dbacklight.slice @3.907s
                    └─system.slice
                      └─-.slice

Seems to indicate that the graphical.target comes alive at 12 seconds - yet the login prompt on the graphical screen is visible at 7 seconds! I could believe that after the login prompt the network may still be being initialised, but something still doesn't look right compared to the elapsed time for the graphical target.

stevenhoneyman · 2014-09-11 19:40:46

Yes, I spent a week trying to get something working how I wanted (not how systemd demands it is done) and then gave up. Every way I tried brought up a cryptic error message (even when it worked fine!).

try

systemctl list-dependencies

for a full tree listing... that should show you which services depend on things, and between the two, kdm should be in the middle somewhere

I still can't see why these trees are upside-down either! it would make more sense to me probably in the way "plot" shows (which is broken for me)

Last edited by stevenhoneyman (2014-09-11 19:43:49)

Arch Linux

#1 2014-09-11 07:39:41

Trying to understand boot time reported by systemd-analyze

#2 2014-09-11 08:12:27

Re: Trying to understand boot time reported by systemd-analyze

#3 2014-09-11 17:32:23

Re: Trying to understand boot time reported by systemd-analyze

#4 2014-09-11 18:59:46

Re: Trying to understand boot time reported by systemd-analyze

#5 2014-09-11 19:40:46

Re: Trying to understand boot time reported by systemd-analyze

Board footer