systemd-analyze: what slows the boot and what is wrong in a unit

systemd records when each unit started and finished starting. systemd-analyze reads these times and shows them three ways: the boot total, a list of units and a chain of dependencies. The same command checks a unit file before systemd reads it.

Without a subcommand it prints the boot total of the lab machine:

student@ubuntu:~$ systemd-analyze
Startup finished in 2.902s (kernel) + 6.382s (userspace) = 9.285s
multi-user.target reached after 6.356s in userspace.

kernel is the kernel and initramfs before systemd starts, userspace is systemd's work until the boot is done. The systemd-boot loader on UEFI also reports firmware and loader; GRUB does not report these times. The second line names the boot target and when systemd reached it.

How long each unit took — blame

student@ubuntu:~$ systemd-analyze blame | head -6
2.368s apparmor.service
2.208s labs-ssh-hostkeys.service
1.151s dev-vda4.device
 892ms containerd.service
 835ms rsyslog.service
 671ms ldconfig.service

The time on a line is how long the unit took to start: from the "start" command to the active state. Units start in parallel, so the times add up to more than the whole boot, and the first line may have delayed nobody. critical-chain shows who actually held the boot.

The time depends on the service type. For Type=oneshot it includes all of the ExecStart= work. A Type=simple service counts as started as soon as systemd creates its process — even if the program then spends a minute getting ready to accept requests.

Services started after the boot are on the list too. A test service with ExecStart=/bin/sleep 4 and Type=oneshot came first:

4.007s lab-slow.service

The critical chain

student@ubuntu:~$ systemd-analyze critical-chain
multi-user.target @6.356s
└─containerd.service @4.211s +892ms
  └─dbus.service @4.060s +131ms
    └─basic.target @4.045s
      └─sockets.target @4.044s
        └─lxd-installer.socket @4.030s +11ms
          └─sysinit.target @3.989s
            └─apparmor.service @1.618s +2.368s
              └─local-fs.target @1.603s

Two lines before the tree explain the marks: after @ is when the unit became active (seconds from the start of userspace), after + is how long it took to start. Read from the bottom up: each unit waited for the one below it. apparmor.service took 2.368 s, and sysinit.target got it only at 3.989 s — everything above started after that. Units started after the target was reached are not in its chain.

The chain follows After=: of the units this one starts after, it picks the one that finished last. With a unit name it shows what that unit itself waited for; the first line has only +:

student@ubuntu:~$ systemd-analyze critical-chain lab-slow.service
lab-slow.service +4.007s
└─nginx.service @4.114s +207ms
  └─basic.target @4.045s
    └─sockets.target @4.044s

lab-slow.service took 4 s, and before that it waited for nginx.service — it has After=nginx.service.

Checking a unit — verify

systemd-analyze verify loads a unit the way systemd does on daemon-reload and prints what it did not like. Give a file by path — you can check it before copying it to /etc/systemd/system; give an installed unit by name. What verify prints for mistakes in a unit:

Code 0 only means the unit will load. systemd skips a misspelled line and a wrong value, and the service runs with the defaults: without After=, with type simple. A clean unit is empty output.

• systemd — units, drop-ins and dependencies.
• systemctl — start, stop and service state.
• journalctl — the journal of this boot: journalctl -b.
• boot-grub — what happens before systemd.
• systemd-hardening — systemd-analyze security.
• systemd-timers — systemd-analyze calendar.