Linux 啟動效能分析

語言: CN / TW / HK

系統管理員的一部分工作就是分析系統性能,發現並解決引起效能不佳、啟動時間長的問題。系統管理員也需要去檢查 systemd 的配置和使用的其它方面。

systemd 初始化系統提供了 systemd-analyze 工具,可以幫助發現效能問題和其他重要的 systemd 資訊。在以前的文章《​ ​分析 systemd 日曆和時間跨度​ ​》裡,我用了 systemd-analyze 去分析 systemd 裡的時間戳和時間跨度,但是這個工具還有很多其他用法,這個文章裡我將再揭示一些。

(LCTT 譯註:systemd 是目前主流 Linux 發行版採用的系統管理系統)

(LCTT 譯註:為了區分英文的 “boot” 和 “startup” 的不同涵義,此處將 “boot” 翻譯為“引導”,“startup” 翻譯為“啟動”。)

概述啟動

Linux 啟動過程是值得學習關注的地方,因為 systemd-analyze 工具很多功能聚焦在啟動startup過程。但是首先,要理解引導boot和啟動startup。引導階段從 BIOS 加電自檢(POST)開始,結束於核心完成載入並控制主機系統,然後是開始了啟動過程,也是 systemd 日誌的開始點。

這個系列的第二篇文章《​ ​理解 Linux 啟動時的 systemd​ ​》中,我詳細討論了啟動階段的內容和過程。在這篇文章裡,我想研究一下啟動過程,看看需要多少時間和大部分時間花費在哪裡。

下面我將展示的結果來自我的主要工作站,這比虛擬機器的結果要有趣得多。這個工作站包括一塊 華碩 TUF X299 Mark 2 主機板、一個英特爾 i9-7960X CPU(16 核 32 執行緒),64 G 記憶體。下面的一些命令非 root 使用者也可以使用,但是我在這篇文章裡使用了 root 使用者,以避免在使用者之間切換。

檢查啟動過程有幾種方法,最簡單的 systemd-analyze 命令顯示了啟動的幾個主要部分耗費的時間,包括核心啟動、裝載執行 initrd(即初始 ramdisk,這是一個用來初始化一些硬體、掛載 / 根檔案系統的臨時系統映象),還有使用者空間(載入所有使主機達到可用狀態的程式和守護程式)。如果沒有像該命令傳遞子命令,預設是 systemd-analyze time:

[[email protected] ~]$ systemd-analyze
Startup finished in 53.921s (firmware) + 2.643s (loader) + 2.236s (kernel) + 4.348s (initrd) + 10.082s (userspace) = 1min 13.233s
graphical.target reached after 10.071s in userspace
[[email protected] ~]#

這個輸出中最值得注意的資料是在韌體(BIOS)中花費的時間:幾乎 54 秒。這是一個不太正常的時間,我的其他物理系統都沒有花費這麼長的時間來通過 BIOS。

我的 System76 Oryx Pro 筆記本在 BIOS 階段只花了 8.506 秒,我家裡所有的系統都在 10 秒以內。線上搜尋一陣之後,我發現這塊主機板以其超長的 BIOS 引導時間而聞名。我的主機板從不“馬上啟動”,總是掛起,我需要關機再開機,BIOS 報錯,按 F1 進入 BIOS 設定,選擇要引導的驅動器完成引導,多花費的時間就是這樣用掉的。

不是所有主機都會顯示韌體資料(LCTT 譯註:韌體引導中不涉及 systemd)。我的不科學的實驗使我相信,這個資料只顯示給英特爾 9 代或以上的處理器。但這可能是不正確的。

這個關於引導、啟動的概述提供了很好的(雖然有限)的資訊,但是還有很多關於啟動的資訊,我將在下面描述。

分配責任

你可以用 systemd-analyze blame 來發現哪個 systemd 單元的初始化時間最長。其結果按照初始化時間長短排序,從多到少:

[[email protected] ~]$ systemd-analyze blame  
       5.417s NetworkManager-wait-online.service
       3.423s dracut-initqueue.service
       2.715s systemd-udev-settle.service
       2.519s fstrim.service
       1.275s udisks2.service
       1.271s smartd.service
        996ms upower.service
        637ms lvm2-monitor.service
        533ms [email protected]:17.service
        520ms dmraid-activation.service
        460ms vboxdrv.service
        396ms initrd-switch-root.service
<截斷:刪去了好多時間不長的條目>

因為很多服務是並行開始的,在 BIOS 之後所有單元加在一起的總數大大超過了 systemd-analyze time 彙總數。很多都是小數,不能顯著的節省時間。

