關於strace的一點東西

關於strace的一點東西
好久沒寫部落格了,感覺有點慚愧,覺得自己也應該靜下心來利用自己可分配的時間去提升自己.
雖然最近在看一些Python的東西,可是覺得自己還是不能忘記本行啊,Linux C的一些東西必須一直好好溫習.
不廢話,今天打算寫一個簡單的東西, strace , 應該都對它或多或少的知道一些.很多時候除了core dump, backtrace的方式去排查程式的問題外, strace 跟蹤調試也是不錯的選擇.

　　看一小段測試code:

　　/*======================================================================　　 *　　 *       Filename:  strace_use_test.c　　 *        Version:  1.0　　 *        Created:  2014年07月19日 09時40分49秒　　 *       Revision:  none　　 *       Compiler:  clang　　 *         Author:  sim szm, xianszm007@gmail.com　　 *        Company:  Class 1107 of Computer Science and Technology　　 *　　 * ======================================================================　　 */　　　　#include <unistd.h>　　#include <assert.h>　　#include <stdio.h>　　#include <stdlib.h>　　#include <sys/types.h>　　#include <fcntl.h>　　#include <sys/stat.h>　　　　int main(int argc, char *argv[])　　{　　        int fd,i=0;　　        fd=open("/tmp/non_file",O_RDONLY);　　        if(fd<0)　　              i=2;　　        else　　              i=1;　　        return i;　　}

編譯: gcc strace_use_test.c -o strace_use
　　產生追蹤檔案: strace -o strace_use.txt ./strace_use (其實就是跟蹤結果重新導向到檔案)
　　我們來看下對應代碼產生的strace_dump資訊:

　　szm@szm-Lenovo:~/some_code$ cat strace_use.txt 　　(1) execve("./strace_use", ["./strace_use"], [/* 74 vars */]) = 0　　(2) brk(0)                                  = 0x8a92000　　(3) uname({sys="Linux", node="szm-Lenovo", ...}) = 0　　(4) access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)　　(5) mmap2(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb775d000　　(6) access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)　　(7) open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3　　(8) fstat64(3, {st_mode=S_IFREG|0644, st_size=131876, ...}) = 0　　(9)mmap2(NULL, 131876, PROT_READ, MAP_PRIVATE, 3, 0) = 0xb773c000　　(10) close(3)                                = 0　　(11) access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)　　(12) open("/lib/i386-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3　　(13) read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0000\226\1\0004\0\0\0"..., 512) = 512　　(14) fstat64(3, {st_mode=S_IFREG|0755, st_size=1730024, ...}) = 0　　(15) mmap2(NULL, 1743580, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb7592000　　(16) mprotect(0xb7735000, 4096, PROT_NONE)   = 0　　(17) mmap2(0xb7736000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1a3) = 0xb7736000　　(18) mmap2(0xb7739000, 10972, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xb7739000　　(19) close(3)                                = 0　　(20) mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7591000　　(21) set_thread_area({entry_number:-1 -> 6, base_addr:0xb75916c0, limit:1048575, seg_32bit:1, contents:0, read_exec_only:0, limit_in_pages:1, seg_not_present:0, useable:1}) = 0　　(22) mprotect(0xb7736000, 8192, PROT_READ)   = 0　　(23) mprotect(0x8049000, 4096, PROT_READ)    = 0　　(24) mprotect(0xb777f000, 4096, PROT_READ)   = 0　　(25) munmap(0xb773c000, 131876)              = 0　　(26) open("/tmp/non_file", O_RDONLY)         = -1 ENOENT (No such file or directory)　　(27) exit_group(2)                           = ?

(當然,標號是我自己編輯上去的,哈哈)

看到這一堆,也許你會看到一些熟悉的函數調用,但是每行幹嘛的估計是不是有點迷惑.所以我們來說說每一行都在幹什麼.其實更多的就是每一行對應了一個系統調用:(下面的一些系統地址是我自己機子,換台機子肯定不同),差不多格式就是[系統調用的名( 參數... ) = 傳回值 錯誤標誌和描述] 這種樣子,還是看看啥意思吧.
　　 1: 對於命令列下執行的程式，execve(或exec系列調用中的某一個)均為strace輸出系統調用中的第一個。strace首先調用fork或clone函數建立一個子進程，然後在子進程中調用exec載入需要執行的程式(這裡為./strace_use)
　　 2: 以0作為參數調用brk，傳回值為記憶體管理的起始地址(若在子進程中調用malloc，則從0x8a92000地址開始分配空間)
　　 3: 調用access函數檢驗/etc/ld.so.nohwcap是否存在
　　 5: 使用mmap2函數進行匿名記憶體映射，以此來擷取8192bytes記憶體空間，該空間起始地址為0xb775d000，匿名記憶體映射就是不涉及具體的檔案名稱,避免了檔案的建立及開啟,很顯然只能用於具有親緣關係的處理序間通訊(這個解釋也許有點簡單,google一下吧)
　　 7: 調用open函數嘗試開啟/etc/ld.so.cache檔案，返迴文件描述符為3
　　 8: fstat64函數擷取/etc/ld.so.cache檔案資訊
　　 9: 調用mmap2函數將/etc/ld.so.cache檔案對應至記憶體
　　 10: close關閉檔案描述符為3指向的/etc/ld.so.cache檔案
　　 13: 調用read，從/lib/i386-linux-gnu/libc.so.6該libc庫檔案中讀取512bytes，即讀取ELF頭資訊
　　 16: 使用mprotect函數對0xb7735000,起始的4096bytes空間進行保護(PROT_NONE參數就是不能訪問，對應還有PROT_READ表示可以讀取)
　　 25: 調用munmap函數，將/etc/ld.so.cache檔案從記憶體中去映射，與9行的mmap2函數對應
　　 26: 對應源碼中使用到的唯一的系統調用——open函數，使用其開啟/tmp/non_file檔案
　　 27: 子進程結束，退出碼為2(源碼傳回值)
　　從之前的源碼看來,真正能與源碼對應上的只有open這一個系統調用(Line 26)，其他系統調用幾乎都用於進行進程初始化工作：裝載被執行程式、載入libc函數庫、設定記憶體映射等。而且源碼中的if語句或其他代碼在相應strace輸出中並沒有體現，因為它們並沒有喚起系統調用。所以strace只關心程式與系統之間產生的互動，進而strace不適用於程式邏輯代碼的排錯和分析。當然對於Linux中幾百個系統調用，上面strace輸出的幾個只是很小一塊啦.
　　
　　下面說說strace一般常用的幾點吧:
　　首先那就是跟蹤進程嘍, 預設情況下，strace只跟蹤指定的進程，而不對指定進程中建立的子進程進行跟蹤。使用-f選項，可對進程中建立的子進程進行跟蹤，並在輸出結果中列印相應進程PID：
　　我們吧strace_use_test.c的代碼改為如下:

　　/*======================================================================　　 *　　 *       Filename:  strace_use_test.c　　 *        Version:  1.0　　 *        Created:  2014年07月19日 09時40分49秒　　 *       Revision:  none　　 *       Compiler:  clang　　 *         Author:  sim szm, xianszm007@gmail.com　　 *        Company:  Class 1107 of Computer Science and Technology　　 *　　 * ======================================================================　　 */　　　　#include <unistd.h>　　#include <assert.h>　　#include <stdio.h>　　#include <stdlib.h>　　#include <sys/types.h>　　#include <fcntl.h>　　#include <sys/stat.h>　　　　int main(int argc, char *argv[])　　{　　        pid_t pid;　　        pid=fork();　　        if(pid>0){　　                printf("child do_something here !\n");　　        }else if(pid==0){　　                printf("parent area print!\n");　　        }else{　　                perror("fork error !");　　                _exit(0);　　        }　　        return 0;　　}　　對應加上 -f 選項跟蹤父子進程, dump 資訊如下:

　　szm@szm-Lenovo:~/some_code$ strace -o strace_use.txt -f ./strace_use 　　parent area print!　　child do_something here !　　szm@szm-Lenovo:~/some_code$ cat strace_use.txt 　　9256  execve("./strace_use", ["./strace_use"], [/* 74 vars */]) = 0　　9256  brk(0)                            = 0x8d8d000　　9256  uname({sys="Linux", node="szm-Lenovo", ...}) = 0　　9256  access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)　　9256  mmap2(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7799000　　9256  access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)　　9256  open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3　　9256  fstat64(3, {st_mode=S_IFREG|0644, st_size=131876, ...}) = 0　　9256  mmap2(NULL, 131876, PROT_READ, MAP_PRIVATE, 3, 0) = 0xb7778000　　9256  close(3)                          = 0　　9256  access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)　　9256  open("/lib/i386-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3　　9256  read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0000\226\1\0004\0\0\0"..., 512) = 512　　9256  fstat64(3, {st_mode=S_IFREG|0755, st_size=1730024, ...}) = 0　　9256  mmap2(NULL, 1743580, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb75ce000　　9256  mprotect(0xb7771000, 4096, PROT_NONE) = 0　　9256  mmap2(0xb7772000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1a3) = 0xb7772000　　9256  mmap2(0xb7775000, 10972, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xb7775000　　9256  close(3)                          = 0　　9256  mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb75cd000　　9256  set_thread_area({entry_number:-1 -> 6, base_addr:0xb75cd6c0, limit:1048575, seg_32bit:1, contents:0, read_exec_only:0, limit_in_pages:1, seg_not_present:0, useable:1}) = 0　　9256  mprotect(0xb7772000, 8192, PROT_READ) = 0　　9256  mprotect(0x8049000, 4096, PROT_READ) = 0　　9256  mprotect(0xb77bb000, 4096, PROT_READ) = 0　　9256  munmap(0xb7778000, 131876)        = 0　　9256  clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0xb75cd728) = 9257　　9257  fstat64(1,  <unfinished ...>　　9256  fstat64(1,  <unfinished ...>　　9257  <... fstat64 resumed> {st_mode=S_IFCHR|0600, st_rdev=makedev(136, 0), ...}) = 0　　9256  <... fstat64 resumed> {st_mode=S_IFCHR|0600, st_rdev=makedev(136, 0), ...}) = 0　　9257  mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0 <unfinished ...>　　9256  mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0 <unfinished ...>　　9257  <... mmap2 resumed> )             = 0xb7798000　　9256  <... mmap2 resumed> )             = 0xb7798000　　9257  write(1, "parent area print!\n", 19 <unfinished ...>　　9256  write(1, "child do_something here !\n", 26 <unfinished ...>　　9257  <... write resumed> )             = 19　　9256  <... write resumed> )             = 26　　9257  exit_group(0)                     = ?　　9256  exit_group(0)                     = ?

