strace 命令详解
一、strace 是什么?
按照 strace 官網的描述,strace 是一個可用于診斷、調試和教學的 Linux 用戶空間跟蹤器。我們用它來監控用戶空間進程和內核的交互,比如系統調用、信號傳遞、進程狀態變更等。
strace 底層使用內核的 ptrace 特性來實現其功能。
在運維的日常工作中,故障處理和問題診斷是個主要的內容,也是必備的技能。strace 作為一種動態跟蹤工具,能夠幫助運維高效地定位進程和服務故障。它像是一個偵探,通過系統調用的蛛絲馬跡,告訴你異常的真相。
二、strace 能做什么?
運維工程師都是實踐派的人,我們還是先來個例子吧。
我們從別的機器 copy 了個叫做 some_server 的軟件包過來,開發說直接啟動就行,啥都不用改。可是嘗試啟動時卻報錯,根本起不來!
啟動命令:
./some_server ../conf/some_server.conf輸出:?
FATAL: InitLogFile failed iRet: -1! Init error: -1655為什么起不來呢?從日志看,似乎是初始化日志文件失敗,真相到底怎樣呢?我們用 strace 來看看。?
strace -tt -f ./some_server ../conf/some_server.conf我們注意到,在輸出 InitLogFile failed 錯誤的前一行,有個 open 系統調用:?
23:14:24.448034?open("/usr/local/apps/some_server/log//server_agent.log",?O_RDWR|O_CREAT|O_APPEND|O_LARGEFILE,?0666)?=?-1?ENOENT?(No?such?file?or?directory)它嘗試打開文件 /usr/local/apps/some_server/log//server_agent.log 來寫(不存在則創建),可是卻出錯了,返回碼是 -1 , 系統錯誤號 errorno 為 ENOENT。 查下 open 系統調用的手冊頁:
man 2 open
搜索 ENOENT 這個錯誤號 errno 的解釋
ENOENT O_CREAT ?is not set and the named file does not exist. ?Or, a directory component in pathname does not exist or is a dangling symbolic link.
這里說得比較清楚,因為我們例子中的 open 選項指定了 O_CREAT 選項,這里 errno 為 ENOENT 的原因是日志路徑中某個部分不存在或者是一個失效的符號鏈接。我們來一級一級看下路徑中的哪部分不存在:
?
ls -l /usr/local/apps/some_server/log ls: cannot access /usr/local/apps/some_server/log: No such file or directory ls -l /usr/local/apps/some_server total 8 drwxr-xr-x 2 root users 4096 May 14 23:13 bin drwxr-xr-x 2 root users 4096 May 14 22:48 conf原來是 log 子目錄不存在!上層目錄都是存在的。手工創建 log 子目錄后,服務就能正常啟動了。
回過頭來, strace 究竟能做什么呢?
它能夠打開應用進程的這個黑盒,通過系統調用的線索,告訴你進程大概在干嘛。
三、strace怎么用?
strace 有兩種運行模式。
一種是通過它啟動要跟蹤的進程。用法很簡單,在原本的命令前加上 strace 即可。比如我們要跟蹤 "ls -lh /var/log/messages"?這個命令的執行,可以這樣:
strace ls -lh /var/log/messages另外一種運行模式,是跟蹤已經在運行的進程,在不中斷進程執行的情況下,理解它在干嘛。 這種情況,給 strace 傳遞個 -p pid 選項即可。
比如,有個在運行的 some_server 服務,第一步,查看 pid:
pidof some_server 17553得到其 pid 17553 然后就可以用 strace 跟蹤其執行:?
strace?-p?17553完成跟蹤時,按 Ctrl + C 結束 strace 即可。
strace 有一些選項可以調整其行為,我們這里介紹下其中幾個比較常用的,然后通過示例講解其實際應用效果。
strace 常用選項:
從一個示例命令來看:
strace -tt -T -v -f -e trace=file -o /data/log/strace.log -s 1024 -p 23489- -tt:在每行輸出的前面,顯示毫秒級別的時間
- -T:顯示每次系統調用所花費的時間
- -v:對于某些相關調用,把完整的環境變量,文件 stat 結構等打出來。
- -f:跟蹤目標進程,以及目標進程創建的所有子進程
- -e:控制要跟蹤的事件和跟蹤行為,比如指定要跟蹤的系統調用名稱
- -o:把 strace 的輸出單獨寫到指定的文件
- -s:當系統調用的某個參數是字符串時,最多輸出指定長度的內容,默認是 32 個字節
- -p:指定要跟蹤的進程 pid,要同時跟蹤多個 pid,重復多次 -p 選項即可。
四、strace問題定位案例
1、定位進程異常退出
問題:機器上有個叫做run.sh的常駐腳本,運行一分鐘后會死掉。需要查出死因。
定位:進程還在運行時,通過ps命令獲取其pid, 假設我們得到的pid是24298
strace -o strace.log -tt -p 24298?查看 strace.log,我們在最后 2 行看到如下內容:
22:47:42.803937?wait4(-1,? <unfinished?...> 22:47:43.228422?+++?killed?by?SIGKILL?+++這里可以看出,進程是被其他進程用 KILL 信號殺死的。
實際上,通過分析,我們發現機器上別的服務有個監控腳本,它監控一個也叫做 run.sh 的進程,當發現 run.sh 進程數大于 2 時,就會把它殺死重啟。結果導致我們這個 run.sh 腳本被誤殺。
進程被殺退出時,strace 會輸出 killed by SIGX(SIGX 代表發送給進程的信號)等,那么,進程自己退出時會輸出什么呢?
這里有個叫做 test_exit 的程序,其代碼如下:
#include <stdio.h> #include <stdlib.h>int main(int argc, char **argv) {exit(1); }我們 strace 看下它退出時 strace 上能看到什么痕跡。?
strace -tt -e trace=process -f ./test_exit說明: -e trace=process 表示只跟蹤和進程管理相關的系統調用。
輸出:
23:07:24.672849?execve("./test_exit",?["./test_exit"],?[/*?35?vars?*/])?=?0 23:07:24.674665?arch_prctl(ARCH_SET_FS,?0x7f1c0eca7740)?=?0 23:07:24.675108?exit_group(1)? ? ? ? ? ?=?? 23:07:24.675259?+++?exited?with?1?+++可以看出,進程自己退出時(調用 exit 函數,或者從 main 函數返回), 最終調用的是 exit_group 系統調用, 并且 strace 會輸出 exited with X(X為退出碼)。
可能有人會疑惑,代碼里面明明調用的是 exit,怎么顯示為 exit_group?
這是因為這里的 exit 函數不是系統調用,而是 glibc 庫提供的一個函數,exit 函數的調用最終會轉化為 exit_group 系統調用,它會退出當前進程的所有線程。實際上,有一個叫做 _exit()的系統調用(注意 exit 前面的下劃線),線程退出時最終會調用它。
2、定位共享內存異常
有個服務啟動時報錯:
shmget 267264 30097568: Invalid argument Can not get shm...exit!錯誤日志大概告訴我們是獲取共享內存出錯,通過 strace 看下:?
strace -tt -f -e trace=ipc ./a_mon_svr ../conf/a_mon_svr.conf輸出:?
22:46:36.351798 shmget(0x5feb, 12000, 0666) = 0 22:46:36.351939 shmat(0, 0, 0) = ? Process 21406 attached 22:46:36.355439 shmget(0x41400, 30097568, 0666) = -1 EINVAL (Invalid argument) shmget 267264 30097568: Invalid argument Can not get shm...exit!這里,我們通過 -e trace=ipc 選項,讓 strace 只跟蹤和進程通信相關的系統調用。
從 strace 輸出,我們知道是 shmget 系統調用出錯了,errno 是 EINVAL。同樣, 查詢下 shmget 手冊頁,搜索 EINVAL 的錯誤碼的說明:
?EINVAL A new segment was to be created and size < SHMMIN or size > SHMMAX, or no new segment was to be created, a segment with given key existed, but size is greater than the size of that segment
翻譯下,shmget 設置 EINVAL 錯誤碼的原因為下列之一:
-
要創建的共享內存段比 SHMMIN 小 (一般是1個字節)
-
要創建的共享內存段比 SHMMAX 大 (內核參數 kernel.shmmax 配置)
-
指定 key 的共享內存段已存在,其大小和調用 shmget 時傳遞的值不同。
從 strace 輸出看,我們要連的共享內存 key 0x41400,指定的大小是 30097568 字節,明顯與第1、2 種情況不匹配。那只剩下第三種情況。使用 ipcs 看下是否真的是大小不匹配:
?
ipcs? -m?|?grep?41400 key? ? ? ? shmid? ? ? owner? ? ? perms? ? ? bytes? ? ? nattch? ? ?status? ? 0x00041400?1015822? ? root? ? ? ?666? ? ? ? 30095516? ?1可以看到,已經 0x41400 這個 key 已經存在,并且其大小為 30095516 字節,和我們調用參數中的 30097568 不匹配,于是產生了這個錯誤。
在我們這個案例里面,導致共享內存大小不一致的原因,是一組程序中,其中一個編譯為32位,另外一個編譯為64位,代碼里面使用了long這個變長int數據類型。
把兩個程序都編譯為64解決了這個問題。
這里特別說下 strace 的 -e trace 選項。
要跟蹤某個具體的系統調用,-e trace=xxx 即可。但有時候我們要跟蹤一類系統調用,比如所有和文件名有關的調用、所有和內存分配有關的調用。
如果人工輸入每一個具體的系統調用名稱,可能容易遺漏。于是strace提供了幾類常用的系統調用組合名字。
?
-e trace=file ? ? 跟蹤和文件訪問相關的調用(參數中有文件名)
-e trace=process ?和進程管理相關的調用,比如fork/exec/exit_group
-e trace=network ?和網絡通信相關的調用,比如socket/sendto/connect
-e trace=signal ? ?信號發送和處理相關,比如kill/sigaction
-e trace=desc ?和文件描述符相關,比如write/read/select/epoll等
-e trace=ipc 進程見同學相關,比如shmget等
絕大多數情況,我們使用上面的組合名字就夠了。實在需要跟蹤具體的系統調用時,可能需要注意C 庫實現的差異。
比如我們知道創建進程使用的是 fork 系統調用,但在 glibc 里面,fork 的調用實際上映射到了更底層的 clone 系統調用。使用 strace 時,得指定 -e trace=clone,指定 -e trace=fork 什么也匹配不上。
3、 性能分析
假如有個需求,統計 Linux 4.5.4 版本內核中的代碼行數(包含匯編和 C 代碼)。這里提供兩個Shell 腳本實現:
poor_script.sh:
!/bin/bash total_line=0 while read filename; doline=$(wc -l $filename | awk ‘{print $1}’)(( total_line += line )) done < <( find linux-4.5.4 -type f ( -iname ‘.c’ -o -iname ‘.h’ -o -iname ‘*.S’ ) ) echo “total line: $total_line”good_script.sh:?
!/bin/bash find linux-4.5.4 -type f ( -iname ‘.c’ -o -iname ‘.h’ -o -iname ‘*.S’ ) -print0 \ | wc -l —files0-from - | tail -n 1兩段代碼實現的目的是一樣的。 我們通過 strace 的 -c 選項來分別統計兩種版本的系統調用情況和其所花的時間(使用 -f 同時統計子進程的情況)
從兩個輸出可以看出,good_script.sh 只需要 2 秒就可以得到結果:19613114 行。它大部分的調用(calls)開銷是文件操作(read/open/write/close)等,統計代碼行數本來就是干這些事情。
而 poor_script.sh 完成同樣的任務則花了 539 秒。它大部分的調用開銷都在進程和內存管理上(wait4/mmap/getpid…)。
實際上,從兩個圖中 clone 系統調用的次數,我們可以看出 good_script.sh 只需要啟動 3 個進程,而 poor_script.sh 完成整個任務居然啟動了 126335 個進程!
而進程創建和銷毀的代價是相當高的,性能不差才怪。
五、總結
當發現進程或服務異常時,我們可以通過 strace 來跟蹤其系統調用,“看看它在干啥”,進而找到異常的原因。熟悉常用系統調用,能夠更好地理解和使用strace。
當然,萬能的 strace 也不是真正的萬能。當目標進程卡死在用戶態時,strace 就沒有輸出了。
這個時候我們需要其他的跟蹤手段,比如 gdb / perf?/ SystemTap 等。
備注:
1、perf 原因 kernel 支持
2、ftrace ?kernel 支持可編程
3、systemtap 功能強大,RedHat?系統支持,對用戶態,內核態邏輯都能探查,使用范圍更廣。
轉載:strace命令詳解 - 馬昌偉 - 博客園
(SAW:Game Over!)
總結
以上是生活随笔為你收集整理的strace 命令详解的全部內容,希望文章能夠幫你解決所遇到的問題。
- 上一篇: Linux桌面环境介绍以及优缺点分析
- 下一篇: 数据脱敏的 6 种方案