這個命令提供的資料指明瞭改善啟動時間的辦法。無用的服務可以禁用(disable)。在這個啟動過程中,似乎沒有任何一個服務需要花費過長的時間。你可能會在每次啟動時看到不同的結果。(LCTT 譯註:並行啟動服務的原因)

關鍵鏈

就像專案管理中的關鍵路徑一樣,關鍵鏈顯示了在啟動過程中發生的時間關鍵的事件鏈(LCTT 譯註:systemd 可以定義服務間的依賴,構成關鍵鏈)。如果啟動緩慢,這些是你想檢視的 systemd 單元,因為它們是導致延遲的單元。這個工具不會顯示所有啟動的單元,只顯示這個關鍵事件鏈中的單元。(LCTT 譯註:相當於最短路徑。並不顯示依賴不在關鍵鏈上的服務單元)

[[email protected] ~]# systemd-analyze critical-chain
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.
graphical.target @10.071s
└─lxdm.service @10.071s
  └─plymouth-quit.service @10.047s +22ms
    └─systemd-user-sessions.service @10.031s +7ms
      └─remote-fs.target @10.026s
        └─remote-fs-pre.target @10.025s
          └─nfs-client.target @4.636s
            └─gssproxy.service @4.607s +28ms
              └─network.target @4.604s
                └─NetworkManager.service @4.383s +219ms
                  └─dbus-broker.service @4.434s +136ms
                    └─dbus.socket @4.369s
                      └─sysinit.target @4.354s
                        └─systemd-update-utmp.service @4.345s +9ms
                          └─auditd.service @4.301s +42ms
                            └─systemd-tmpfiles-setup.service @4.254s +42ms
                              └─import-state.service @4.233s +19ms
                                └─local-fs.target @4.229s
                                  └─Virtual.mount @4.019s +209ms
                                    └─[email protected]_david2\x2dVirtual.service @3.742s +274ms
                                      └─local-fs-pre.target @3.726s
                                        └─lvm2-monitor.service @356ms +637ms
                                          └─dm-event.socket @319ms
                                            └─-.mount
                                              └─system.slice
                                                └─-.slice
[[email protected] ~]#

前面有 @ 的數字表示單元啟用開始啟動所使用的絕對秒數。前面有 + 的數字顯示單元啟動所需的時間。

系統狀態

有時候你需要確定系統的當前狀態,systemd-analyze dump 命令轉儲了當前系統狀態的大量資料。有主要的啟動時間戳,一個每個 systemd 單元的列表,並對每個單元狀態進行了完整描述:

[[email protected] ~]# systemd-analyze dump
Timestamp firmware: 1min 7.983523s
Timestamp loader: 3.872325s
Timestamp kernel: Wed 2020-08-26 12:33:35 EDT
Timestamp initrd: Wed 2020-08-26 12:33:38 EDT
Timestamp userspace: Wed 2020-08-26 12:33:42 EDT
Timestamp finish: Wed 2020-08-26 16:33:56 EDT
Timestamp security-start: Wed 2020-08-26 12:33:42 EDT
Timestamp security-finish: Wed 2020-08-26 12:33:42 EDT
Timestamp generators-start: Wed 2020-08-26 16:33:42 EDT
Timestamp generators-finish: Wed 2020-08-26 16:33:43 EDT
Timestamp units-load-start: Wed 2020-08-26 16:33:43 EDT
Timestamp units-load-finish: Wed 2020-08-26 16:33:43 EDT
Timestamp initrd-security-start: Wed 2020-08-26 12:33:38 EDT
Timestamp initrd-security-finish: Wed 2020-08-26 12:33:38 EDT
Timestamp initrd-generators-start: Wed 2020-08-26 12:33:38 EDT
Timestamp initrd-generators-finish: Wed 2020-08-26 12:33:38 EDT
Timestamp initrd-units-load-start: Wed 2020-08-26 12:33:38 EDT
Timestamp initrd-units-load-finish: Wed 2020-08-26 12:33:38 EDT
-> Unit system.slice:
        Description: System Slice
        Instance: n/a
        Unit Load State: loaded
        Unit Active State: active
        State Change Timestamp: Wed 2020-08-26 12:33:38 EDT
        Inactive Exit Timestamp: Wed 2020-08-26 12:33:38 EDT
        Active Enter Timestamp: Wed 2020-08-26 12:33:38 EDT
        Active Exit Timestamp: n/a
        Inactive Enter Timestamp: n/a
        May GC: no
<截斷:刪除了大量的輸出行>

在我的主工作站上,這個命令生成了 49680 行輸出,大概 1.66MB,這個命令非常快,不需要等待。

我很喜歡為各種連線裝置(如儲存裝置)提供的大量細節。每個 systemd 單元有一個部分,包括各種執行時、快取、日誌目錄的模式、啟動單元的命令列、PID、開始時間戳,以及記憶體和檔案限制等細節。

