在 Linux 如何優雅的統計程式執行時間?恕我直言,你執行的可能是假 time

肖邦linux發表於2021-05-12

最近在使用 time 命令時,無意間發現了一些隱藏的小祕密和強大功能,今天分享給大家。

time 在 Linux 下是比較常用的命令,可以幫助我們方便的計算程式的執行時間,對比採用不同方案時程式的執行效能。看似簡單的命令,其實蘊藏著很多細節和技巧,來跟著肖邦一起學習吧。

1 基礎用法詳解

先來看下最基礎的用法,也可能是大家最常見的用法了

root@chopin:~$ time find . -name "chopin.txt"
......
real   0m0.174s
user   0m0.084s
sys    0m0.084s

可以很清楚看到,find 命令執行的時間為 0.174s,是不是很簡單,很方便呢

不過,time 命令輸出了三個引數,我們只用到了第一個引數,其它兩個引數代表什麼含義呢?

這裡我來解釋一下:

  • real:表示的是牆上時間,說白了,其實就是從程式執行開始到結束所經歷的時間;
  • user:表示程式執行期間,cpu 在使用者態所花費的時間;
  • sys:表示程式執行期間,cpu 在核心態所花費的時間;

細心的讀者會發現,上述案例中的 user + sys 不等於 real,這是怎麼回事呢?

其實上邊解釋的 usersys,是 cpu 執行指令所消耗的時間,並不包含:程式阻塞 IO、排程排隊,這些非 cpu 執行時間。

案例中 find 執行查詢檔案過程中,會有磁碟 IO 讀取,這時 cpu 會被釋放出來幹別的事情,這些 IO 消耗的時間,是不包含在 usersys 統計資料中,所以就出現了 real 時間大於 user + sys 了。

再通過一個示例來驗證並加強我們的理解

root@chopin:~$ time sleep 2
real   0m2.001s
user   0m0.000s
sys    0m0.000s

可以清楚地看到,sleep 命令基本上沒有消耗 cpu,程式真實的執行時間就是 2 秒

那我們是不是可以得出如下結論了呢:

real >= user + sys

其實這個結論在單個 cpu 情況下,是正確的。

如果伺服器是多個 cpu,你的程式正好可以將多個 cpu 充分利用起來,程式執行期間是多核心並行的,那麼 user + sys 統計的 cpu 時間可能就會大於 real 時間啦

所以這 3 個時間之間的關係並不是恆定的,你需要清楚的瞭解伺服器是否為多個核心。

其實,通過統計到的 cpu 消耗時間,我們也可以大概知道,程式執行期間 cpu 利用情況。對於單核,計算密集型的程式,real 會很接近 usersys 時間之和的。

Tips:有些同學可能對作業系統可能不太熟悉,這裡簡單科普下核心態使用者態的基本概念

Linux 為使系統更穩定,採取了隔離保護的措施,執行狀態分為核心態和使用者態

  • 使用者態:使用者程式碼不具備直接訪問底層資源的能力,需要藉助核心提供的系統呼叫 API。在這種隔離保護下,即使使用者程式崩潰,也不會影響整個系統的功能。
  • 核心態:核心程式碼具備最大許可權,可執行任意 cpu 指令,不受任何限制。核心態通常是作業系統提供的最底層、最可靠的程式碼執行的,核心態的程式碼崩潰是災難性的,影響整個系統的正常執行。

2 你執行的可能是假time

time 還有其它功能嗎?看一下幫助文件吧

root@chopin:~$ time --help
--helpcommand not found
real 0m0.129s
user 0m0.084s
sys 0m0.036s

竟然報錯,將 --help 當成了命令來執行了,難道 time 就這麼點能耐嗎?

好吧,我也不賣關子了,直接說答案:你執行的可能是假time。你可能有點懵逼,怎麼就假的了。

其實在 Linux 系統上,使用 time 時,你可能會遇到三種版本:

# 1. Bash
time is a shell keyword
# 2. Zsh
time is a reserved word
# 3. GNU time
time is /usr/bin/time

我們當前 Shell 是 Bash,可以通過 type 命令

root@chopin:~$ type time
time is a shell keyword

可以看到,我們剛才執行的 time 是 Shell 的內建命令,如果你用的是 zsh,預設使用的 time 也是對應內建命令。

GNU time 命令路徑是 /usr/bin/time,一般的 Linux 發行版都帶有這個命令,它才是我們今天的豬腳。

3 更強大的功能

