自助Linux之問題診斷工具strace【轉】

標籤：

轉自：http://www.cnblogs.com/bangerlee/archive/2012/02/20/2356818.html

 

引言

“Oops，系統掛死了..."

“Oops，程式崩潰了..."

“Oops，命令執行報錯..."

 

對於維護人員來說，這樣的悲劇每天都在上演。理想情況下，系統或應用程式的錯誤記錄檔提供了足夠全面的資訊，通過查看相關日誌，維護人員就能很快地定位出問題發生的原因。但現實情況，許多錯誤記錄檔列印模淩兩可，更多地描述了出錯時的現象(比如"could not open file"，"connect to XXX time out")，而非出錯的原因。

 

錯誤記錄檔不能滿足定位問題的需求，我們能從更“深層”的方面著手分析嗎？程式或命令的執行，需要通過系統調用(system call)與作業系統產生互動，其實我們可以通過觀察這些系統調用及其參數、傳回值，界定出錯的範圍，甚至找出問題出現的根因。

 

在Linux中，strace就是這樣一款工具。通過它，我們可以跟蹤程式執行過程中產生的系統調用及接收到的訊號，協助我們剖析器或命令執行中遇到的異常情況。

 

一個簡單的例子

如何使用strace對程式進行跟蹤，如何查看相應的輸出？下面我們通過一個例子來說明。

1.被跟蹤程式樣本

//main.c
#include <sys/types.h>
#include <sys/stat.h>
#include <fcntl.h>
int main( )
{
　　int fd ;
　　int i = 0 ;
　　fd = open( “/tmp/foo”, O_RDONLY ) ;
　　if ( fd < 0 )
　　　　i=5;
　　else
　　　　i=2;
　　return i;
}

以上程式嘗試以唯讀方式開啟/tmp/foo檔案，然後退出，其中只使用了open這一個系統調用函數。之後我們對該程式進行編譯，產生可執行檔：

[email protected]:~$ gcc main.c -o main

 

2.strace跟蹤輸出

使用以下命令，我們將使用strace對以上程式進行跟蹤，並將結果重新導向至main.strace檔案：

[email protected]:~$ strace -o main.strace ./main

接下來我們來看main.strace檔案的內容：

