在Linux上,使用time優(yōu)雅的統(tǒng)計程序運行時間
大家好,我是肖邦。
最近在使用 time 命令時,無意間發(fā)現(xiàn)了一些隱藏的小秘密和強大功能,今天分享給大家。
time 在 Linux 下是比較常用的命令,可以幫助我們方便的計算程序的運行時間,對比采用不同方案時程序的運行性能。看似簡單的命令,其實蘊藏著很多細(xì)節(jié)和技巧,來跟著肖邦一起學(xué)習(xí)吧。
1 基礎(chǔ)用法詳解
先來看下最基礎(chǔ)的用法,也可能是大家最常見的用法了
- root@chopin:~$ time find . -name "chopin.txt"
- ......
- real 0m0.174s
- user 0m0.084s
- sys 0m0.084s
可以很清楚看到,find 命令執(zhí)行的時間為 0.174s,是不是很簡單,很方便呢
不過,time 命令輸出了三個參數(shù),我們只用到了第一個參數(shù),其它兩個參數(shù)代表什么含義呢?
這里我來解釋一下:
- real:表示的是墻上時間,說白了,其實就是從程序運行開始到結(jié)束所經(jīng)歷的時間;
- user:表示程序運行期間,cpu 在用戶態(tài)所花費的時間;
- sys:表示程序運行期間,cpu 在內(nèi)核態(tài)所花費的時間;
細(xì)心的讀者會發(fā)現(xiàn),上述案例中的 user + sys 不等于 real,這是怎么回事呢?
其實上邊解釋的 user 和 sys,是 cpu 執(zhí)行指令所消耗的時間,并不包含:進(jìn)程阻塞 IO、調(diào)度排隊,這些非 cpu 運行時間。
案例中 find 執(zhí)行查找文件過程中,會有磁盤 IO 讀取,這時 cpu 會被釋放出來干別的事情,這些 IO 消耗的時間,是不包含在 user 和 sys 統(tǒng)計數(shù)據(jù)中,所以就出現(xiàn)了 real 時間大于 user + sys 了。
再通過一個示例來驗證并加強我們的理解
- root@chopin:~$ time sleep 2
- real 0m2.001s
- user 0m0.000s
- sys 0m0.000s
可以清楚地看到,sleep 命令基本上沒有消耗 cpu,程序真實的運行時間就是 2 秒
那我們是不是可以得出如下結(jié)論了呢:
real >= user + sys
其實這個結(jié)論在單個 cpu 情況下,是正確的。
如果服務(wù)器是多個 cpu,你的程序正好可以將多個 cpu 充分利用起來,程序運行期間是多核心并行的,那么 user + sys 統(tǒng)計的 cpu 時間可能就會大于 real 時間啦
所以這 3 個時間之間的關(guān)系并不是恒定的,你需要清楚的了解服務(wù)器是否為多個核心。
通過統(tǒng)計到的 cpu 消耗時間,我們也可以大概知道,程序運行期間 cpu 利用情況。對于單核,計算密集型的程序,real 會很接近 user 和 sys 時間之和的。
Tips:有些同學(xué)可能對操作系統(tǒng)可能不太熟悉,這里簡單科普下內(nèi)核態(tài)和用戶態(tài)的基本概念
Linux 為使系統(tǒng)更穩(wěn)定,采取了隔離保護的措施,運行狀態(tài)分為內(nèi)核態(tài)和用戶態(tài):
- 用戶態(tài):用戶代碼不具備直接訪問底層資源的能力,需要借助內(nèi)核提供的系統(tǒng)調(diào)用 API。在這種隔離保護下,即使用戶程序崩潰,也不會影響整個系統(tǒng)的功能。
- 內(nèi)核態(tài):內(nèi)核代碼具備最大權(quán)限,可執(zhí)行任意 cpu 指令,不受任何限制。內(nèi)核態(tài)通常是操作系統(tǒng)提供的最底層、最可靠的代碼運行的,內(nèi)核態(tài)的代碼崩潰是災(zāi)難性的,影響整個系統(tǒng)的正常運行。
2 你運行的可能是假time
time 還有其它功能嗎?看一下幫助文檔吧
- root@chopin:~$ time --help
- --help: command not found
- real 0m0.129s
- user 0m0.084s
- sys 0m0.036s
竟然報錯,將 --help 當(dāng)成了命令來執(zhí)行了,難道 time 就這么點能耐嗎?
好吧,我也不賣關(guān)子了,直接說答案:你運行的可能是假time。你可能有點懵逼,怎么就假的了。
其實在 Linux 系統(tǒng)上,使用 time 時,你可能會遇到三種版本:
- # 1. Bash
- time is a shell keyword
- # 2. Zsh
- time is a reserved word
- # 3. GNU time
- time is /usr/bin/time
我們當(dāng)前 Shell 是 Bash,可以通過 type 命令
- root@chopin:~$ type time
- time is a shell keyword
可以看到,我們剛才執(zhí)行的 time 是 Shell 的內(nèi)置命令,如果你用的是 zsh,默認(rèn)使用的 time 也是對應(yīng)內(nèi)置命令。
GNU time 命令路徑是 /usr/bin/time,一般的 Linux 發(fā)行版都帶有這個命令,它才是我們今天的豬腳。
3 更強大的功能
GNU time 命令提供了更強大的功能:
- 更詳細(xì)的統(tǒng)計信息
- 更豐富的格式輸出
- 支持保存統(tǒng)計數(shù)據(jù)到文件
下邊我們來學(xué)習(xí)寫 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. 保持內(nèi)置 time 的輸出樣式
有同學(xué)會問,能輸出內(nèi)置 Shell 那種的格式么?可以的,使用 -p 選項即可
- root@chopin:~$ /usr/bin/time -p sleep 2
- real 2.00
- user 0.00
- sys 0.00
3. 輸出更詳細(xì)的信息
還可以輸出更加詳細(xì)的信息,讓你對程序運行信息一目了然。請使用 -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
這里詳細(xì)介紹下 time 命令輸出各項指標(biāo)
(一)時間相關(guān)
(二)內(nèi)存相關(guān)
(三)IO 相關(guān)
4. 統(tǒng)計信息輸出到文件
如果你希望將 time 統(tǒng)計的信息輸出到文件,可以使用 -o 選項
- root@chopin:~$ /usr/bin/time -v -o a.txt sleep 2
統(tǒng)計信息直接保存到了 a.txt,如果你希望統(tǒng)計信息能夠追加到文件,可以額外加 -a 選項
5. 自定義格式輸出
如果命令中內(nèi)置的輸出格式,不符合你的需求,GNU time 可以支持自定義輸出格式,通過選項 -f 可以各種指標(biāo)參數(shù)
- /usr/bin/time -f "real %e\nuser %U\nsys %S\n" sleep 1
- real 1.00
- user 0.00
- sys 0.00
具體支持的格式,貼心的肖邦已經(jīng)幫你整理好了
這些格式參數(shù)太多了,平時大部分情況用不到,可以收藏起來,以便后期使用時可以快速參考。
4 在性能分析中的作用
看到這么多系統(tǒng)參數(shù)指標(biāo),難免會有同學(xué)會感到疑惑,這些參數(shù)能干什么呀?
其實這些指標(biāo),對應(yīng)到操作系統(tǒng) cpu、內(nèi)存、IO 這幾方面。深刻的理解了這些指標(biāo)參數(shù),可以幫助你從本質(zhì)上把握程序的運行情況,甚至可以協(xié)助你分析程序的性能瓶頸。
下邊我簡單解釋幾個概念,希望能起到拋磚引玉的作用。
(一)CPU 時間
cpu 時間包括:real、user、sys,當(dāng) user + sys >= real 時,說明該程序是計算密集型;當(dāng) user + sys 遠(yuǎn)小于 real 時,說明存在較多的 IO 等待。
(二)上下文切換
平時所說的上下文,是指進(jìn)程的運行環(huán)境,包括當(dāng)時的寄存器值、內(nèi)存堆棧等信息,內(nèi)核可以根據(jù)上下文完全恢復(fù)一個被打斷的進(jìn)程任務(wù)。
當(dāng)執(zhí)行系統(tǒng)調(diào)用、進(jìn)程切換時,都會產(chǎn)生上下文切換。切換上下文時,操作系統(tǒng)需要為進(jìn)程保存和恢復(fù)上下文信息。
上下文切換分為主動和被動兩種,主動上下文切換多,說明存在較多的阻塞調(diào)用;被動上下文切換說明 cpu 使用率高。
當(dāng)上下文切換過多時,意味著較多的 cpu 時間花費在上下文切換上,導(dǎo)致 cpu 處理進(jìn)程任務(wù)的有效時間大大減少。
(三)缺頁異常
次缺頁異常較多,說明程序的內(nèi)存布局相對合理,命中率高;當(dāng)主缺頁異常較多時,說明程序?qū)?nèi)存的訪問跳躍性大,命中率低。
處理缺頁異常和切換上下文的時間,不包含在 user 和 sys 中,當(dāng)發(fā)現(xiàn) user + sys 遠(yuǎn)小于 real 時,則很可能大部分時間都消耗在這些地方,需要重點分析這兩點。