GNU time 命令提供了更強大的功能:

  • 更詳細的統計資訊
  • 更豐富的格式輸出
  • 支援儲存統計資料到檔案

下邊我們來學習寫 GNU time 的使用

1. 最簡單的用法

root@chopin:~$ /usr/bin/time sleep 2
0.00user 0.00system 0:02.00elapsed 0%CPU (0avgtext+0avgdata 1784maxresident)k
0inputs+0outputs (0major+72minor)pagefaults 0swaps

使用 GNU time 命令,直接使用絕對路徑即可,我們可以看到輸出資訊更多了,不過格式有點醜,後邊會講如何自定義格式。

2. 保持內建 time 的輸出樣式

有同學會問,能輸出內建 Shell 那種的格式麼?可以的,使用 -p 選項即可

root@chopin:~$ /usr/bin/time -p sleep 2
real 2.00
user 0.00
sys  0.00

3. 輸出更詳細的資訊

還可以輸出更加詳細的資訊,讓你對程式執行資訊一目瞭然。請使用 -v 選項

root@chopin:~$ /usr/bin/time -v sleep 2
Command being timed: "sleep 2"
User time (seconds): 0.00
System time (seconds): 0.00
Percent of CPU this job got: 0%
Elapsed (wall clock) time (h:mm:ss or m:ss): 0:02.00
Average shared text size (kbytes): 0
Average unshared data size (kbytes): 0
Average stack size (kbytes): 0
Average total size (kbytes): 0
Maximum resident set size (kbytes): 1804
Average resident set size (kbytes): 0
Major (requiring I/O) page faults: 0
Minor (reclaiming a frame) page faults: 71
Voluntary context switches: 1
Involuntary context switches: 1
Swaps: 0
File system inputs: 0
File system outputs: 0
Socket messages sent: 0
Socket messages received: 0
Signals delivered: 0
Page size (bytes): 4096
Exit status: 0

這裡詳細介紹下 time 命令輸出各項指標

(一)時間相關

(二)記憶體相關

(三)IO 相關

4. 統計資訊輸出到檔案

如果你希望將 time 統計的資訊輸出到檔案,可以使用 -o 選項

root@chopin:~$ /usr/bin/time -v -o a.txt sleep 2

統計資訊直接儲存到了 a.txt,如果你希望統計資訊能夠追加到檔案,可以額外加 -a 選項

5. 自定義格式輸出

如果命令中內建的輸出格式,不符合你的需求,GNU time 可以支援自定義輸出格式,通過選項 -f 可以各種指標引數

/usr/bin/time -f "real %e\nuser %U\nsys %S\n" sleep 1
real 1.00
user 0.00
sys  0.00

具體支援的格式,貼心的肖邦已經幫你整理好了

這些格式引數太多了,平時大部分情況用不到,可以收藏起來,以便後期使用時可以快速參考。

4 效能分析中的作用

看到這麼多系統引數指標,難免會有同學會感到疑惑,這些引數能幹什麼呀?

其實這些指標,對應到作業系統 cpu、記憶體、IO 這幾方面。深刻的理解了這些指標引數,可以幫助你從本質上把握程式的執行情況,甚至可以協助你分析程式的效能瓶頸。

下邊我簡單解釋幾個概念,希望能起到拋磚引玉的作用。

(一)CPU 時間

cpu 時間包括:realusersys,當 user + sys >= real 時,說明該程式是計算密集型;當 user + sys 遠小於 real 時,說明存在較多的 IO 等待。

(二)上下文切換

平時所說的上下文,是指程式的執行環境,包括當時的暫存器值、記憶體堆疊等資訊,核心根據上下文完全恢復一個被打斷的程式任務。

當執行系統呼叫、程式切換時,都會產生上下文切換。切換上下文時,作業系統需要為程式儲存和恢復上下文資訊。

上下文切換分為主動被動兩種,主動上下文切換多,說明存在較多的阻塞呼叫;被動上下文切換說明 cpu 使用率高。

當上下文切換過多時,意味著較多的 cpu 時間花費在上下文切換上,導致 cpu 處理程式任務的有效時間大大減少。

(三)缺頁異常

次缺頁異常較多,說明程式的記憶體佈局相對合理,命中率高;當主缺頁異常較多時,說明程式對記憶體的訪問跳躍性大,命中率低。

處理缺頁異常和切換上下文的時間,不包含在 usersys 中,當發現 user + sys 遠小於 real 時,則很可能大部分時間都消耗在這些地方,需要重點分析這兩點。

推薦閱讀

推薦閱讀

歡迎各位老鐵關注

相關文章