9256 clone(child_stack=0,flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0xb75cd728) = 9257
即9256這個進程核心進行clone()產生9527.

所以很多時候多進程的一些程式strace跟蹤時,一般開啟 -f 選項, 使用strace對運行中的程式進行跟蹤，-p 參數即可，命令執行之後，被跟蹤的進程照常執行，strace的其他選項也適用於運行中的進程跟蹤。有時間要求的時候,strace還可以記錄程式與系統互動時，各個系統調用發生時的時間資訊，有r、t、tt、ttt、T等幾個選項，它們記錄時間的方式為：
　　-T: 記錄各個系統調用花費的時間，精確到微秒
　　-r: 以第一個系統調用(通常為execve)計時，精確到微秒
　　-t: 時：分：秒
　　-tt: 時：分：秒. 微秒
　　-ttt: 電腦紀元以來的秒數. 微秒
　　
Strace 還可以用來判斷程式掛起的問題,繼續修改程式如下:

/*====================================================================== * *       Filename:  strace_use_test.c *        Version:  1.0 *        Created:  2014年07月19日 09時40分49秒 *       Revision:  none *       Compiler:  clang *         Author:  sim szm, xianszm007@gmail.com *        Company:  Class 1107 of Computer Science and Technology * * ====================================================================== */#include <unistd.h>#include <assert.h>#include <stdio.h>#include <stdlib.h>#include <sys/types.h>#include <fcntl.h>#include <sys/stat.h>int main(int argc, char *argv[]){        printf("flag see !\n");        if(strcmp(argv[1],"flag1")==0){                while(1);        }else if(strcmp(argv[1],"flag2")==0){                sleep(400);        }        return 0;}

flag1 可以用來類比使用者態死迴圈掛死狀態,flag2 可以用來類比核心態掛死狀態.因為sleep()是陷入核心的.
看下對應的 strace dump結果:
首先對應的是flag1

