一、什么是strace
strace常用來跟蹤進程執行時的系統調用和所接收的信號。
在Linux世界,進程不能直接訪問硬件設備,當進程需要訪問硬件設備(比如讀取磁盤文件,接收網絡數據等等)時,必須由用戶態模式切換至內核態模式,通過系統調用訪問硬件設備。
strace可以跟蹤到一個進程產生的系統調用,包括參數,返回值,執行消耗的時間。
什么是系統調用
系統調用(英語:system call),又稱為系統呼叫,指運行在用戶空間的程序向操作系統內核請求需要更高權限運行的服務。
系統調用提供用戶程序與操作系統之間的接口。操作系統的進程空間分為用戶空間和內核空間:
- 操作系統內核直接運行在硬件上,提供設備管理、內存管理、任務調度等功能。
- 用戶空間通過API請求內核空間的服務來完成其功能——內核提供給用戶空間的這些API, 就是系統調用
Linux內核目前有300多個系統調用,詳細的列表可以通過syscalls手冊頁查看。這些系統調用主要分為幾類:
文件和設備訪問類 比如open/close/read/write/chmod等
進程管理類 fork/clone/execve/exit/getpid等
信號類 signal/sigaction/kill 等
內存管理 brk/mmap/mlock等
進程間通信IPC shmget/semget * 信號量,共享內存,消息隊列等
網絡通信 socket/connect/sendto/sendmsg 等
其他
查看系統調用幫助手冊 man 2 函數名,例如
man 2 open
man 2 fstat
man 2 poll
strace的應用場景
- 基於特定的系統調用或系統調用組進行過濾
- 通過統計特定系統調用的使用次數,所花費的時間,以及成功和錯誤的數量來分析系統調用的使用。
- 它跟蹤發送到進程的信號。
- 通過pid附加到任何正在運行的進程。
- 調試性能問題,查看系統調用的頻率,找出耗時的程序段
- 查看程序讀取的是哪些文件從而定位比如配置文件加載錯誤問題
- 查看某個php腳本長時間運行“假死”情況
- 當程序出現“Out of memory”時被系統發出的SIGKILL信息所kill
- 另外因為strace拿到的是系統調用相關信息,一般也即是IO操作信息,這個對於排查比如cpu占用100%問題是無能為力的。這個時候就可以使用GDB工具了。
二、快速入門
strace有兩種運行模式
- 1.通過它啟動要跟蹤的進程,在原本的命令前加上strace
如我們要跟蹤docker ps這個執行strace docker ps - 2.跟蹤已經運行的進程。傳遞一個-p pid選項
如有一個python程序的pid為7067,可以這樣跟蹤strace -p 7067
三、常用參數
從一個示例命令查看
strace -tt -T -v -f -e trace=file -o /data/log/strace.log -s 1024 -p 23489
-c 統計每一系統調用的所執行的時間,次數和出錯的次數等.
-d 輸出strace關於標准錯誤的調試信息.
-f 除了跟蹤當前進程外,還跟蹤由fork調用所產生的子進程.
-ff 如果提供-o filename,則所有進程的跟蹤結果輸出到相應的filename.pid中,pid是各進程的進程號.
-F 嘗試跟蹤vfork調用.在-f時,vfork不被跟蹤.
-h 輸出簡要的幫助信息.
-i 輸出系統調用的入口指針寄存器值.
-q 禁止輸出關於結合(attaching)、脫離(detaching)的消息,當輸出重定向到一個文件時,自動抑制此類消息.
-r 打印出相對時間關於每一個系統調用,即連續的系統調用起點之間的時間差,與-t對應.
-t 打印各個系統調用被調用時的絕對時間秒級,觀察程序各部分的執行時間可以用此選項。
-tt 在輸出中的每一行前加上時間信息,微秒級.
-ttt 在每行輸出前添加相對時間信息,格式為”自紀元時間起經歷的秒數.微秒數”
-T 顯示每一調用所耗的時間,其時間開銷在輸出行最右側的尖括號內.
-v 冗余顯示模式:顯示系統調用中argv[]envp[]stat、termio(s)等數組/結構體參數所有的元素/成員內容.
-V 輸出strace的版本信息.
-x 以十六進制形式輸出非標准字符串 。
-xx 所有字符串以十六進制形式輸出.
-a column 設置返回值的輸出位置.默認為40,即"="出現在第40列.
-e expr 指定一個表達式,用來控制如何跟蹤.
-e trace=set 只跟蹤指定的系統 調用.例如:-e trace=open.
-e trace=file 只跟蹤有關文件操作的系統調用.
-e trace=process 只跟蹤有關進程控制的系統調用.
-e trace=network 跟蹤與網絡有關的所有系統調用.
-e trace=signal 跟蹤所有與系統信號有關的系統調用
-e trace=ipc 跟蹤所有與進程通訊有關的系統調用
-e abbrev=set 設定 strace輸出的系統調用的結果集.-v 等與 abbrev=none.默認為abbrev=all.
-e raw=set 將指 定的系統調用的參數以十六進制顯示.
-e signal=set 指定跟蹤的系統信號.默認為all.如signal=!SIGIO,表示不跟蹤SIGIO信號.
-e read=set 輸出從指定文件中讀出 的數據.例如: -e read=3,5 -e write=set
-E var 從命令的環境變量列表中移除var。
-E var=val 將var=val放入命令的環境變量列表.
-o filename 將strace的輸出寫入文件filename,而不是顯示到標准錯誤輸出(stderr).
-p pid 跟蹤指定的進程pid,可指定多達32個(-p pid)選項以同時跟蹤多個進程。該選項常用於調試后台進程.
-s strsize 限制每行輸出中字符串(如read參數)的最大顯示長度,默認32字節。但文件名總是完整顯示
-S sortby 按指定規則對-c選項的輸出直方圖進行排序。sortby取值可為time、calls、name和nothing(默認 time)
-u username 以username 的UID和GID執行被跟蹤的命令
四、實用示例
1.跟蹤redis-server, 看其啟動時都訪問了哪些文件
strace -tt -T -f -e trace=file -o /home/chenqionghe/log/strace.log -s 1024 redis-server
日志文件如下
15711 10:18:06.423843 execve("/usr/bin/redis-server", ["redis-server"], 0x7ffe3e8af6c8 /* 25 vars */) = 0 <0.000203>
15711 10:18:06.424317 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory) <0.000053>
15711 10:18:06.424442 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory) <0.000041>
15711 10:18:06.424584 openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3 <0.000055>
15711 10:18:06.424819 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory) <0.000020>
15711 10:18:06.424904 openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libm.so.6", O_RDONLY|O_CLOEXEC) = 3 <0.000053>
15711 10:18:06.425282 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory) <0.000051>
15711 10:18:06.425425 openat(AT_FDCWD, "/usr/lib/x86_64-linux-gnu/libjemalloc.so.1", O_RDONLY|O_CLOEXEC) = 3 <0.000027>
15711 10:18:06.425865 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory) <0.000026>
2.找出程序在啟動時讀取的配置文件
bash-4.4# strace php 2>&1 | grep php.ini
open("/usr/bin/php.ini", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/etc/php7/php.ini", O_RDONLY) = 3
3.定位進程異常退出
問題:機器上有個叫做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信號殺死的。
進程自己退出時是調用exit_group,如下
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 +++
4.定位共享內存異常
有個服務啟動時報錯:
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解決了這個問題。
參考鏈接
Linux系統調用列表
https://www.ibm.com/developerworks/cn/linux/kernel/syscall/part1/appendix.html
strace參數含義
https://www.cnblogs.com/duanxz/p/6012768.html
strace用法詳解
https://www.linuxidc.com/Linux/2018-01/150654.htm
strace工具使用手冊
https://blog.csdn.net/Huangxiang6/article/details/81295752
