• 0 Posts
  • 2 Comments
Joined 3 years ago
Cake day: June 10th, 2023
  • vole@lemmy.worldtoLinux@lemmy.ml•Why is the TPM so slow on boot?English
    11·
    6 days ago

    The first thing is to do is to understand what you’re looking at. Read this:

    systemd-analyze blame¶

    This command prints a list of all running units, ordered by the time they took to initialize. This information may be used to optimize boot-up times. Note that the output might be misleading as the initialization of one service might be slow simply because it waits for the initialization of another service to complete. Also note: systemd-analyze blame does not display results for services with Type=simple, because systemd considers such services to be started immediately, hence no measurement of the initialization delays can be done. Also note that this command only shows the time units took for starting up, it does not show how long unit jobs spent in the execution queue. In particular it shows the time units spent in “activating” state, which is not defined for units such as device units that transition directly from “inactive” to “active”. This command hence gives an impression of the performance of program code, but cannot accurately reflect latency introduced by waiting for hardware and similar events.

    For example: I have passphrase disk encryption (no TPM encryption), and the time I take to enter the passphrase is added to many entries in systemd-analyze blame. Here is the output of systemd-analyze blame if I wait 2 minutes to enter my disk encryption passphrase:

    2min 12.640s sys-module-fuse.device
2min 12.618s sys-devices-platform-MSFT0101:00-tpm-tpm0.device
2min 12.618s dev-tpm0.device
2min 12.551s dev-ttyS0.device
2min 12.551s sys-devices-pnp0-00:00-00:00:0-00:00:0.0-tty-ttyS0.device
2min 12.550s dev-ttyS2.device
...

    So, I guess my advice is that systemd-analyze blame is not always going to be a clear indicator that a particular service is holding your boot times back. The .device entries in particular probably just represent how long after boot that the device became active. And unfortunately the systemd-analyze tools do not always lead you to the underlying delay.

    $ systemd-analyze critical-chain dev-tpm0.device
The time when unit became active or started is printed after the "@" character.
The time the unit took to start is printed after the "+" character.

dev-tpm0.device +2min 12.618s

$ systemd-analyze critical-chain dracut-initqueue.service
The time when unit became active or started is printed after the "@" character.
The time the unit took to start is printed after the "+" character.

dracut-initqueue.service +2min 11.123s
└─systemd-udev-trigger.service @770ms +158ms
  └─systemd-udevd-varlink.socket @760ms +65us
    └─system.slice
      └─-.slice

    If you are trying to deal with an issue that is causing significant delays in your boot time, journalctl --boot can sometimes be helpful. For the example boot above where I waited 2 minutes before entering the disk encryption passphrase:

    Jul 31 14:09:39 mycomputer kernel: Linux version 7.1.5-201.fc44.x86_64 (mockbuild@9b86e96a386140128351588d751166fd) (gcc (GCC) 16.1.1 20260515 (Red Hat 16.1.1-2), GNU ld versi>
... (a lot of log lines within a few seconds, but then I find a big jump) ...
Jul 31 14:09:44 mycomputer kernel: [drm] pre_validate_dsc:1667 MST_DSC dsc precompute is not needed
Jul 31 14:11:48 mycomputer systemd-cryptsetup[551]: Set cipher aes, mode xts-plain64, key size 512 bits for device /dev/disk/by-uuid/...
... (and then there are a lot of log lines in the following seconds after the above line) ...