systemd-analyze 的手冊頁裡展示了 systemd-analyze --user dump 選項,目的是顯示使用者管理器的內部狀態。但這個選項對我來說是失敗的,網際網路搜尋之後表明它可能有一些問題。在 systemd 裡,--user 例項用來管理和控制處理器給每個使用者的程序資源。處理能力按分給每個使用者的程序都屬於一個控制組,我將在以後的文章中介紹。

分析圖表

大多數啥都不懂的猥瑣老闆(PHB)和許多優秀的管理者都發現漂亮的圖表比我通常喜歡的基於文字的系統性能資料更容易閱讀和理解。但有時,即使是我也喜歡一個好的圖表,systemd-analyze 提供了顯示引導/啟動資料的 SVG 向量圖表。

下面的命令生成一個向量圖檔案,來顯示在引導和啟動過程發生的事件。生成這個檔案只需要幾秒:

[[email protected] ~]# systemd-analyze plot > /tmp/bootup.svg

這個命令建立了一個 SVG 檔案,SVG 是一個定義了一系列圖形向量的文字檔案,包括 Image Viewer、Ristretto、Okular、Eye of Mate、LibreOffice Draw 在內的這些可以生成圖形的應用,可以用 SVG 來建立影象。

我用 LibreOffice Draw(LCTT 譯註:一個辦公文件軟體)來渲染一幅圖形。這張圖形很大,你需要放到很大才能看清細節。這裡是它的一小部分:

The bootup.svg file displayed in LibreOffice Draw.

圖中時間軸上零點(0)的左邊是引導階段,零點的右邊是啟動階段。這一小部分顯示了核心、initrd 和 initrd 啟動的程序。

這張圖一目瞭然地顯示了什麼時候啟動,啟動需要多少時間,以及主要的依賴項。關鍵路徑用紅色高亮顯示。

另外一個生成圖形輸出的命令是 systemd-analyze plot,它生成了 DOT 格式的文字依賴圖。產生的資料流通過 dot 工具進行處理,這是一組用來從多種型別資料中生成向量圖檔案的程式。這些 SVG 檔案也能被上面列出的工具處理。

首先,生成檔案,在我的主工作站花了 9 分鐘:

[[email protected] ~]# time systemd-analyze dot | dot -Tsvg > /tmp/test.svg
   Color legend: black     = Requires
                 dark blue = Requisite
                 dark grey = Wants
                 red       = Conflicts
                 green     = After
real    8m37.544s
user    8m35.375s
sys     0m0.070s
[[email protected] ~]#

我不會在這裡重現輸出,因為產生的圖形就像一大堆義大利麵條。但是你應該試試,看看我想讓你看到的結果。

條件

在閱讀 systemd-analyze(1) 的手冊頁時,我發現了一個更有趣的功能,但又有點通用,就是條件子命令。(是的,我確實在讀手冊頁,而且我神奇地通過這種方式學到了很多東西!)。這個 condition 子命令能用來測試 systemd 單元檔案中的條件和斷言。

它也可以在指令碼中用來評估一個或多個條件 —— 如果所有條件都滿足,則返回 0;如果有條件不滿足,則返回 1。在其它情況下,它都會輸出其結果文字。

下面的例子來自手冊頁,稍微有點複雜。它測試了核心版本是否在 4.0 和 5.1 之間,主機是否使用交流電供電,系統結構是否是 ARM,以及 /etc/os-release 目錄是否存在。我添加了 echo $? 來列印返回值。

[[email protected] ~]# systemd-analyze condition 'ConditionKernelVersion = ! <4.0' \
                    'ConditionKernelVersion = >=5.1' \
                    'ConditionACPower=|false' \
                    'ConditionArchitecture=|!arm' \
                    'AssertPathExists=/etc/os-release' ; \
echo $?
test.service: AssertPathExists=/etc/os-release succeeded.
Asserts succeeded.
test.service: ConditionArchitecture=|!arm succeeded.
test.service: ConditionACPower=|false failed.
test.service: ConditionKernelVersion=>=5.1 succeeded.
test.service: ConditionKernelVersion=!<4.0 succeeded.
Conditions succeeded.
0
[[email protected] ~]#

條件和斷言的列表大約從 systemd.unit(5) 手冊頁的第 600 行左右開始。

列出配置檔案

systemd-analyze 工具提供了一種將各種配置檔案的內容傳送到 STDOUT 的方法,如圖所示。其基本目錄是 /etc/。

