linux下定位異常消耗的執行緒實戰分析

良知猶存發表於2021-12-05

前言:

之前分享過一篇Linux開發coredump檔案分析實戰分享 ,今天再來分享一篇實戰文章。

在我們嵌入式linux開發過程中,開發過程中我們經常會使用多程式、多執行緒開發。那麼多執行緒使用過程中,我們大概率會遇到某執行緒長時間佔用cpu,導致裝置執行異常。

通常只有四五個執行緒,我們可以通過一個個執行緒除錯捕捉到異常執行緒,如果你開發的裝置上面執行了大概三四十個執行緒,我們一下子不好看到對應哪個執行緒出問題,也不好使用列舉法進行搜尋,這個時候我們需要配合一些工具進行監控以及檢查我們執行的程式下面的執行緒。下面我就給大家介紹一下我自己工作中實際遇到的例子。

作者:良知猶存

轉載授權以及圍觀:歡迎關注微信公眾號:羽林君

或者新增作者個人微信:become_me


情節介紹:

在工作中,我遇到這樣一個問題,我的裝置跑機的時候發現,機器執行某些狀態時候有些怪異,對於某些機制的處理響應不夠及時,最後top檢查,發現是我執行的某個程式中的某幾個執行緒執行cpu佔有率很高,導致其他的一些執行緒無法及時執行。

找到問題了,接下來我們就開始找對應的執行緒然後進行修改,前文提到,程式裡面有一兩個執行緒還好說,我們可以通過一些比較基礎的方法,一個個執行緒進行log或者其他手段的資訊輸出,但是如果我們遇到單個程式裡面有很多執行緒的時候,我們如何檢查呢?

初步列一個使用的工具大綱:ps 組合命令、top組合命令、pstack、strace、ltrace、gdb attach <pid>實時除錯 、 kill <sig> <pid>、coredump檔案檢視執行緒堆疊

以上就是我使用到的一些命令和操作,接下來一一給大家進行分析和介紹:

首先給大家介紹每個工具和命令詳細介紹,再用自己的一個小例子把這些工具進行組合使用說明。

工具和組合命令詳細介紹

首先給詳細的介紹一下這些工具說明書:

ps 的選項引數介紹:

ps命令大家在linux使用應該是很熟悉的,ps是Process Status的縮寫,用來列出系統中當前執行的程式。使用該命令可以確定有哪些程式正在執行和執行的狀態、程式是否結束、程式有沒有僵死、哪些程式佔用了過多的資源等等。ps命令所列出的進行是當前程式的快照,也就是並不是動態的,而是執行該命令時那一時刻進行的狀態。

ps 的引數非常多, 在此僅列出幾個常用的引數並大略介紹含義
-A 列出所有的程式
-w 顯示加寬可以顯示較多的資訊
-au 顯示較詳細的資訊
-aux 顯示所有包含其他使用者的行程

我一般都是使用 ps -aux進行檢視後臺執行的程式pid

下面再進行補充一下今天要使用到的ps組合命令

檢視程式對應的執行緒

ps -T -p 472 (472 此處為真實程式的pid大家自行替換)

第一行是對應的程式ID,第二行是對應的執行緒ID

檢視程式對應執行緒的執行時間

ps -eLo pid,lwp,pcpu |grep 1780(1780 此處為真實程式的pid大家自行替換)

第一行是程式pid,第二行是程式裡面執行緒對應的pid,第三行是該執行緒執行ms時間,通過執行緒執行時間長度,我們配合該執行緒的堆疊資訊,執行緒頻繁執行IO操作或者執行緒頻繁執行的庫函式來判斷該執行緒是否錯誤佔用cpu資源。

top組合命令介紹:

top命令也是大家熟悉的一個命令,可以顯示當前系統正在執行的程式的相關資訊,包括程式ID、記憶體佔用率、CPU佔用率等。同時也可以對指定程式傳送一個訊號。

-b 批處理
-c 顯示完整的資訊
-I 忽略失效過程
-s 保密模式
-S 累積模式
-i<時間> 設定間隔時間
-u<使用者名稱> 指定使用者名稱
-p<程式號> 指定程式
-n<次數> 迴圈顯示的次數

首先我們一般會直接使用top命令,檢視程式資訊,這裡做一下多描述,因為後續使用strace工具還是使用ltrace工具,是從top命令的cpu資訊區進行確定我們使用具體工具。

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顯示的統計資訊:

top顯示資訊前五行是當前系統情況整體的統計資訊區。這部分統計資訊的解釋參考文章《top命令》:

第一行,任務佇列資訊,同 uptime 命令的執行結果

test@test:~# uptime
 13:46:08 up  1:04,  1 user,  load average: 0.00, 0.00, 0.00

具體引數說明情況如下:
02:32:07 — 當前系統時間
up 17 min,  — 系統已經執行了17分鐘
2 users — 當前有2個使用者終端登入系統
load average: 3.17, 3.26, 2.17— load average後面的三個數分別是1分鐘、5分鐘、15分鐘的負載情況。

load average資料是每隔5秒鐘檢查一次活躍的程式數,然後按特定演算法計算出的數值。如果這個數除以邏輯CPU的數量,結果高於5的時候就表明系統在超負荷運轉了。

第二行,Tasks — 任務(程式),具體資訊說明如下:

系統現在共有165個程式,其中處於執行中的有3個,162個在休眠(sleep),stoped狀態的有0個,zombie狀態(殭屍)的有0個。

第三行,cpu狀態資訊,具體屬性說明如下:


31.3 us — 使用者空間佔用CPU的百分比。
7.0  sy — 核心空間佔用CPU的百分比。
0.0  ni — 改變過優先順序的程式佔用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 虛擬機器管理程式為另一個處理器(從虛擬機器中竊取)服務時,虛擬cpu進行非自願等待所花費的時間

第四行,記憶體狀態,具體資訊如下:

3845.3 total — 實體記憶體總量(3.8GB)
3424.3 free — 空閒記憶體總量(3.2GB)
240.9 used — 使用中的記憶體總量(240.9MB)
180.1 buff/cache — 快取的記憶體量 (180M)

第五行,swap交換分割槽資訊,具體資訊說明如下:

0.0 total — 交換區總量(0.0 GB)
0.0 free — 空閒交換區總量(0MB)
0.0 used — 使用的交換區總量(0MB)
3566.7 avail Mem — 可使用緩衝的交換區總量(3.5GB)

第六行,空行。

第七行以下:各程式(任務)的狀態監控,專案列資訊說明如下:

PID — 程式id
USER — 程式所有者
PR — 程式優先順序
NI — nice值。負值表示高優先順序,正值表示低優先順序
VIRT — 程式使用的虛擬記憶體總量,單位kb。VIRT=SWAP+RES
RES — 程式使用的、未被換出的實體記憶體大小,單位kb。RES=CODE+DATA
SHR — 共享記憶體大小,單位kb
S — 程式狀態。D=不可中斷的睡眠狀態 R=執行 S=睡眠 T=跟蹤/停止 Z=殭屍程式
%CPU — 上次更新到現在的CPU時間佔用百分比
%MEM — 程式使用的實體記憶體百分比
TIME+ — 程式使用的CPU時間總計,單位1/100秒
COMMAND — 程式名稱(命令名/命令列)

這是top的常規使用得到的資訊,我們一般進行組合使用命令,我一般使用,

top -Hp 461(461 此處為真實程式的pid大家自行替換)

通過-Hp命令,我可以檢視指定程式的執行緒

其中在統計資訊的第三行中,可以看到cpu佔用率主要是使用者態。

那麼我們應該最好使用ltrace進行使用者態庫函式的呼叫查詢。當然strace也可以,但是由於核心使用佔據cpu使用率不高,你追蹤到的IO操作應該遠少於使用者態庫函式呼叫。

pstack 的選項引數介紹:

pstack 是 Linux 系統下的一個命令列工具,此命令可以顯示指定程式每個執行緒的堆疊快照,便於排查程式異常和效能評估,此命令允許使用的唯一選項是要檢查的程式的 PID。要是要使用這個包大家需要在所使用的linux lib和斌目錄裡面增加該工具。

示例

sudo pstack 16634(該pid為我自己測試電腦對應的程式 大家使用時候可以自行替換成自己對應的pid)

可以在一段時間內,多執行幾次pstack,若發現程式碼棧總是停在同一個位置,
那個位置就需要重點關注,很可能就是出問題的地方;

ltrace 的選項引數介紹:

ltrace能夠跟蹤程式的庫函式呼叫,它會顯現出呼叫了哪個庫函式,而strace則是跟蹤程式的每個系統呼叫。ltrace跟蹤程式呼叫庫函式引數選項有什麼?

ltrace 的選項引數介紹:


-c 統計庫函式每次呼叫的時間,最後程式退出時列印摘要。
-C 解碼低階別名稱(核心級)為使用者級名稱。
-d 列印除錯資訊。
-e expr 輸出過濾器,通過表示式,可以過濾掉你不想要的輸出。
-e printf 表示只檢視printf函式調。
-e!printf 表示檢視除printf函式以外的所有函式呼叫。
-f 跟蹤子程式。
-o flename 將ltrace的輸出寫入檔案filename。
-p pid 指定要跟蹤的程式pid。
-r 輸出每一個呼叫的相對時間。
-S 顯示系統呼叫。
-t 在輸出中的每一行前加上時間資訊。
-tt 在輸出中的每一行前加上時間資訊,精確到微秒。
-ttt 在輸出中的每一行前加上時間資訊,精確到微秒,而且時間表示為UNIX時間戳。
-T 顯示每次呼叫所花費的時間。


strace 的選項引數介紹:

strace常用來跟蹤程式執行時的系統呼叫和所接收的訊號。 在Linux世界,程式不能直接訪問硬體裝置,當程式需要訪問硬體裝置(比如讀取磁碟檔案,接收網路資料等等)時,必須由使用者態模式切換至核心態模式,通過系統呼叫訪問硬體裝置。strace可以跟蹤到一個程式產生的系統呼叫,包括引數,返回值,執行消耗的時間。

-f 跟蹤目標程式,以及目標程式建立的所有子程式
-t 在輸出中的每一行前加上時間資訊(-tt 表示微秒級)
-T 顯示每個系統呼叫所耗的時間

通過觀察系統呼叫我們可以確認當前程式的行為,分析其消耗的時間、返回值是否正常。可以過濾指定的執行緒號,確認當前執行緒的行為是否符合預期,如果執行命令後完全沒有輸出,那麼可以懷疑是否由於網路、IO等原因導致阻塞,或程式產生死鎖。


pstree 的選項引數介紹:

命令將所有程式以樹狀圖顯示,樹狀圖將會以 pid (如果有指定) 或是以 init 這個基本程式為根 (root),如果有指定使用者 id,則樹狀圖會只顯示該使用者所擁有的程式。要是要使用這個包大家需要在所使用的linux lib和斌目錄裡面增加該工具。

-A: 各程式樹之間的連線以ASCII碼字元來連線
-U:各程式樹之間的連線以utf8字元來連線,某些終端可能會有錯誤
-p:同時列出每個程式的PID
-u: 同時列出每個程式的所屬賬號名稱:

pstree -up 輸出程式和子程式樹形資料

kill <sig> <pid>和coredump檔案檢視執行緒堆疊:

因為有些時候我們使用的linux環境下面不一定有很全的工具,例如上面所提到的pstack檢視對應的執行緒,會有其他的一些命令和工具替代,這裡我就給大家介紹兩種我使用的方法,用來檢視我實際的堆疊和對應的pid執行緒資訊。

kill -11 461

對應的程式就會 出現Segmentation fault (core dumped)

而我們設定了coredump檔案的產生,產生條件裡面有段錯誤訊號,所以我傳送了11訊號給該程式。

如果大家對於自己需要的訊號不知道對應的數字,可以用 kill -l 命令查詢。

至於通過coredump檢視對應的堆疊資訊,我之前的這篇文章寫的比較全面了,這裡就不再過多贅述了,大家可以點選這篇文章進行檢視
Linux開發coredump檔案分析實戰分享

除了使用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>實時除錯:

這個是gdb中實時除錯的工具,指定程式實時除錯,但是實際中遇到大型程式碼,除錯起來太卡了,所以基本不用它實時除錯,我是用來它來進行實時看一些堆疊資訊以及檢視執行緒id和實際程式碼的匹配。
操作也是比較簡單,從上面我們可以獲知你執行的程式的pid,你用gdb attach指定pid就可以進行除錯了。進入之後的操作命令就是gdb除錯的命令。

大家可以看到gdb attach一進來就在最前面顯示對應的lwp執行緒pid,這個pid和我們用top命令和ps命令以及strace、ltrace列印的pid資訊是一致的。通過相同的pid我們就可以知道該程式或者執行緒下執行的具體操作了。