[email protected]:~$ cat main.strace
1 execve("./main", ["./main"], [/* 43 vars */]) = 0
2 brk(0)                                  = 0x9ac4000
3 access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
4 mmap2(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7739000
5 access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
6 open("/etc/ld.so.cache", O_RDONLY)      = 3
7 fstat64(3, {st_mode=S_IFREG|0644, st_size=80682, ...}) = 0
8 mmap2(NULL, 80682, PROT_READ, MAP_PRIVATE, 3, 0) = 0xb7725000
9 close(3)                                = 0
10 access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
11 open("/lib/i386-linux-gnu/libc.so.6", O_RDONLY) = 3
12 read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\220o\1\0004\0\0\0"..., 512) = 512
13 fstat64(3, {st_mode=S_IFREG|0755, st_size=1434180, ...}) = 0
14 mmap2(NULL, 1444360, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x56d000
15 mprotect(0x6c7000, 4096, PROT_NONE)     = 0
16 mmap2(0x6c8000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x15a) = 0x6c8000
17 mmap2(0x6cb000, 10760, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x6cb000
18 close(3)                                = 0
19 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7724000
20 set_thread_area({entry_number:-1 -> 6, base_addr:0xb77248d0, limit:1048575, seg_32bit:1, contents:0, read_exec_    only:0, limit_in_pages:1, seg_not_present:0, useable:1}) = 0
21 mprotect(0x6c8000, 8192, PROT_READ)     = 0
22 mprotect(0x8049000, 4096, PROT_READ)    = 0
23 mprotect(0x4b0000, 4096, PROT_READ)     = 0
24 munmap(0xb7725000, 80682)               = 0
25 open("/tmp/foo", O_RDONLY)              = -1 ENOENT (No such file or directory)
26 exit_group(5)                           = ?
//標紅的行號為方便說明而添加，非strace執行輸出

看到這一堆輸出，是否心生畏難情緒？不用擔心，下面我們對輸出逐條進行分析。

 

strace跟蹤程式與系統互動時產生的系統調用，以上每一行就對應一個系統調用，格式為：

系統調用的名稱( 參數... ) = 傳回值  錯誤標誌和描述

 

Line 1:  對於命令列下執行的程式，execve(或exec系列調用中的某一個)均為strace輸出系統調用中的第一個。strace首先調用fork或clone函數建立一個子進程，然後在子進程中調用exec載入需要執行的程式(這裡為./main)

Line 2:  以0作為參數調用brk，傳回值為記憶體管理的起始地址(若在子進程中調用malloc，則從0x9ac4000地址開始分配空間)

Line 3:  調用access函數檢驗/etc/ld.so.nohwcap是否存在

Line 4:  使用mmap2函數進行匿名記憶體映射，以此來擷取8192bytes記憶體空間，該空間起始地址為0xb7739000，關於匿名記憶體映射，可以看這裡

Line 6:  調用open函數嘗試開啟/etc/ld.so.cache檔案，返迴文件描述符為3

Line 7:  fstat64函數擷取/etc/ld.so.cache檔案資訊

Line 8:  調用mmap2函數將/etc/ld.so.cache檔案對應至記憶體，關於使用mmap對應檔至記憶體，可以看這裡

Line 9:  close關閉檔案描述符為3指向的/etc/ld.so.cache檔案

Line12:  調用read，從/lib/i386-linux-gnu/libc.so.6該libc庫檔案中讀取512bytes，即讀取ELF頭資訊

Line15:  使用mprotect函數對0x6c7000起始的4096bytes空間進行保護(PROT_NONE表示不能訪問，PROT_READ表示可以讀取)

Line24:  調用munmap函數，將/etc/ld.so.cache檔案從記憶體中去映射，與Line 8的mmap2對應

Line25:  對應源碼中使用到的唯一的系統調用——open函數，使用其開啟/tmp/foo檔案

Line26:  子進程結束，退出碼為5(為什麼退出值為5？返回前面程式樣本部分看看源碼吧：)

 

3.輸出分析

呼呼！看完這麼多系統調用函數，是不是有點摸不著北？讓我們從整體入手，回到主題strace上來。

從上面輸出可以發現，真正能與源碼對應上的只有open這一個系統調用(Line25)，其他系統調用幾乎都用於進行進程初始化工作：裝載被執行程式、載入libc函數庫、設定記憶體映射等。

 

源碼中的if語句或其他代碼在相應strace輸出中並沒有體現，因為它們並沒有喚起系統調用。strace只關心程式與系統之間產生的互動，因而strace不適用於程式邏輯代碼的排錯和分析。

 

對於Linux中幾百個系統調用，上面strace輸出的幾個只是冰山一角，想要更深入地瞭解Linux系統調用，那就man一下吧！

man 2 系統調用名稱
man ld.so  //Linux動態連結的manpage

 

strace常用選項

該節介紹經常用到的幾個strace命令選項，以及在何時使用這些選項合適。

1.跟蹤子進程

預設情況下，strace只跟蹤指定的進程，而不對指定進程中建立的子進程進行跟蹤。使用-f選項，可對進程中建立的子進程進行跟蹤，並在輸出結果中列印相應進程PID：

mprotect(0x5b1000, 4096, PROT_READ)     = 0
munmap(0xb77fc000, 80682)               = 0
clone(Process 13600 attached
child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0xb77fb938) = 13600
[pid 13599] fstat64(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0
[pid 13600] fstat64(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0
[pid 13599] mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0 <unfinished ...>
[pid 13600] mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb780f000
……

對多進程程式、命令和指令碼使用strace進行跟蹤的時，一般開啟-f選項。

 

2.記錄系統調用時間

strace還可以記錄程式與系統互動時，各個系統調用發生時的時間資訊，有r、t、tt、ttt、T等幾個選項，它們記錄時間的方式為：

-T:   記錄各個系統調用花費的時間，精確到微秒

-r:   以第一個系統調用(通常為execve)計時，精確到微秒

-t:   時：分：秒

-tt:  時：分：秒 . 微秒

-ttt: 電腦紀元以來的秒數 . 微秒

比較常用的為T選項，因為其提供了每個系統調用花費時間。而其他選項的時間記錄既包含系統調用時間，又算上使用者級代碼執行用時，參考意義就小一些。對部分時間選項我們可以組合起來使用，例如：

strace -Tr ./main
0.000000 execve(“./main”, [“main”], [/* 64 vars */]) = 0
0.000931 fcntl64(0, F_GETFD)= 0 <0.000012>
0.000090 fcntl64(1, F_GETFD)= 0 <0.000022>
0.000060 fcntl64(2, F_GETFD)= 0 <0.000012>
0.000054 uname({sys=”Linux”, node=”ion”, ...}) = 0 <0.000014>
0.000307 geteuid32()= 7903 <0.000011>
0.000040 getuid32()= 7903 <0.000012>
0.000039 getegid32()= 200 <0.000011>
0.000039 getgid32()= 200 <0.000011>
……

最左邊一列為-r選項對應的時間輸出，最右邊一列為-T選項對應的輸出。

 

3.跟蹤正在啟動並執行進程

使用strace對運行中的程式進行跟蹤，使用命令“strace -p PID”即可，命令執行之後，被跟蹤的進程照常執行，strace的其他選項也適用於運行中的進程跟蹤。

 

使用strace處理常式掛死

最後我們通過一個程式樣本，學習使用strace剖析器掛死的方法。

1.掛死程式源碼

//hang.c
#include <stdio.h>
#include <sys/types.h>
#include <unistd.h>
#include <string.h>

int main(int argc, char** argv)
{
    getpid(); //該系統調用起到標識作用
    if(argc < 2)
    {
        printf("hang (user|system)\n");
        return 1;
    }
    if(!strcmp(argv[1], "user"))
        while(1);
    else if(!strcmp(argv[1], "system"))
        sleep(500);
    return 0;
}

可向該程式傳送user和system參數，以上代碼使用死迴圈類比使用者態掛死，調用sleep類比核心態程式掛死。

2.strace跟蹤輸出

使用者態掛死跟蹤輸出：

[email protected]:~$ gcc hang.c -o hang
[email protected]:~$ strace ./hang user
……
mprotect(0x8049000, 4096, PROT_READ)    = 0
mprotect(0xb59000, 4096, PROT_READ)     = 0
munmap(0xb77bf000, 80682)               = 0
getpid()                                = 14539

核心態掛死跟蹤輸出：

[email protected]:~$ strace ./hang system
……
mprotect(0x8049000, 4096, PROT_READ)    = 0
mprotect(0xddf000, 4096, PROT_READ)     = 0
munmap(0xb7855000, 80682)               = 0
getpid()                                = 14543
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
rt_sigaction(SIGCHLD, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
nanosleep({500, 0}, 

 

3.輸出分析

使用者態掛死情況下，strace在getpid()一行輸出之後沒有其他系統調用輸出；進程在核心態掛死，最後一行的系統調用nanosleep不能完整顯示，這裡nanosleep沒有傳回值表示該調用尚未完成。

 

因而我們可以得出以下結論：使用strace跟蹤掛死程式，如果最後一行系統調用顯示完整，程式在邏輯代碼處掛死；如果最後一行系統調用顯示不完整，程式在該系統調用處掛死。

 

當程式掛死在系統調用處，我們可以查看相應系統調用的man手冊，瞭解在什麼情況下該系統調用會出現掛死情況。另外，系統調用的參數也為我們提供了一些資訊，例如掛死在如下系統調用：

read(16,

那我們可以知道read函數正在對檔案描述符為16的檔案或socket進行讀取，進一步地，我們可以使用lsof工具，擷取對應於檔案描述符為16的檔案名稱、該檔案被哪些進程佔用等資訊。

 

小結

本文對Linux中常用的問題診斷工具strace進行了介紹，通過程式樣本，介紹了strace的使用方法、輸出格式以及使用strace剖析器掛死問題的方法，另外對strace工具的幾個常用選項進行了說明，描述了這幾個選項適用的情境。

下次再遇到程式掛死、命令執行報錯的問題，如果從程式日誌和系統日誌中看不出問題出現的原因，先別急著google或找高手幫忙，別忘了一個強大的工具它就在那裡，不離不棄，strace一下吧！

自助Linux之問題診斷工具strace【轉】