翻譯自《Netflix Tech Blog》,原作者Brendan Gregg
Linux Performance Analysis in 60,000 Milliseconds
登陸一臺 Linux 服務器排查性能問題:開始一分鐘你該檢查哪些呢况木?
在 Netflix 我們有一個龐大的 EC2 Linux集群街州,也有許多性能分析工具用于監(jiān)視和檢查它們的性能兜喻。它們包括用于云監(jiān)測的Atlas (工具代號) 福澡,用于實例分析的 Vector (工具代號) 吧慢。
盡管這些工具能幫助我們解決大部分問題,我們有時也需要登陸一臺實例奄抽、運行一些標準的 Linux 性能分析工具。
在這篇文章甩鳄,Netflix 性能工程團隊將向您展示:在開始的60秒鐘逞度,利用標準的Linux命令行工具,執(zhí)行一次充分的性能檢查妙啃。
黃金60秒:概述
運行以下10個命令档泽,你可以在60秒內,獲得系統資源利用率和進程運行情況的整體概念揖赴。查看是否存在異常馆匿、評估飽和度,它們都非常易于理解燥滑,可用性強渐北。飽和度表示資源還有多少負荷可以讓它處理,并且能夠展示請求隊列的長度或等待的時間铭拧。
uptime
dmesg | tail vmstat 1
mpstat -P ALL 1 pidstat 1
iostat -xz 1 free -m
sar -n DEV 1
sar -n TCP,ETCP 1 top
這些命令需要安裝sysstat包赃蛛。
這些命令輸出的指標,將幫助你掌握一些有效的方法:一整套尋找性能瓶頸的方法論搀菩。這些命令需要檢查所有資源的利用率呕臂、飽和度和錯誤信息(CPU、內存肪跋、磁盤等)歧蒋。同時,當你檢查或排除一些資源的時候,需要注意在檢查過程中疏尿,根據指標數據指引瘟芝,逐步縮小目標范圍。
接下來的章節(jié)褥琐,將結合生產環(huán)境的案例演示這些命令锌俱。如果希望了解這些工具的詳細信息,可以查閱它們的操作文檔敌呈。
1. uptime
$ uptime
23:51:26up21:31, 1user, loadaverage:30.02,26.43,19.02
這是一個快速查看平均負載的方法贸宏,表示等待運行的任務(進程)數量。
在Linux系統中磕洪,這些數字包含等待CPU運行的進程數吭练,也包括不間斷I/O阻塞的進程數(通常是磁盤I/O)。
它展示了一個資源負載(或需求)的整體概念析显,但是無法理解其中的內涵鲫咽,在沒有其它工具的情況下。僅僅是一種快速查看手段而已谷异。
這三個數字呈現出平均負載在幾何級減弱分尸,依次表示持續(xù)1分鐘,5分鐘和15分鐘內歹嘹。這三個數字能告訴我們負載在時間線上是如何變化的箩绍。
舉例說明,如果你在一個問題服務器上執(zhí)行檢查尺上,1分鐘的值遠遠低于15分鐘的值材蛛,可以判斷出你也許登錄得太晚了,已經錯過了問題怎抛。
在上面的例子中卑吭,平均負載的數值顯示最近正在上升,1分鐘值高達30马绝,對比15分鐘值則是19陨簇。這些指標值像現在這么大意味著很多情況:也許是CPU繁忙;vmstat 或者 mpstat 將可以確認迹淌,本系列的第三和第四條命令。
2. dmesg | tail
$ dmesg | tail
[1880957.563150] perl invoked oom-killer: gfp_mask=0x280da, order=0, oom_score_adj=0
[...]
[1880957.563400] Out of memory: Kill process 18694 (perl) score 246 or sacrifice child
[1880957.563408] Killed process 18694 (perl) total-vm:1972392kB, anon-rss:1953348kB, file-r
ss:0kB
[2320864.954447] TCP: Possible SYN flooding on port 7001. Dropping request. Check SNMP cou
nters.
這個結果輸出了最近10條系統信息己单。
可以查看到引起性能問題的錯誤唉窃。上面的例子包含了oom-killer,以及TCP丟包。
PS:這個真的很容易忽略啊纹笼,真真的踩過坑N品荨! 另外,除了error級的日志蔓涧,info級的也要留個心眼件已,可能包含一些隱藏信息。
[譯者注:oom-killer]
一層保護機制元暴,用于避免 Linux 在內存不足的時候不至于出太嚴重的問題篷扩,把無關緊要的進程殺掉,有些壯士斷腕的意思
3. vmstat 1
$ vmstat 1
procs ---------memory---------- ---swap-- -----io---- -system-- ------cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
34 0 0 200889792 73708 591828 0 0 0 5 6 10 96 1 3 0 0
32 0 0 200889920 73708 591860 0 0 0 592 13284 4282 98 1 1 0 0
32 0 0 200890112 73708 591860 0 0 0 0 9501 2154 99 1 0 0 0
32 0 0 200889568 73712 591856 0 0 0 48 11900 2459 99 0 0 0 0
32 0 0 200890208 73712 591860 0 0 0 0 15898 4840 98 1 1 0 0
vmstat 是一個獲得虛擬內存狀態(tài)概況的通用工具(最早創(chuàng)建于10年前的BSD)茉盏。它每一行記錄了關鍵的服務器統計信息鉴未。
vmstat 運行的時候有一個參數1,用于輸出一秒鐘的概要數據鸠姨。
第一行輸出顯示啟動之后的平均值铜秆,用以替代之前的一秒鐘數據。
現在讶迁,跳過第一行连茧,讓我們來學習并且記住每一列代表的意義。
r:正在CPU上運行或等待運行的進程數巍糯。
相對于平均負載來說啸驯,這提供了一個更好的、用于查明CPU飽和度的指標鳞贷,它不包括I/O負載坯汤。注: “r”值大于CPU數即是飽和。
free: 空閑內存(kb)
如果這個數值很大搀愧,表明你還有足夠的內存空閑惰聂。
包括命令7“free m”,很好地展現了空閑內存的狀態(tài)咱筛。
si, so: swap入/出搓幌。
如果這個值非0,證明內存溢出了迅箩。
us, sy, id, wa, st:
它們是CPU分類時間溉愁,針對所有CPU的平均訪問。
分別是用戶時間饲趋,系統時間(內核)拐揭,空閑,I/O等待時間奕塑,以及被偷走的時間(其它訪客堂污,或者是Xen)。CPU分類時間將可以幫助確認龄砰,CPU是否繁忙盟猖,通過累計用戶系統時間讨衣。
等待I/O的情形肯定指向的是磁盤瓶頸;這個時候CPU通常是空閑的式镐,因為任務被阻塞以等待分配磁盤I/O反镇。你可以將等待I/O當作另一種CPU空閑,一種它們?yōu)槭裁纯臻e的解釋線索娘汞。
系統時間對I/O處理非常必要歹茶。一個很高的平均系統時間,超過20%价说,值得深入分析:也許是內核處理I/O非常低效辆亏。
在上面的例子中,CPU時間幾乎完全是用戶級的鳖目,與應用程序級的利用率正好相反扮叨。所有CPU的平均利用率也超過90%。這不一定是一個問題领迈;還需檢查“r”列的飽和度彻磁。
4. mpstat P ALL 1
$ mpstat -P ALL 1
Linux 3.13.0-49-generic (titanclusters-xxxxx) 07/14/2015 _x86_64_ (32 CPU)
07:38:49 PM CPU %usr %nice %sys %iowait %irq %soft %steal %guest %gnice %idle
07:38:50 PM all 98.47 0.00 0.75 0.00 0.00 0.00 0.00 0.00 0.00 0.78
07:38:50 PM 0 96.04 0.00 2.97 0.00 0.00 0.00 0.00 0.00 0.00 0.99
07:38:50 PM 1 97.00 0.00 1.00 0.00 0.00 0.00 0.00 0.00 0.00 2.00
07:38:50 PM 2 98.00 0.00 1.00 0.00 0.00 0.00 0.00 0.00 0.00 1.00
07:38:50 PM 3 96.97 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 3.03
[...]
這個命令可以按時間線打印每個CPU的消耗,常常用于檢查不均衡的問題狸捅。
如果只有一個繁忙的CPU衷蜓,可以判斷是屬于單進程的應用程序。
5. pidstat 1
$ pidstat 1
Linux 3.13.0-49-generic (titanclusters-xxxxx) 07/14/2015 _x86_64_ (32 CPU)
07:41:02 PM UID PID %usr %system %guest %CPU CPU Command
07:41:03 PM 0 9 0.00 0.94 0.00 0.94 1 rcuos/0
07:41:03 PM 0 4214 5.66 5.66 0.00 11.32 15 mesos-slave
07:41:03 PM 0 4354 0.94 0.94 0.00 1.89 8 java
07:41:03 PM 0 6521 1596.23 1.89 0.00 1598.11 27 java
07:41:03 PM 0 6564 1571.70 7.55 0.00 1579.25 28 java
07:41:03 PM 60004 60154 0.94 4.72 0.00 5.66 9 pidstat
07:41:03 PM UID PID %usr %system %guest %CPU CPU Command
07:41:04 PM 0 4214 6.00 2.00 0.00 8.00 15 mesos-slave
07:41:04 PM 0 6521 1590.00 1.00 0.00 1591.00 27 java
07:41:04 PM 0 6564 1573.00 10.00 0.00 1583.00 28 java
07:41:04 PM 108 6718 1.00 0.00 0.00 1.00 0 snmp-pass
07:41:04 PM 60004 60154 1.00 4.00 0.00 5.00 9 pidstat
^C
pidstat 有一點像頂級視圖-針對每一個進程尘喝,但是輸出的時候滾屏磁浇,而不是清屏。
它非常有用朽褪,特別是跨時間段查看的模式置吓,也能將你所看到的信息記錄下來,以利于進一步的研究缔赠。
上面的例子識別出兩個 java 進程引起的CPU耗盡衍锚。
“%CPU” 是對所有CPU的消耗;1591% 顯示 java 進程占用了幾乎16個CPU嗤堰。
6. iostat xz 1
$ iostat -xz 1
Linux 3.13.0-49-generic (titanclusters-xxxxx) 07/14/2015 _x86_64_ (32 CPU)
avg-cpu: %user %nice %system %iowait %steal %idle
73.96 0.00 3.73 0.03 0.06 22.21
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util
xvda 0.00 0.23 0.21 0.18 4.52 2.08 34.37 0.00 9.98 13.80 5.42 2.44 0.09
xvdb 0.01 0.00 1.02 8.94 127.97 598.53 145.79 0.00 0.43 1.78 0.28 0.25 0.25
xvdc 0.01 0.00 1.02 8.86 127.79 595.94 146.50 0.00 0.45 1.82 0.30 0.27 0.26
dm-0 0.00 0.00 0.69 2.32 10.47 31.69 28.01 0.01 3.23 0.71 3.98 0.13 0.04
dm-1 0.00 0.00 0.00 0.94 0.01 3.78 8.00 0.33 345.84 0.04 346.81 0.01 0.00
dm-2 0.00 0.00 0.09 0.07 1.35 0.36 22.50 0.00 2.55 0.23 5.62 1.78 0.03
[...]
這是一個理解塊設備(磁盤)極好的工具戴质,不論是負載評估還是作為性能測試成績。
r/s, w/s, rkB/s, wkB/s: 這些是該設備每秒讀%踢匣、寫%告匠、讀Kb、寫Kb离唬≠旌#可用于描述工作負荷。一個性能問題可能只是簡單地由于一個過量的負載引起男娄。
await: I/O平均時間(毫秒)
這是應用程序需要的時間,它包括排隊以及運行的時間。
遠遠大于預期的平均時間可以作為設備飽和模闲,或者設備問題的指標建瘫。
avgqu-sz: 向設備發(fā)出的平均請求數。
值大于1可視為飽和(盡管設備能對請求持續(xù)運行尸折,特別是前端的虛擬設備-后端有多個磁盤)啰脚。
%util: 設備利用率
這是一個實時的繁忙的百分比,顯示設備每秒鐘正在進行的工作实夹。
值大于60%屬于典型的性能不足(可以從await處查看)橄浓,盡管它取決于設備。
值接近100% 通常指示飽和亮航。
如果存儲設備是一個前端邏輯磁盤荸实、后掛一堆磁盤,那么100%的利用率也許意味著缴淋,一些已經處理的I/O此時占用100%准给,然而,后端的磁盤也許遠遠沒有達到飽和重抖,其實可以承擔更多的工作露氮。
切記:磁盤I/O性能低并不一定是應用程序問題。許多技術一貫使用異步I/O钟沛,所以應用程序并不會阻塞畔规,以及遭受直接的延遲(例如提前加載,緩沖寫入)恨统。
7. free m
$ free -m
total used free shared buffers cached
Mem: 245998 24545 221453 83 59 541
-/+ buffers/cache: 23944 222053
Swap: 0 0 0
buffers: buffer cache,用于塊設備I/O叁扫。
cached:page cache, 用于文件系統。
我們只是想檢查這些指標值不為0延欠,那樣意味著磁盤I/O高陌兑、性能差(確認需要用iostat)。
上面的例子看起來不錯由捎,每一個都有很多Mbytes兔综。
“-/+ buffers/cache”: 提供了關于內存利用率更加準確的數值。
Linux可以將空閑內存用于緩存狞玛,并且在應用程序需要的時候收回软驰。
所以應用到緩存的內存必須以另一種方式包括在內存空閑的數據里面。
甚至有一個網站linux ate my ram,專門探討這個困惑心肪。
它還有更令人困惑的地方锭亏,如果在Linux上使用ZFS,正如我們運行一些服務,ZFS擁有自己的文件系統混存硬鞍,也不能在free -m 的輸出里正確反映慧瘤。
這種情況會顯示系統空閑內存不足戴已,但是內存實際上可用,通過回收 ZFS 的緩存锅减。
8. sar n DEV 1
$ sar -n DEV 1
Linux 3.13.0-49-generic (titanclusters-xxxxx) 07/14/2015 _x86_64_ (32 CPU)
12:16:48 AM IFACE rxpck/s txpck/s rxkB/s txkB/s rxcmp/s txcmp/s rxmcst/s %ifutil
12:16:49 AM eth0 18763.00 5032.00 20686.42 478.30 0.00 0.00 0.00 0.00
12:16:49 AM lo 14.00 14.00 1.36 1.36 0.00 0.00 0.00 0.00
12:16:49 AM docker0 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
12:16:49 AM IFACE rxpck/s txpck/s rxkB/s txkB/s rxcmp/s txcmp/s rxmcst/s %ifutil
12:16:50 AM eth0 19763.00 5101.00 21999.10 482.56 0.00 0.00 0.00 0.00
12:16:50 AM lo 20.00 20.00 3.25 3.25 0.00 0.00 0.00 0.00
12:16:50 AM docker0 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
^C
使用這個工具用來檢查網絡接口吞吐量:
rxkB/s 和** txkB/s**, 作為負載的一種度量方式, 也可以用來檢查是否已經達到某種瓶頸糖儡。
在上面的例子中,網卡 eth0 收包大道 22 Mbytes/s, 即176 Mbits/sec (就是說怔匣,在 1 Gbit/sec 的限制之內)握联。
此版本也有一個體現設備利用率的 “%ifutil” (兩個方向最大值),我們也可以使用 Brendan的 nicstat 工具來度量每瞒。
和 nicstat 類似金闽,這個值很難準確獲取,看起來在這個例子中并沒有起作用(0.00)剿骨。
9. sar n TCP,ETCP 1
$ sar -n TCP,ETCP 1
Linux 3.13.0-49-generic (titanclusters-xxxxx) 07/14/2015 _x86_64_ (32 CPU)
12:17:19 AM active/s passive/s iseg/s oseg/s
12:17:20 AM 1.00 0.00 10233.00 18846.00
12:17:19 AM atmptf/s estres/s retrans/s isegerr/s orsts/s
12:17:20 AM 0.00 0.00 0.00 0.00 0.00
12:17:20 AM active/s passive/s iseg/s oseg/s
12:17:21 AM 1.00 0.00 8359.00 6039.00
12:17:20 AM atmptf/s estres/s retrans/s isegerr/s orsts/s
12:17:21 AM 0.00 0.00 0.00 0.00 0.00
^C
這是一個關鍵TCP指標的概覽視圖代芜。包括:
active/s: 本地初始化的 TCP 連接數 /每秒(例如,通過connect() )
passive/s: 遠程初始化的 TCP 連接數/每秒(例如懦砂,通過accept() )
retrans/s: TCP重發(fā)數/每秒
這些活躍和被動的計數器常常作為一種粗略的服務負載度量方式:新收到的連接數 (被動的),以及下行流量的連接數 (活躍的)蜒犯。
這也許能幫助我們理解,活躍的都是外向的荞膘,被動的都是內向的罚随,但是嚴格來說這種說法是不準確的(例如,考慮到“本地-本地”的連接)羽资。
重發(fā)數是網絡或服務器問題的一個標志淘菩;它也許是因為不可靠的網絡(如,公共互聯網)屠升,也許是由于一臺服務器已經超負荷潮改、發(fā)生丟包。
上面的例子顯示每秒鐘僅有一個新的TCP連接腹暖。
10. top
$ top
top - 00:15:40 up 21:56, 1 user, load average: 31.09, 29.87, 29.92
Tasks: 871 total, 1 running, 868 sleeping, 0 stopped, 2 zombie
%Cpu(s): 96.8 us, 0.4 sy, 0.0 ni, 2.7 id, 0.1 wa, 0.0 hi, 0.0 si, 0.0 st
KiB Mem: 25190241+total, 24921688 used, 22698073+free, 60448 buffers
KiB Swap: 0 total, 0 used, 0 free. 554208 cached Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
20248 root 20 0 0.227t 0.012t 18748 S 3090 5.2 29812:58 java
4213 root 20 0 2722544 64640 44232 S 23.5 0.0 233:35.37 mesos-slave
66128 titancl+ 20 0 24344 2332 1172 R 1.0 0.0 0:00.07 top
5235 root 20 0 38.227g 547004 49996 S 0.7 0.2 2:02.74 java
4299 root 20 0 20.015g 2.682g 16836 S 0.3 1.1 33:14.42 java
1 root 20 0 33620 2920 1496 S 0.0 0.0 0:03.82 init
2 root 20 0 0 0 0 S 0.0 0.0 0:00.02 kthreadd
3 root 20 0 0 0 0 S 0.0 0.0 0:05.35 ksoftirqd/0
5 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kworker/0:0H
6 root 20 0 0 0 0 S 0.0 0.0 0:06.94 kworker/u256:0
8 root 20 0 0 0 0 S 0.0 0.0 2:38.05 rcu_sched
top命令包含了許多我們之前已經檢查的指標汇在。
它可以非常方便地運行,看看是否任何東西看起來與從前面的命令的結果完全不同脏答,可以表明負載指標是不斷變化的糕殉。
頂部下面的輸出,很難按照時間推移的模式查看殖告,可能使用如 vmstat 和 pidstat 等工具會更清晰阿蝶,它們提供滾動輸出。
如果你保持輸出的動作不夠快 (CtrlS 要暫停黄绩,CtrlQ 繼續(xù))羡洁,屏幕將清除,間歇性問題的證據也會丟失爽丹。
追蹤分析
你還可以嘗試更多筑煮、更深的命令和方法辛蚊。
詳見Brendan的 Linux 性能工具輔導課,包括40多種命令咆瘟,覆蓋可觀測性嚼隘、標桿管理、調優(yōu)袒餐、靜態(tài)性能優(yōu)化、監(jiān)視和追蹤谤狡。
基于可擴展的web灸眼,解決系統的擴展和性能問題,是我們矢志不渝的追求墓懂。
如果你希望能夠解決這類挑戰(zhàn)焰宣,加入我們!
Brendan Gregg
以下為原文:
Linux Performance Analysis in 60,000 Milliseconds
You login to a Linux server with a performance issue:
what do you check in the first minute?
At Netflix we have a massive EC2 Linux cloud, and numerous performance analysis tools to monitor and investigate its performance.
These include Atlas for cloud-wide monitoring, and Vector for on-demand instance analysis.
While those tools help us solve most issues, we sometimes need to login to an instance and run some standard Linux performance tools.
In this post, the Netflix Performance Engineering team will show you the first 60 seconds of an optimized performance investigation at the command line, using standard Linux tools you should have available.
First 60 Seconds: Summary
In 60 seconds you can get a high level idea of system resource usage and running processes by running the following ten commands.
Look for errors and saturation metrics, as they are both easy to interpret, and then resource utilization.
Saturation is where a resource has more load than it can handle, and can be exposed either as the length of a request queue, or time spent waiting.
uptime
dmesg | tail vmstat 1
mpstat -P ALL 1 pidstat 1
iostat -xz 1 free -m
sar -n DEV 1
sar -n TCP,ETCP 1 top
Some of these commands require the sysstat package installed.
The metrics these commands expose will help you complete some of the USE Method: a methodology for locating performance bottlenecks.
This involves checking utilization, saturation, and error metrics for all resources (CPUs, memory, disks, e.t.c.).
Also pay attention to when you have checked and exonerated a resource, as by process of elimination this narrows the targets to study, and directs any follow on investigation.
The following sections summarize these commands, with examples from a production system. For more information about these tools, see their man pages.
1. uptime
$ uptime
23:51:26up21:31, 1user, loadaverage:30.02,26.43,19.02
This is a quick way to view the load averages, which indicate the number of tasks (processes) wanting to run. On Linux systems, these numbers include processes wanting to run on CPU, as well as processes blocked in uninterruptible I/O (usually disk I/O).
This gives a high level idea of resource load (or demand), but can’t be properly understood without other tools.
Worth a quick look only.
The three numbers are exponentially damped moving sum averages with a 1 minute, 5 minute, and 15 minute constant.
The three numbers give us some idea of how load is changing over time.
For example, if you’ve been asked to check a problem server, and the 1 minute value is much lower than the 15 minute value, then you might have logged in too late and missed the issue.
In the example above, the load averages show a recent increase, hitting 30 for the 1 minute value, compared to 19 for the 15 minute value.
That the numbers are this large means a lot of something: probably CPU demand; vmstat or mpstat will confirm, which are commands 3 and 4 in this sequence.
2. dmesg | tail
$ dmesg | tail
[1880957.563150] perl invoked oom-killer: gfp_mask=0x280da, order=0, oom_score_adj=0
[...]
[1880957.563400] Out of memory: Kill process 18694 (perl) score 246 or sacrifice child
[1880957.563408] Killed process 18694 (perl) total-vm:1972392kB, anon-rss:1953348kB, file-r
ss:0kB
[2320864.954447] TCP: Possible SYN flooding on port 7001. Dropping request. Check SNMP cou
nters.
This views the last 10 system messages, if there are any.
Look for errors that can cause performance issues.
The example above includes the oom-killer, and TCP dropping a request.
Don’t miss this step! dmesg is always worth checking.
3. vmstat 1
$ vmstat 1
procs ---------memory---------- ---swap-- -----io---- -system-- ------cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
34 0 0 200889792 73708 591828 0 0 0 5 6 10 96 1 3 0 0
32 0 0 200889920 73708 591860 0 0 0 592 13284 4282 98 1 1 0 0
32 0 0 200890112 73708 591860 0 0 0 0 9501 2154 99 1 0 0 0
32 0 0 200889568 73712 591856 0 0 0 48 11900 2459 99 0 0 0 0
32 0 0 200890208 73712 591860 0 0 0 0 15898 4840 98 1 1 0 0
Short for virtual memory stat, vmstat(8) is a commonly available tool (first created for BSD decades ago).
It prints a summary of key server statistics on each line.
vmstat was run with an argument of 1, to print one second summaries.
The first line of output (in this version of vmstat) has some columns that show the average since boot, instead of the previous second.
For now, skip the first line, unless you want to learn and remember which column is which. Columns to check:
r:
Number of processes running on CPU and waiting for a turn.
This provides a better signal than load averages for determining CPU saturation, as it does not include I/O.
To interpret: an “r” value greater than the CPU count is saturation.
free: Free memory in kilobytes.
If there are too many digits to count, you have enough free memory.
The “free -m” command, included as command 7, better explains the state of free memory.
si, so:
Swap-ins and swap-outs. If these are non-zero, you’re out of memory.
us, sy, id, wa, st:
These are breakdowns of CPU time, on average across all CPUs.
They are user time, system time (kernel), idle, wait I/O,
and stolen time (by other guests, or with Xen, the guest's own isolated driver domain).
The CPU time breakdowns will confirm if the CPUs are busy, by adding user + system time.
A constant degree of wait I/O points to a disk bottleneck;
this is where the CPUs are idle, because tasks are blocked waiting for pending disk I/O. You can treat wait I/O as another form of CPU idle, one that gives a clue as to why they are idle.
System time is necessary for I/O processing.
A high system time average, over 20%, can be interesting to explore further: perhaps the kernel is processing the I/O inefficiently.
In the above example, CPU time is almost entirely in user-level, pointing to application level usage instead.
The CPUs are also well over 90% utilized on average.
This isn’t necessarily a problem; check for the degree of saturation using the “r” column.
4. mpstat -P ALL 1
$ mpstat -P ALL 1
Linux 3.13.0-49-generic (titanclusters-xxxxx) 07/14/2015 _x86_64_ (32 CPU)
07:38:49 PM CPU %usr %nice %sys %iowait %irq %soft %steal %guest %gnice %idle
07:38:50 PM all 98.47 0.00 0.75 0.00 0.00 0.00 0.00 0.00 0.00 0.78
07:38:50 PM 0 96.04 0.00 2.97 0.00 0.00 0.00 0.00 0.00 0.00 0.99
07:38:50 PM 1 97.00 0.00 1.00 0.00 0.00 0.00 0.00 0.00 0.00 2.00
07:38:50 PM 2 98.00 0.00 1.00 0.00 0.00 0.00 0.00 0.00 0.00 1.00
07:38:50 PM 3 96.97 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 3.03
[...]
This command prints CPU time breakdowns per CPU, which can be used to check for an imbalance.
A single hot CPU can be evidence of a single-threaded application.
5. pidstat 1
$ pidstat 1
Linux 3.13.0-49-generic (titanclusters-xxxxx) 07/14/2015 _x86_64_ (32 CPU)
07:41:02 PM UID PID %usr %system %guest %CPU CPU Command
07:41:03 PM 0 9 0.00 0.94 0.00 0.94 1 rcuos/0
07:41:03 PM 0 4214 5.66 5.66 0.00 11.32 15 mesos-slave
07:41:03 PM 0 4354 0.94 0.94 0.00 1.89 8 java
07:41:03 PM 0 6521 1596.23 1.89 0.00 1598.11 27 java
07:41:03 PM 0 6564 1571.70 7.55 0.00 1579.25 28 java
07:41:03 PM 60004 60154 0.94 4.72 0.00 5.66 9 pidstat
07:41:03 PM UID PID %usr %system %guest %CPU CPU Command
07:41:04 PM 0 4214 6.00 2.00 0.00 8.00 15 mesos-slave
07:41:04 PM 0 6521 1590.00 1.00 0.00 1591.00 27 java
07:41:04 PM 0 6564 1573.00 10.00 0.00 1583.00 28 java
07:41:04 PM 108 6718 1.00 0.00 0.00 1.00 0 snmp-pass
07:41:04 PM 60004 60154 1.00 4.00 0.00 5.00 9 pidstat
^C
Pidstat is a little like top’s per-process summary, but prints a rolling summary instead of clearing the screen.
This can be useful for watching patterns over time, and also recording what you saw (copy-n-paste) into a record of your investigation.
The above example identifies two java processes as responsible for consuming CPU.
The %CPU column is the total across all CPUs; 1591% shows that that java processes is consuming almost 16 CPUs.
6. iostat -xz 1
$ iostat -xz 1
Linux 3.13.0-49-generic (titanclusters-xxxxx) 07/14/2015 _x86_64_ (32 CPU)
avg-cpu: %user %nice %system %iowait %steal %idle
73.96 0.00 3.73 0.03 0.06 22.21
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util
xvda 0.00 0.23 0.21 0.18 4.52 2.08 34.37 0.00 9.98 13.80 5.42 2.44 0.09
xvdb 0.01 0.00 1.02 8.94 127.97 598.53 145.79 0.00 0.43 1.78 0.28 0.25 0.25
xvdc 0.01 0.00 1.02 8.86 127.79 595.94 146.50 0.00 0.45 1.82 0.30 0.27 0.26
dm-0 0.00 0.00 0.69 2.32 10.47 31.69 28.01 0.01 3.23 0.71 3.98 0.13 0.04
dm-1 0.00 0.00 0.00 0.94 0.01 3.78 8.00 0.33 345.84 0.04 346.81 0.01 0.00
dm-2 0.00 0.00 0.09 0.07 1.35 0.36 22.50 0.00 2.55 0.23 5.62 1.78 0.03
[...]
This is a great tool for understanding block devices (disks), both the workload applied and the resulting performance.
Look for:
r/s, w/s, rkB/s, wkB/s:
These are the delivered reads, writes, read Kbytes, and write Kbytes per second to the device.
Use these for workload characterization.
A performance problem may simply be due to an excessive load applied.
await:
The average time for the I/O in milliseconds.
This is the time that the application suffers, as it includes both time queued and time being serviced. Larger than expected average times can be an indicator of device saturation, or device problems.
avgqu-sz:
The average number of requests issued to the device. Values greater than 1 can be evidence of saturation (although devices can typically operate on requests in parallel, especially virtual devices which front multiple back-end disks.)
%util:
Device utilization.
This is really a busy percent, showing the time each second that the device was doing work. Values greater than 60% typically lead to poor performance (which should be seen in await), although it depends on the device.
Values close to 100% usually indicate saturation.
If the storage device is a logical disk device fronting many back-end disks, then 100% utilization may just mean that some I/O is being processed 100% of the time, however, the back-end disks may be far from saturated, and may be able to handle much more work.
Bear in mind that poor performing disk I/O isn’t necessarily an application issue.
Many techniques are typically used to perform I/O asynchronously, so that the application doesn’t block and suffer the latency directly (e.g., read-ahead for reads, and buffering for writes).
7. free -m
$ free -m
total used free shared buffers cached
Mem: 245998 24545 221453 83 -/+ buffers/cache: 23944 222053
Swap: 0 0 0
The right two columns show:
buffers: For the buffer cache, used for block device I/O.
cached: For the page cache, used by file systems.
We just want to check that these aren’t near-zero in size, which can lead to higher disk I/O (confirm using iostat), and worse performance. The above example looks fine, with many Mbytes in each.
The “-/+ buffers/cache” provides less confusing values for used and free memory. Linux uses free memory for the caches, but can reclaim it quickly if applications need it. So in a way the cached memory should be included in the free memory column, which this line does. There’s even a website, linuxatemyram, about this confusion.
It can be additionally confusing if ZFS on Linux is used, as we do for some services, as ZFS has its own file system cache that isn’t reflected properly by the free -m columns. It can appear that the system is low on free memory, when that memory is in fact available for use from the ZFS cache as needed.
8. sar -n DEV 1
$ sar -n DEV 1
Linux 3.13.0-49-generic (titanclusters-xxxxx) 07/14/2015 _x86_64_ (32 CPU)
12:16:48 AM IFACE rxpck/s txpck/s rxkB/s txkB/s rxcmp/s txcmp/s rxmcst/s %ifutil
12:16:49 AM eth0 18763.00 5032.00 20686.42 478.30 0.00 0.00 0.00 0.00
12:16:49 AM lo 14.00 14.00 1.36 1.36 0.00 0.00 0.00 0.00
12:16:49 AM docker0 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
12:16:49 AM IFACE rxpck/s txpck/s rxkB/s txkB/s rxcmp/s txcmp/s rxmcst/s %ifutil
12:16:50 AM eth0 19763.00 5101.00 21999.10 482.56 0.00 0.00 0.00 0.00
12:16:50 AM lo 20.00 20.00 3.25 3.25 0.00 0.00 0.00 0.00
12:16:50 AM docker0 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
^C
Use this tool to check network interface throughput:
rxkB/s and txkB/s, as a measure of workload, and also to check if any limit has been reached.
In the above example, eth0 receive is reaching 22 Mbytes/s, which is 176 Mbits/sec (well under, say, a 1 Gbit/sec limit).
This version also has %ifutil for device utilization (max of both directions for full duplex), which is something we also use Brendan’s nicstat tool to measure. And like with nicstat, this is hard to get right, and seems to not be working in this example (0.00).
9. sar -n TCP,ETCP 1
$ sar -n TCP,ETCP 1
Linux 3.13.0-49-generic (titanclusters-xxxxx) 07/14/2015 _x86_64_ (32 CPU)
12:17:19 AM active/s passive/s iseg/s oseg/s
12:17:20 AM 1.00 0.00 10233.00 18846.00
12:17:19 AM atmptf/s estres/s retrans/s isegerr/s orsts/s
12:17:20 AM 0.00 0.00 0.00 0.00 0.00
12:17:20 AM active/s passive/s iseg/s oseg/s
12:17:21 AM 1.00 0.00 8359.00 6039.00
12:17:20 AM atmptf/s estres/s retrans/s isegerr/s orsts/s
12:17:21 AM 0.00 0.00 0.00 0.00 0.00
^C
active/s: Number of locally-initiated TCP connections per second (e.g., via connect()).
passive/s: Number of remotely-initiated TCP connections per second (e.g., via accept()).
retrans/s: Number of TCP retransmits per second.
The active and passive counts are often useful as a rough measure of server load: number of new accepted connections (passive), and number of downstream connections (active).
It might help to think of active as outbound, and passive as inbound, but this isn’t strictly true (e.g., consider a localhost to localhost connection).
Retransmits are a sign of a network or server issue; it may be an unreliable network (e.g., the public Internet), or it may be due a server being overloaded and dropping packets. The example above shows just one new TCP connection per-second.
10. top
$ top
top - 00:15:40 up 21:56, 1 user, load average: 31.09, 29.87, 29.92
Tasks: 871 total, 1 running, 868 sleeping, 0 stopped, 2 zombie
%Cpu(s): 96.8 us, 0.4 sy, 0.0 ni, 2.7 id, 0.1 wa, 0.0 hi, 0.0 si, 0.0 st
KiB Mem: 25190241+total, 24921688 used, 22698073+free, 60448 buffers
KiB Swap: 0 total, 0 used, 0 free. 554208 cached Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
20248 root 20 0 0.227t 0.012t 18748 S 3090 5.2 29812:58 java
4213 root 20 0 2722544 64640 44232 S 23.5 0.0 233:35.37 mesos-slave
66128 titancl+ 20 0 24344 2332 1172 R 1.0 0.0 0:00.07 top
5235 root 20 0 38.227g 547004 49996 S 0.7 0.2 2:02.74 java
4299 root 20 0 20.015g 2.682g 16836 S 0.3 1.1 33:14.42 java
1 root 20 0 33620 2920 1496 S 0.0 0.0 0:03.82 init
2 root 20 0 0 0 0 S 0.0 0.0 0:00.02 kthreadd
3 root 20 0 0 0 0 S 0.0 0.0 0:05.35 ksoftirqd/0
5 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kworker/0:0H
6 root 20 0 0 0 0 S 0.0 0.0 0:06.94 kworker/u256:0
8 root 20 0 0 0 0 S 0.0 0.0 2:38.05 rcu_sched
The top command includes many of the metrics we checked earlier.
It can be handy to run it to see if anything looks wildly different from the earlier commands, which would indicate that load is variable.
A downside to top is that it is harder to see patterns over time, which may be more clear in tools like vmstat and pidstat, which provide rolling output.
Evidence of intermittent issues can also be lost if you don’t pause the output quick enough (Ctrl-S to pause, Ctrl-Q to continue), and the screen clears.
Follow-on Analysis
There are many more commands and methodologies you can apply to drill deeper.
See Brendan’s Linux Performance Tools tutorial from Velocity 2015, which works through over 40 commands, covering observability, benchmarking, tuning, static performance tuning, profiling, and tracing.
Tackling system reliability and performance problems at web scale is one of our passions.
If you would like to join us in tackling these kinds of challenges we are hiring!
Posted by Brendan Gregg