輸入gdb命令 thread apply all bt ,我們就可以看到對應執行緒的堆疊,通過堆疊的資訊,我們就可以反向查詢程式碼了。
下面是一個擷取,展示的是lwp 790(執行緒pid==790)的一個堆疊資訊,通過#3 我們可以知道該執行緒程式碼在even_manager.cpp的40行

實戰中的組合使用

通過上面的命令介紹,我們也知道了在linux下我們可以用到哪些工具可以分析我們的異常程式和執行緒,下面我就通過一個我自己實際遇到的情況,給大家實際介紹一下這些工具的組合使用情況。

首先,我先使用top命令檢視我cpu使用情況

這一看,ex程式竟然佔用了176%的cpu(我的裝置是多核裝置),也就是差不多兩個核的cpu被佔滿了。此時可以看到主要佔用的cpu資源是使用者態的資源,所以推薦使用ltrace檢視,但是我這邊目前裝置裡面沒有這個包,所以直接使用了strace檢視。

接下來我就想知道到底該程式下的哪個執行緒,以及執行緒對應的是哪部分程式碼,頻繁執行了什麼操作。

所以我先使用了 top -Hp 461 檢視我對應該程式下所有的執行緒執行所佔cpu的百分比。

也可以使用 ps -T -p 461 檢視程式對應的執行緒pid資訊

ps -eLo pid,lwp,pcpu |grep 461 檢視執行緒執行消耗的時間

strace -p 461 -f進行檢視該程式下執行了核心互動函式最多執行的部分

最左邊的部分就是對應的執行IO函式下的執行緒PID,我們同時可以直接指定執行緒pid進行查詢執行緒的操作,例如我們看到執行緒845在讀fd為13的一個裝置,我們可以單獨strace -p 845.

本來應該是strace、ltrace、pstack配合使用,但是我使用的裝置上沒有ltrace和pstack,所以我使用gdb attach直接除錯程式,檢視對應的執行緒堆疊資訊,用來確認top組合命令的出的執行緒pid資訊和實際程式碼進行對映。

gdb attach 461 實時除錯檢視執行緒堆疊資訊用來匹配實際的程式碼部分

進入之後直接使用 thread apply all bt 檢視對應的執行緒堆疊資訊,通過堆疊資訊,我們就可以知道對應的程式碼部分

每一個堆疊資訊的最上面有顯示 lwp <pid> 大家就可以對照檢視程式碼了。

這時候我們就知道了該程式下有哪些執行緒,那我們還需要知道該執行緒對應的是程式碼哪一部分程式碼,以及執行緒具體執行了哪些操作。

strace和gdb attach命令等從開發初始來說是好的技術,但是實際使用中,由於程式碼複雜性,以及c受限與cpu,在我strace和gdb attach使用中,這些工具因為要一直監控程式,會很佔用你cpu資源,甚至gdb attach開始除錯,機器直接執行非常緩慢,遠端ssh登入都卡住了。所以只能用一些消耗資源少的操作進行檢視資訊,就像記憶體分析中的mtrace和valgrind,一啟動使用,機器直接卡停。所以很多時候工具雖好,但是實際只能輔助一些而已,更重要我們要規範寫程式碼。

結語

這就是我分享我在工作中使用的一些linux執行緒監控的操作,如果大家有更好的想法和需求,也歡迎大家加我好友交流分享哈。


作者:良知猶存,白天努力工作,晚上原創公號號主。公眾號內容除了技術還有些人生感悟,一個認真輸出內容的職場老司機,也是一個技術之外豐富生活的人,攝影、音樂 and 籃球。關注我,與我一起同行。

                              ‧‧‧‧‧‧‧‧‧‧‧‧‧‧‧‧  END  ‧‧‧‧‧‧‧‧‧‧‧‧‧‧‧‧

推薦閱讀

【1】在球場上我向人民幣玩家低了頭

【2】Linux開發coredump檔案分析實戰分享

【3】CPU中的程式是怎麼執行起來的 必讀

【4】cartographer環境建立以及建圖測試

【5】設計模式之簡單工廠模式、工廠模式、抽象工廠模式的對比

本公眾號全部原創乾貨已整理成一個目錄,回覆[ 資源 ]即可獲得。

相關文章