systemd-analyze blameとは
systemd-analyze blameは、起動時に実行された各Unitの初期化にかかった時間を一覧表示するコマンドである。時間の長い順にソートされるため、起動が遅い原因となっているサービスを特定する際に利用する。
使い方
以下のコマンドを実行する。
$ systemd-analyze blame
動作確認
Dockerコンテナ上でsystemdを動かし、動作を確認する。
通常の起動時間を確認する
まず全体の起動時間をsystemd-analyzeで確認する。
$ systemd-analyze
Startup finished in 188ms (userspace)
graphical.target reached after 180ms in userspace
続けてsystemd-analyze blameを実行し、各サービスの初期化時間を確認する。
$ systemd-analyze blame
37ms systemd-resolved.service
33ms systemd-logind.service
23ms systemd-journal-flush.service
17ms systemd-journald.service
14ms e2scrub_reap.service
5ms dev-hugepages.mount
5ms sys-kernel-debug.mount
4ms sys-kernel-tracing.mount
4ms systemd-user-sessions.service
4ms systemd-tmpfiles-setup.service
時間のかかった順にサービスが並んでおり、systemd-resolved.serviceが最も時間を要していることが分かる。
起動の遅いサービスを検出する
意図的に起動を遅くするサービスを作成し、systemd-analyze blameで検出できるか確認する。
[Unit]
Description=Slow demo service
DefaultDependencies=no
Before=sysinit.target
[Service]
Type=oneshot
ExecStart=/bin/sleep 3
RemainAfterExit=yes
[Install]
WantedBy=sysinit.target
起動時に3秒sleepするだけのサービスである。DefaultDependencies=noとBefore=sysinit.targetは起動の早い段階でサービスを開始させるための検証用の設定であり、通常のアプリケーションサービスでは使わない。作成後、有効化して再起動する。
$ sudo systemctl enable slow-demo.service
$ sudo reboot
再起動後にsystemd-analyze blameを実行する。
$ systemd-analyze blame
3.003s slow-demo.service
40ms systemd-logind.service
34ms systemd-resolved.service
30ms systemd-journal-flush.service
23ms systemd-journald.service
19ms e2scrub_reap.service
slow-demo.serviceが最上位に表示され、他のサービスと比べて突出して時間がかかっていることが一目で分かる。
critical-chainで依存関係も含めた時間を確認する
systemd-analyze blameは各Unit単体の初期化時間を表示するのみで、Unit間の依存関係は考慮しない。そのため、あるサービスの初期化自体は速くても、依存先のサービスの起動待ちで全体の起動が遅くなっているケースはblameだけでは分からない。
依存関係を含めた起動時間のクリティカルパスを確認するにはsystemd-analyze critical-chainを使う。
$ systemd-analyze critical-chain
graphical.target @3.127s
└─multi-user.target @3.126s
└─systemd-logind.service @3.086s +40ms
└─dbus.socket @3.064s
└─sysinit.target @3.062s
└─slow-demo.service @59ms +3.003s
└─systemd-journald.socket @54ms
└─-.mount @45ms
└─-.slice @45ms
@の後ろの時間はUnitが起動した時刻、+の後ろの時間はそのUnit自体の起動に要した時間である。slow-demo.serviceの起動完了をsysinit.targetが待っているため、後続の起動全体が遅延していることが分かる。
サーバー全体の起動時間を短縮したい場合は、まずsystemd-analyze blameで時間のかかっているサービスの見当をつけ、systemd-analyze critical-chainで依存関係上のボトルネックになっているかを確認するとよい。
