Linux下定位異常消耗的線程實戰(zhàn)分析
前言:
之前分享過一篇Linux開發(fā)coredump文件分析實戰(zhàn)分享 ,今天再來分享一篇實戰(zhàn)文章。
在我們嵌入式linux開發(fā)過程中,開發(fā)過程中我們經(jīng)常會使用多進程、多線程開發(fā)。那么多線程使用過程中,我們大概率會遇到某線程長時間占用cpu,導致設備執(zhí)行異常。
通常只有四五個線程,我們可以通過一個個線程調(diào)試捕捉到異常線程,如果你開發(fā)的設備上面運行了大概三四十個線程,我們一下子不好看到對應哪個線程出問題,也不好使用列舉法進行搜索,這個時候我們需要配合一些工具進行監(jiān)控以及檢查我們執(zhí)行的進程下面的線程。下面我就給大家介紹一下我自己工作中實際遇到的例子。
情節(jié)介紹:
在工作中,我遇到這樣一個問題,我的設備跑機的時候發(fā)現(xiàn),機器運行某些狀態(tài)時候有些怪異,對于某些機制的處理響應不夠及時,最后top檢查,發(fā)現(xiàn)是我運行的某個進程中的某幾個線程運行cpu占有率很高,導致其他的一些線程無法及時運行。
找到問題了,接下來我們就開始找對應的線程然后進行修改,前文提到,進程里面有一兩個線程還好說,我們可以通過一些比較基礎的方法,一個個線程進行l(wèi)og或者其他手段的信息輸出,但是如果我們遇到單個進程里面有很多線程的時候,我們?nèi)绾螜z查呢?
初步列一個使用的工具大綱:ps 組合命令、top組合命令、pstack、strace、ltrace、gdb attach
以上就是我使用到的一些命令和操作,接下來一一給大家進行分析和介紹:
首先給大家介紹每個工具和命令詳細介紹,再用自己的一個小例子把這些工具進行組合使用說明。
工具和組合命令詳細介紹
首先給詳細的介紹一下這些工具說明書:
ps 的選項參數(shù)介紹:
ps命令大家在linux使用應該是很熟悉的,ps是Process Status的縮寫,用來列出系統(tǒng)中當前運行的進程。使用該命令可以確定有哪些進程正在運行和運行的狀態(tài)、進程是否結(jié)束、進程有沒有僵死、哪些進程占用了過多的資源等等。ps命令所列出的進行是當前進程的快照,也就是并不是動態(tài)的,而是執(zhí)行該命令時那一時刻進行的狀態(tài)。
- ps 的參數(shù)非常多, 在此僅列出幾個常用的參數(shù)并大略介紹含義
- -A 列出所有的進程
- -w 顯示加寬可以顯示較多的資訊
- -au 顯示較詳細的資訊
- -aux 顯示所有包含其他使用者的行程
我一般都是使用 ps -aux進行查看后臺運行的進程pid
下面再進行補充一下今天要使用到的ps組合命令
查看進程對應的線程
- ps -T -p 472 (472 此處為真實進程的pid大家自行替換)
第一行是對應的進程ID,第二行是對應的線程ID
查看進程對應線程的執(zhí)行時間
- ps -eLo pid,lwp,pcpu |grep 1780(1780 此處為真實進程的pid大家自行替換)
第一行是進程pid,第二行是進程里面線程對應的pid,第三行是該線程執(zhí)行ms時間,通過線程執(zhí)行時間長度,我們配合該線程的堆棧信息,線程頻繁執(zhí)行IO操作或者線程頻繁執(zhí)行的庫函數(shù)來判斷該線程是否錯誤占用cpu資源。
top組合命令介紹:
top命令也是大家熟悉的一個命令,可以顯示當前系統(tǒng)正在執(zhí)行的進程的相關信息,包括進程ID、內(nèi)存占用率、CPU占用率等。同時也可以對指定進程發(fā)送一個信號。
- -b 批處理
- -c 顯示完整的信息
- -I 忽略失效過程
- -s 保密模式
- -S 累積模式
- -i<時間> 設置間隔時間
- -u<用戶名> 指定用戶名
- -p<進程號> 指定進程
- -n<次數(shù)> 循環(huán)顯示的次數(shù)
首先我們一般會直接使用top命令,查看進程信息,這里做一下多描述,因為后續(xù)使用strace工具還是使用ltrace工具,是從top命令的cpu信息區(qū)進行確定我們使用具體工具。
- test@test:~# top
- top - 02:32:07 up 17 min, 2 users, load average: 3.17, 3.26, 2.17
- Tasks: 165 total, 3 running, 162 sleeping, 0 stopped, 0 zombie
- %Cpu(s): 31.3 us, 7.0 sy, 0.0 ni, 60.9 id, 0.0 wa, 0.0 hi, 0.9 si, 0.0 st
- MiB Mem : 3845.3 total, 3424.3 free, 240.9 used, 180.1 buff/cache
- MiB Swap: 0.0 total, 0.0 free, 0.0 used. 3566.7 avail Mem
- PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
- 461 root -96 -20 2432536 58472 18888 S 176.5 1.5 18:15.07 ex
- 375 root -2 0 0 0 0 S 5.9 0.0 0:04.23 RTW_RECV_THREAD
- 430 root 20 0 682204 22536 6880 S 5.9 0.6 0:55.69 python
- 16913 root 20 0 0 0 0 S 5.9 0.0 0:02.46 kworker/u12:0
- 22219 root 20 0 3300 2100 1628 R 5.9 0.1 0:00.02 top
- 1 root 20 0 1892 620 556 S 0.0 0.0 0:00.41 init
- 2 root 20 0 0 0 0 S 0.0 0.0 0:00.01 kthreadd
- 3 root 20 0 0 0 0 S 0.0 0.0 0:00.14 ksoftirqd/0
- 5 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kworker/0:0H
- 7 root 20 0 0 0 0 R 0.0 0.0 0:02.24 rcu_sched
- 8 root 20 0 0 0 0 S 0.0 0.0 0:00.00 rcu_bh
- 9 root rt 0 0 0 0 S 0.0 0.0 0:00.16 migration/0
- 10 root rt 0 0 0 0 S 0.0 0.0 0:00.00 watchdog/0
top顯示的統(tǒng)計信息:
top顯示信息前五行是當前系統(tǒng)情況整體的統(tǒng)計信息區(qū)。這部分統(tǒng)計信息的解釋參考文章《top命令》:
第一行,任務隊列信息,同 uptime 命令的執(zhí)行結(jié)果
- test@test:~# uptime
- 13:46:08 up 1:04, 1 user, load average: 0.00, 0.00, 0.00
具體參數(shù)說明情況如下:
- 02:32:07 — 當前系統(tǒng)時間
- up 17 min, — 系統(tǒng)已經(jīng)運行了17分鐘
- 2 users — 當前有2個用戶終端登錄系統(tǒng)
- load average: 3.17, 3.26, 2.17— load average后面的三個數(shù)分別是1分鐘、5分鐘、15分鐘的負載情況。
load average數(shù)據(jù)是每隔5秒鐘檢查一次活躍的進程數(shù),然后按特定算法計算出的數(shù)值。如果這個數(shù)除以邏輯CPU的數(shù)量,結(jié)果高于5的時候就表明系統(tǒng)在超負荷運轉(zhuǎn)了。
第二行,Tasks — 任務(進程),具體信息說明如下:
- 系統(tǒng)現(xiàn)在共有165個進程,其中處于運行中的有3個,162個在休眠(sleep),stoped狀態(tài)的有0個,zombie狀態(tài)(僵尸)的有0個。
第三行,cpu狀態(tài)信息,具體屬性說明如下:
- 31.3 us — 用戶空間占用CPU的百分比。
- 7.0 sy — 內(nèi)核空間占用CPU的百分比。
- 0.0 ni — 改變過優(yōu)先級的進程占用CPU的百分比
- 60.9 id — 空閑CPU百分比
- 0.0 wa — IO等待占用CPU的百分比
- 0.0 hi — 硬中斷(Hardware IRQ)占用CPU的百分比
- 0.9 si — 軟中斷(Software Interrupts)占用CPU的百分比
- 0.0 st 虛擬機管理程序為另一個處理器(從虛擬機中竊?。┓諘r,虛擬cpu進行非自愿等待所花費的時間
第四行,內(nèi)存狀態(tài),具體信息如下:
- 3845.3 total — 物理內(nèi)存總量(3.8GB)
- 3424.3 free — 空閑內(nèi)存總量(3.2GB)
- 240.9 used — 使用中的內(nèi)存總量(240.9MB)
- 180.1 buff/cache — 緩存的內(nèi)存量 (180M)
第五行,swap交換分區(qū)信息,具體信息說明如下:
- 0.0 total — 交換區(qū)總量(0.0 GB)
- 0.0 free — 空閑交換區(qū)總量(0MB)
- 0.0 used — 使用的交換區(qū)總量(0MB)
- 3566.7 avail Mem — 可使用緩沖的交換區(qū)總量(3.5GB)
第六行,空行。
第七行以下:各進程(任務)的狀態(tài)監(jiān)控,項目列信息說明如下:
- PID — 進程id
- USER — 進程所有者
- PR — 進程優(yōu)先級
- NI — nice值。負值表示高優(yōu)先級,正值表示低優(yōu)先級
- VIRT — 進程使用的虛擬內(nèi)存總量,單位kb。VIRT=SWAP+RES
- RES — 進程使用的、未被換出的物理內(nèi)存大小,單位kb。RES=CODE+DATA
- SHR — 共享內(nèi)存大小,單位kb
- S — 進程狀態(tài)。D=不可中斷的睡眠狀態(tài) R=運行 S=睡眠 T=跟蹤/停止 Z=僵尸進程
- %CPU — 上次更新到現(xiàn)在的CPU時間占用百分比
- %MEM — 進程使用的物理內(nèi)存百分比
- TIME+ — 進程使用的CPU時間總計,單位1/100秒
- COMMAND — 進程名稱(命令名/命令行)
這是top的常規(guī)使用得到的信息,我們一般進行組合使用命令,我一般使用,
- top -Hp 461(461 此處為真實進程的pid大家自行替換)
通過-Hp命令,我可以查看指定進程的線程
其中在統(tǒng)計信息的第三行中,可以看到cpu占用率主要是用戶態(tài)。
那么我們應該最好使用ltrace進行用戶態(tài)庫函數(shù)的調(diào)用查詢。當然strace也可以,但是由于內(nèi)核使用占據(jù)cpu使用率不高,你追蹤到的IO操作應該遠少于用戶態(tài)庫函數(shù)調(diào)用。
pstack 的選項參數(shù)介紹:
pstack 是 Linux 系統(tǒng)下的一個命令行工具,此命令可以顯示指定進程每個線程的堆??煺?,便于排查程序異常和性能評估,此命令允許使用的唯一選項是要檢查的進程的 PID。要是要使用這個包大家需要在所使用的linux lib和斌目錄里面增加該工具。
示例
- sudo pstack 16634(該pid為我自己測試電腦對應的進程 大家使用時候可以自行替換成自己對應的pid)
可以在一段時間內(nèi),多執(zhí)行幾次pstack,若發(fā)現(xiàn)代碼??偸峭T谕粋€位置, 那個位置就需要重點關注,很可能就是出問題的地方;
ltrace 的選項參數(shù)介紹:
ltrace能夠跟蹤進程的庫函數(shù)調(diào)用,它會顯現(xiàn)出調(diào)用了哪個庫函數(shù),而strace則是跟蹤進程的每個系統(tǒng)調(diào)用。ltrace跟蹤進程調(diào)用庫函數(shù)參數(shù)選項有什么?
ltrace 的選項參數(shù)介紹:
- -c 統(tǒng)計庫函數(shù)每次調(diào)用的時間,最后程序退出時打印摘要。
- -C 解碼低級別名稱(內(nèi)核級)為用戶級名稱。
- -d 打印調(diào)試信息。
- -e expr 輸出過濾器,通過表達式,可以過濾掉你不想要的輸出。
- -e printf 表示只查看printf函數(shù)調(diào)。
- -e!printf 表示查看除printf函數(shù)以外的所有函數(shù)調(diào)用。
- -f 跟蹤子進程。
- -o flename 將ltrace的輸出寫入文件filename。
- -p pid 指定要跟蹤的進程pid。
- -r 輸出每一個調(diào)用的相對時間。
- -S 顯示系統(tǒng)調(diào)用。
- -t 在輸出中的每一行前加上時間信息。
- -tt 在輸出中的每一行前加上時間信息,精確到微秒。
- -ttt 在輸出中的每一行前加上時間信息,精確到微秒,而且時間表示為UNIX時間戳。
- -T 顯示每次調(diào)用所花費的時間。
strace 的選項參數(shù)介紹:
strace常用來跟蹤進程執(zhí)行時的系統(tǒng)調(diào)用和所接收的信號。在Linux世界,進程不能直接訪問硬件設備,當進程需要訪問硬件設備(比如讀取磁盤文件,接收網(wǎng)絡數(shù)據(jù)等等)時,必須由用戶態(tài)模式切換至內(nèi)核態(tài)模式,通過系統(tǒng)調(diào)用訪問硬件設備。strace可以跟蹤到一個進程產(chǎn)生的系統(tǒng)調(diào)用,包括參數(shù),返回值,執(zhí)行消耗的時間。
- -f 跟蹤目標進程,以及目標進程創(chuàng)建的所有子進程
- -t 在輸出中的每一行前加上時間信息(-tt 表示微秒級)
- -T 顯示每個系統(tǒng)調(diào)用所耗的時間
通過觀察系統(tǒng)調(diào)用我們可以確認當前程序的行為,分析其消耗的時間、返回值是否正常??梢赃^濾指定的線程號,確認當前線程的行為是否符合預期,如果執(zhí)行命令后完全沒有輸出,那么可以懷疑是否由于網(wǎng)絡、IO等原因?qū)е伦枞虺绦虍a(chǎn)生死鎖。
pstree 的選項參數(shù)介紹:
命令將所有進程以樹狀圖顯示,樹狀圖將會以 pid (如果有指定) 或是以 init 這個基本進程為根 (root),如果有指定使用者 id,則樹狀圖會只顯示該使用者所擁有的進程。要是要使用這個包大家需要在所使用的linux lib和斌目錄里面增加該工具。
- -A: 各進程樹之間的連接以ASCII碼字符來連接
- -U:各進程樹之間的連接以utf8字符來連接,某些終端可能會有錯誤
- -p:同時列出每個進程的PID
- -u: 同時列出每個進程的所屬賬號名稱:
pstree -up 輸出進程和子進程樹形數(shù)據(jù)
kill <sig> <pid>和coredump文件查看線程堆棧:
因為有些時候我們使用的linux環(huán)境下面不一定有很全的工具,例如上面所提到的pstack查看對應的線程,會有其他的一些命令和工具替代,這里我就給大家介紹兩種我使用的方法,用來查看我實際的堆棧和對應的pid線程信息。
- kill -11 461
對應的進程就會 出現(xiàn)Segmentation fault (core dumped)
而我們設置了coredump文件的產(chǎn)生,產(chǎn)生條件里面有段錯誤信號,所以我發(fā)送了11信號給該進程。
如果大家對于自己需要的信號不知道對應的數(shù)字,可以用 kill -l 命令查詢。
至于通過coredump查看對應的堆棧信息,我之前的這篇文章寫的比較全面了,這里就不再過多贅述了,大家可以點擊這篇文章進行查看Linux開發(fā)coredump文件分析實戰(zhàn)分享。
除了使用kill命令殺死指定進程,我們也可以通過top組合命令來殺死進程:首先使用top進入top顯示的信息,其次假如我們選擇好了 461這個進程準備殺死:
先輸入 k 進入top的kill選項
- PID to signal/kill [default pid = 1451]
- PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
- 461 root -96 -20 2081464 28672 17756 S 21.7 1.4 0:07.05 exc
再按照提示輸入 指定pid 461
- PID to signal/kill [default pid = 1451] 461
使用enter 之后,按照提示輸入信號,我選擇了 11( 段錯誤信號)
- Send pid 461 signal [15/sigterm] 11
這個操作等同于 kill -11 461
gdb attach <pid>實時調(diào)試:
這個是gdb中實時調(diào)試的工具,指定進程實時調(diào)試,但是實際中遇到大型代碼,調(diào)試起來太卡了,所以基本不用它實時調(diào)試,我是用來它來進行實時看一些堆棧信息以及查看線程id和實際代碼的匹配。操作也是比較簡單,從上面我們可以獲知你運行的進程的pid,你用gdb attach指定pid就可以進行調(diào)試了。進入之后的操作命令就是gdb調(diào)試的命令。
大家可以看到gdb attach一進來就在最前面顯示對應的lwp線程pid,這個pid和我們用top命令和ps命令以及strace、ltrace打印的pid信息是一致的。通過相同的pid我們就可以知道該進程或者線程下執(zhí)行的具體操作了。
輸入gdb命令 thread apply all bt ,我們就可以看到對應線程的堆棧,通過堆棧的信息,我們就可以反向查找代碼了。下面是一個截取,展示的是lwp 790(線程pid==790)的一個堆棧信息,通過#3 我們可以知道該線程代碼在even_manager.cpp的40行
實戰(zhàn)中的組合使用
通過上面的命令介紹,我們也知道了在linux下我們可以用到哪些工具可以分析我們的異常進程和線程,下面我就通過一個我自己實際遇到的情況,給大家實際介紹一下這些工具的組合使用情況。
首先,我先使用top命令查看我cpu使用情況
這一看,ex進程竟然占用了176%的cpu(我的設備是多核設備),也就是差不多兩個核的cpu被占滿了。此時可以看到主要占用的cpu資源是用戶態(tài)的資源,所以推薦使用ltrace查看,但是我這邊目前設備里面沒有這個包,所以直接使用了strace查看。
接下來我就想知道到底該進程下的哪個線程,以及線程對應的是哪部分代碼,頻繁執(zhí)行了什么操作。
所以我先使用了 top -Hp 461 查看我對應該進程下所有的線程執(zhí)行所占cpu的百分比。
也可以使用 ps -T -p 461 查看進程對應的線程pid信息
ps -eLo pid,lwp,pcpu |grep 461 查看線程執(zhí)行消耗的時間
strace -p 461 -f進行查看該進程下執(zhí)行了內(nèi)核交互函數(shù)最多執(zhí)行的部分
最左邊的部分就是對應的執(zhí)行IO函數(shù)下的線程PID,我們同時可以直接指定線程pid進行查詢線程的操作,例如我們看到線程845在讀fd為13的一個設備,我們可以單獨strace -p 845.
本來應該是strace、ltrace、pstack配合使用,但是我使用的設備上沒有l(wèi)trace和pstack,所以我使用gdb attach直接調(diào)試進程,查看對應的線程堆棧信息,用來確認top組合命令的出的線程pid信息和實際代碼進行映射。
gdb attach 461 實時調(diào)試查看線程堆棧信息用來匹配實際的代碼部分
進入之后直接使用 thread apply all bt 查看對應的線程堆棧信息,通過堆棧信息,我們就可以知道對應的代碼部分
每一個堆棧信息的最上面有顯示 lwp
這時候我們就知道了該進程下有哪些線程,那我們還需要知道該線程對應的是代碼哪一部分代碼,以及線程具體執(zhí)行了哪些操作。
strace和gdb attach命令等從開發(fā)初始來說是好的技術,但是實際使用中,由于代碼復雜性,以及c受限與cpu,在我strace和gdb attach使用中,這些工具因為要一直監(jiān)控進程,會很占用你cpu資源,甚至gdb attach開始調(diào)試,機器直接運行非常緩慢,遠程ssh登錄都卡住了。所以只能用一些消耗資源少的操作進行查看信息,就像內(nèi)存分析中的mtrace和valgrind,一啟動使用,機器直接卡停。所以很多時候工具雖好,但是實際只能輔助一些而已,更重要我們要規(guī)范寫代碼。
結(jié)語
這就是我分享我在工作中使用的一些linux線程監(jiān)控的操作,如果大家有更好的想法和需求,也歡迎大家加我好友交流分享哈。
作者:良知猶存,白天努力工作,晚上原創(chuàng)公號號主。公眾號內(nèi)容除了技術還有些人生感悟,一個認真輸出內(nèi)容的職場老司機,也是一個技術之外豐富生活的人,攝影、音樂 and 籃球。關注我,與我一起同行。