szm@szm-Lenovo:~/some_code$ strace ./strace_use flag1execve("./strace_use", ["./strace_use", "flag1"], [/* 74 vars */]) = 0brk(0)                                  = 0x8cff000uname({sys="Linux", node="szm-Lenovo", ...}) = 0access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)mmap2(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb77a8000access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3fstat64(3, {st_mode=S_IFREG|0644, st_size=131876, ...}) = 0mmap2(NULL, 131876, PROT_READ, MAP_PRIVATE, 3, 0) = 0xb7787000close(3)                                = 0access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)open("/lib/i386-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0000\226\1\0004\0\0\0"..., 512) = 512fstat64(3, {st_mode=S_IFREG|0755, st_size=1730024, ...}) = 0mmap2(NULL, 1743580, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb75dd000mprotect(0xb7780000, 4096, PROT_NONE)   = 0mmap2(0xb7781000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1a3) = 0xb7781000mmap2(0xb7784000, 10972, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xb7784000close(3)                                = 0mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb75dc000set_thread_area({entry_number:-1 -> 6, base_addr:0xb75dc6c0, limit:1048575, seg_32bit:1, contents:0, read_exec_only:0, limit_in_pages:1, seg_not_present:0, useable:1}) = 0mprotect(0xb7781000, 8192, PROT_READ)   = 0mprotect(0x8049000, 4096, PROT_READ)    = 0mprotect(0xb77ca000, 4096, PROT_READ)   = 0munmap(0xb7787000, 131876)              = 0fstat64(1, {st_mode=S_IFCHR|0600, st_rdev=makedev(136, 0), ...}) = 0mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb77a7000write(1, "flag see !\n", 11flag see !)            = 11

一直卡在這裡迴圈

再看看flag2:

szm@szm-Lenovo:~/some_code$ strace ./strace_use flag2execve("./strace_use", ["./strace_use", "flag2"], [/* 74 vars */]) = 0brk(0)                                  = 0x83c0000uname({sys="Linux", node="szm-Lenovo", ...}) = 0access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)mmap2(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb777a000access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3fstat64(3, {st_mode=S_IFREG|0644, st_size=131876, ...}) = 0mmap2(NULL, 131876, PROT_READ, MAP_PRIVATE, 3, 0) = 0xb7759000close(3)                                = 0access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)open("/lib/i386-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0000\226\1\0004\0\0\0"..., 512) = 512fstat64(3, {st_mode=S_IFREG|0755, st_size=1730024, ...}) = 0mmap2(NULL, 1743580, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb75af000mprotect(0xb7752000, 4096, PROT_NONE)   = 0mmap2(0xb7753000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1a3) = 0xb7753000mmap2(0xb7756000, 10972, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xb7756000close(3)                                = 0mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb75ae000set_thread_area({entry_number:-1 -> 6, base_addr:0xb75ae6c0, limit:1048575, seg_32bit:1, contents:0, read_exec_only:0, limit_in_pages:1, seg_not_present:0, useable:1}) = 0mprotect(0xb7753000, 8192, PROT_READ)   = 0mprotect(0x8049000, 4096, PROT_READ)    = 0mprotect(0xb779c000, 4096, PROT_READ)   = 0munmap(0xb7759000, 131876)              = 0fstat64(1, {st_mode=S_IFCHR|0600, st_rdev=makedev(136, 0), ...}) = 0mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7779000write(1, "flag see !\n", 11flag see !)            = 11rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0rt_sigaction(SIGCHLD, NULL, {SIG_DFL, [], 0}, 8) = 0rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0nanosleep({400, 0},

陷入sleep

　　從輸出的跟蹤資訊可以看出兩中情況的不同, 當使用者態掛死情況下，strace在write(由調用的printf產生write進描述符1,也就是標準輸出) 一行輸出之後沒有其他系統調用輸出；進程在核心態掛死，最後一行的系統調用nanosleep不能完整顯示 (這裡nanosleep沒有傳回值表示該調用尚未完成 ) 所以我們就可以知道：使用strace跟蹤掛死程式，如果最後一行系統調用顯示完整，程式在邏輯代碼處掛死；如果最後一行系統調用顯示不完整，程式在該系統調用處掛死。

　　當程式掛死在系統調用處，我們可以查看相應系統調用的man手冊，瞭解在什麼情況下該系統調用會出現掛死情況。
　　
　　當然strace 還有其他一堆參數,就不說了,其實我也沒看,哈哈.常用跟蹤進程資訊用法的就是strace -o output.txt -T -tt -e trace=all -f -p pid (-e trace=all 意思是跟蹤所有系統調用)

Ok, 周末一上午寫篇Blog 總比睡覺好.Over .