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