[[email protected] ~]# systemd-analyze cat-config systemd/system/display-manager.service
# /etc/systemd/system/display-manager.service
[Unit]
Description=LXDM (Lightweight X11 Display Manager)
#Documentation=man:lxdm(8)
[email protected]
After=systemd-user-sessions.service [email protected] plymouth-quit.service livesys-late.service
#Conflicts=plymouth-quit.service
[Service]
ExecStart=/usr/sbin/lxdm
Restart=always
IgnoreSIGPIPE=no
#BusName=org.freedesktop.lxdm
[Install]
Alias=display-manager.service
[[email protected] ~]#

打了這麼多字卻和標準的 cat 命令做的差不多。我發現下一條命令小有幫助,它能在標準的 systemd 所在的位置搜尋具有指定模式的內容:

[[email protected] ~]# systemctl cat backup*
# /etc/systemd/system/backup.timer
# This timer unit runs the local backup program
# (C) David Both
# Licensed under GPL V2
#
[Unit]
Description=Perform system backups
Requires=backup.service
[Timer]
Unit=backup.service
OnCalendar=*-*-* 00:15:30
[Install]
WantedBy=timers.target
# /etc/systemd/system/backup.service
# This service unit runs the rsbu backup program
# By David Both
# Licensed under GPL V2
#
[Unit]
Description=Backup services using rsbu
Wants=backup.timer
[Service]
Type=oneshot
Environment="HOME=/root"
ExecStart=/usr/local/bin/rsbu -bvd1
ExecStart=/usr/local/bin/rsbu -buvd2
[Install]
WantedBy=multi-user.target
[[email protected] ~]#

這兩個命令在每個檔案的內容前面都有一個註釋行,包含檔案的完整路徑和名稱。

單元檔案檢查

當建立了一個新的單元檔案,可以利用 verify 子命令幫助檢查語法是否正確。它能指出來不正確的拼寫,並列出缺失的服務單元。

[[email protected] ~]# systemd-analyze verify /etc/systemd/system/backup.service

秉承 Unix/Linux 的“沉默是金”的宗旨,沒有輸出意味著掃描的檔案中沒有錯誤。

安全性

security 子命令檢查指定服務的安全級別。它只能針對服務單元,其他型別的單元檔案不起作用:

[[email protected] ~]# systemd-analyze security display-manager
  NAME                                                        DESCRIPTION                                                     >
✗ PrivateNetwork=                                             Service has access to the host's network                        >
✗ User=/DynamicUser=                                          Service runs as root user                                       >
✗ CapabilityBoundingSet=~CAP_SET(UID|GID|PCAP)                Service may change UID/GID identities/capabilities              >
✗ CapabilityBoundingSet=~CAP_SYS_ADMIN                        Service has administrator privileges                            >
✗ CapabilityBoundingSet=~CAP_SYS_PTRACE                       Service has ptrace() debugging abilities                        >
✗ RestrictAddressFamilies=~AF_(INET|INET6)                    Service may allocate Internet sockets                           >
✗ RestrictNamespaces=~CLONE_NEWUSER                           Service may create user namespaces                              >
✗ RestrictAddressFamilies=~…                                  Service may allocate exotic sockets                             >
✗ CapabilityBoundingSet=~CAP_(CHOWN|FSETID|SETFCAP)           Service may change file ownership/access mode/capabilities unres>
✗ CapabilityBoundingSet=~CAP_(DAC_*|FOWNER|IPC_OWNER)         Service may override UNIX file/IPC permission checks            >
✗ CapabilityBoundingSet=~CAP_NET_ADMIN                        Service has network configuration privileges                    >
✗ CapabilityBoundingSet=~CAP_SYS_MODULE                       Service may load kernel modules
<截斷>
✗ CapabilityBoundingSet=~CAP_SYS_TTY_CONFIG                   Service may issue vhangup()                                     >
✗ CapabilityBoundingSet=~CAP_WAKE_ALARM                       Service may program timers that wake up the system              >
✗ RestrictAddressFamilies=~AF_UNIX                            Service may allocate local sockets                              >
→ Overall exposure level for backup.service: 9.6 UNSAFE ?
lines 34-81/81 (END)

是的,表情符是輸出的一部分。但是,當然,許多服務需要幾乎完全訪問所有的東西,以便完成它們的工作。我針對幾個服務運行了這個程式,包括我自己的備份服務;結果可能有所不同,但最底下一行似乎大多是一樣的。

這個工具對於在嚴格的安全環境檢查和修復使用者空間的服務單元是很有用的。我不認為我們的大多數都能用到它。

最後總結

這個強力的工具提供了一些有趣而驚人的有用選項。本文探討的大部分內容是關於使用 systemd-analyze 來深入瞭解 Linux 使用 systemd 的啟動效能。它還可以分析 systemd 的其他方面。

其中有些工具的作用有限,有幾個應該完全忘記。但在解決啟動和其他 systemd 功能的問題時,大多數都能起到很好的作用。