Linux 中用 strace 追蹤系統呼叫和訊號值 （原文棒棒噠）
間接轉載地址：http://www.cnblogs.com/itech/archive/2013/02/28/2937836.html
什麼是strace
開啟man strace，我們能看到對strace的最簡潔的介紹就是”strace – trace system calls and signals”。實際上strace是一個集診斷、除錯、統計與一體的工具，我們可以使用strace對應用的系統呼叫和訊號傳遞的跟蹤結果來對應用進行分析，以達到解決問題或者是瞭解應用工作過程的目的。當然strace與專業的除錯工具比如說gdb之類的是沒法相比的，因為它不是一個專業的偵錯程式。
strace的最簡單的用法就是執行一個指定的命令，在指定的命令結束之後它也就退出了。在命令執行的過程中，strace會記錄和解析命令程序的所有系統呼叫以及這個程序所接收到的所有的訊號值。
命令的使用方法如下
| 1 2 3 4 5 6 7 | strace [ -dffhiqrtttTvxx ] [ -acolumn ] [ -eexpr ] ... [ -ofile ] [-ppid ] ... [ -sstrsize ] [ -uusername ] [ -Evar=val ] ... [ -Evar ]... [command[ arg ... ] ] strace -c [ -eexpr ] ... [ -Ooverhead ] [ -Ssortby ] [command[ arg... ] ] |
strace的基本用法
追蹤系統呼叫
現在我們做一個很簡單的程式來演示strace的基本用法。這個程式的C語言程式碼如下：
| 1 2 3 4 5 6 7 8 9 10 | # filename test.c #include <stdio.h> int main() { inta; scanf("%d", &a); printf("%09d\n", a); return0; } |
然後我們用gcc -o test test.c編譯一下，得到一個可執行的檔案test。然後用strace呼叫執行
| 1 | strace ./test |
執行期間會要求你輸入一個整數，我們輸入99，最後得到如下的結果：
| 1 2 | //直接執行test的結果 [email protected][orcl]:~ $./test |
| 1 2 3 | // 執行的結果 99 000000099 |
| 1 2 | //通過strace執行test的結果 [email protected][orcl]:~ $strace ./test |
| 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 | // strace的trace結果 execve("./test", ["./test"], [/* 41 vars */]) = 0 uname({sys="Linux", node="orainst.desktop.mycompany.com", ...}) = 0 brk(0) = 0x8078000 fstat64(3, {st_mode=S_IFREG|0644, st_size=65900, ...}) = 0 old_mmap(NULL, 65900, PROT_READ, MAP_PRIVATE, 3, 0) = 0xbf5ef000 close(3) = 0 open("/lib/tls/libc.so.6", O_RDONLY) = 3 read(3,"\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\200X\1"..., 512) = 512 fstat64(3, {st_mode=S_IFREG|0755, st_size=1571692, ...}) = 0 old_mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xbf5ee000 old_mmap(NULL, 1275340, PROT_READ|PROT_EXEC, MAP_PRIVATE, 3, 0) = 0xa02000 old_mmap(0xb34000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED, 3, 0x132000) = 0xb34000 old_mmap(0xb37000, 9676, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xb37000 close(3) = 0 set_thread_area({entry_number:-1 -> 6, base_addr:0xbf5ee740, limit:1048575, seg_32bit:1, contents:0, read_exec_only:0, limit_in_pages:1, seg_not_present:0, useable:1}) = 0 munmap(0xbf5ef000, 65900) = 0 fstat64(0, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xbf5ff000 read(0, 99 "99\n", 1024) = 3 fstat64(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xbf5fe000 write(1," 000000099\n", 10000000099 ) = 10 munmap(0xbf5fe000, 4096) = 0 exit_group(0) = ? |
從trace結構可以看到，系統首先呼叫execve開始一個新的進行，接著進行些環境的初始化操作，最後停頓在”read(0,”上面，這也就是執行到了我們的scanf函式，等待我們輸入數字呢，在輸入完99之後，在呼叫write函式將格式化後的數值”000000099″輸出到螢幕，最後呼叫exit_group退出進行，完成整個程式的執行過程。
跟蹤訊號傳遞
我們還是使用上面的那個test程式，來觀察程序接收訊號的情況。還是先strace ./test，等到等待輸入的畫面的時候不要輸入任何東西，然後開啟另外一個視窗，輸入如下的命令
| 1 | killall test |
這時候就能看到我們的程式推出了，最後的trace結果如下：
| 1 2 | [email protected][orcl]:~ $strace ./test |
| 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 | execve("./test", ["./test"], [/* 41 vars */]) = 0 uname({sys="Linux", node="orainst.desktop.mycompany.com", ...}) = 0 brk(0) = 0x9ae2000 old_mmap(NULL, 65900, PROT_READ, MAP_PRIVATE, 3, 0) = 0xbf5ef000 close(3) = 0 open("/lib/tls/libc.so.6", O_RDONLY) = 3 read(3,"\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\200X\1"..., 512) = 512 fstat64(3, {st_mode=S_IFREG|0755, st_size=1571692, ...}) = 0 old_mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xbf5ee000 old_mmap(NULL, 1275340, PROT_READ|PROT_EXEC, MAP_PRIVATE, 3, 0) = 0x2e9000 old_mmap(0x41b000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED, 3, 0x132000) = 0x41b000 old_mmap(0x41e000, 9676, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x41e000 close(3) = 0 set_thread_area({entry_number:-1 -> 6, base_addr:0xbf5ee740, limit:1048575, seg_32bit:1, contents:0, read_exec_only:0, limit_in_pages:1, seg_not_present:0, useable:1}) = 0 munmap(0xbf5ef000, 65900) = 0 fstat64(0, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xbf5ff000 read(0, 0xbf5ff000, 1024) = ? ERESTARTSYS (To be restarted) --- SIGTERM (Terminated) @ 0 (0) --- +++ killed by SIGTERM +++ |
trace中很清楚的告訴你test程序”+++ killed by SIGTERM +++”。
系統呼叫統計
strace不光能追蹤系統呼叫，通過使用引數-c，它還能將程序所有的系統呼叫做一個統計分析給你，下面就來看看strace的統計，這次我們執行帶-c引數的strace：
| 1 | strace -c ./test |
最後能得到這樣的trace結果：
| 1 2 | [email protected][orcl]:~ $strace -c ./test |
| 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 | execve("./test", ["./test"], [/* 41 vars */]) = 0 % time seconds usecs/call calls errors syscall ------ ----------- ----------- --------- --------- ---------------- 45.90 0.000140 5 27 25 open 34.43 0.000105 4 24 21 stat64 7.54 0.000023 5 5 old_mmap 2.62 0.000008 8 1 munmap 1.97 0.000006 6 1 uname 1.97 0.000006 2 3 fstat64 1.64 0.000005 3 2 1 read 1.31 0.000004 2 2 close 0.98 0.000003 3 1 brk 0.98 0.000003 3 1 mmap2 0.66 0.000002 2 1 set_thread_area ------ ----------- ----------- --------- --------- ---------------- 100.00 0.000305 68 47 total |
這裡很清楚的告訴你呼叫了那些系統函式，呼叫次數多少，消耗了多少時間等等這些資訊，這個對我們分析一個程式來說是非常有用的。
常用引數說明
除了-c引數之外，strace還提供了其他有用的引數給我們，讓我們能很方便的得到自己想要的資訊，下面就對那些常用的引數一一做個介紹。
重定向輸出
引數-o用在將strace的結果輸出到檔案中，如果不指定-o引數的話，預設的輸出裝置是STDERR，也就是說使用”-o filename”和” 2>filename”的結果是一樣的。
| 1 2 3 | # 這兩個命令都是將strace結果輸出到檔案test.txt中 strace -c -o test.txt ./test strace -c ./test 2>test.txt |
對系統呼叫進行計時
strace可以使用引數-T將每個系統呼叫所花費的時間打印出來，每個呼叫的時間花銷現在在呼叫行最右邊的尖括號裡面。
| 1 2 | [email protected][orcl]:~ $strace -T ./test |
| 1 2 3 4 5 6 7 8 9 | // 這裡只摘錄部分結果 read(0, 1 "1\n", 1024) = 2 <2.673455> fstat64(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0 <0.000014> mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xbf5fe000 <0.000017> write(1,"000000001\n", 10000000001 ) = 10 <0.000016> munmap(0xbf5fe000, 4096) = 0 <0.000020> exit_group(0) = ? |
系統呼叫的時間
這是一個很有用的功能，strace會將每次系統呼叫的發生時間記錄下來，只要使用-t/tt/ttt三個引數就可以看到效果了，具體的例子可以自己去嘗試。
| 引數名 | 輸出樣式 | 說明 |
|---|---|---|
| -t | 10:33:04 exit_group(0) | 輸出結果精確到秒 |
| -tt | 10:33:48.159682 exit_group(0) | 輸出結果精確到微妙 |
| -ttt | 1262169244.788478 exit_group(0) | 精確到微妙，而且時間表示為unix時間戳 |
截斷輸出
-s引數用於指定trace結果的每一行輸出的字串的長度，下面看看test程式中-s引數對結果有什麼影響，現指定-s為20，然後在read的是是很我們輸入一個超過20個字元的數字串
| 1 | strace -s 20 ./test |
| 1 2 | read(0, 2222222222222222222222222 // 我們輸入的2一共有25個 "22222222222222222222"..., 1024) = 26 // 而我們看到的結果中2只有20個 |
trace一個現有的程序
strace不光能自己初始化一個程序進行trace，還能追蹤現有的程序，引數-p就是取這個作用的，用法也很簡單，具體如下。
| 1 | strace -p pid |
綜合例子
說了那麼多的功能和引數，現在我們來一個實用點的，就是研究下Oracle的lgwr程序，看看這個程序是不是像文件所說的那樣沒3s鍾寫一次log檔案，考慮到lgwr寫日誌的觸發條件比較多，我們需要找一個空閒的Oracle例項做這個實驗。
我們先要得到lgwr程序的pid，執行下面的命令
| 1 | ps -ef|grep lgwr |
| 1 | oracle 5912 1 0 Nov12 ? 00:14:56 ora_lgwr_orcl |
得到lgwr的pid是5912，現在啟動strace，然後將trace的幾個輸出到lgwr.txt檔案中，執行下面的命令
| 1 | strace -tt -s 10 -o lgwr.txt -p 5912 |
過一會之後停止strace，然後檢視結果。由於輸出的結果比較多，為了方便我們只看Oracle寫入log檔案時用的pwrite函式的呼叫
| 1 | grep 'pwrite\(20' lgwr.txt |
等等，為什麼grep的時候用的是”pwrite(2″呢？，因為我知道我這個機器開啟的當前的log檔案的控制代碼編號都是2開始的。具體查詢方法是先使用下面的語句找出當前活動的日誌檔案都有哪些：
| 1 2 | select member, v$log.status from v$log, v$logfile where v$log.group#=v$logfile.group#; |
得到
| 1 2 3 4 5 6 7 8 9 10 | MEMBER STATUS -------------------------------------------------- ---------------- /db/databases/orcl/redo-01-a/redo-t01-g03-m1.log INACTIVE /db/databases/orcl/redo-03-a/redo-t01-g03-m2.log INACTIVE /db/databases/orcl/redo-02-a/redo-t01-g02-m1.log CURRENT /db/databases/orcl/redo-04-a/redo-t01-g02-m2.log CURRENT /db/databases/orcl/redo-01-a/redo-t01-g01-m1.log INACTIVE /db/databases/orcl/redo-03-a/redo-t01-g01-m2.log INACTIVE /db/databases/orcl/redo-02-a/redo-t01-g04-m1.log INACTIVE /db/databases/orcl/redo-04-a/redo-t01-g04-m2.log INACTIVE |
然後到/proc中去找開啟檔案的控制代碼：
| 1 | ll/proc/.5912/fd/ |
得到
| 1 2 3 4 5 6 7 8 | lrwx------ 1 oracle dba 64 Dec 30 10:55 18 ->/db/databases/orcl/redo-01-a/redo-t01-g01-m1.log lrwx------ 1 oracle dba 64 Dec 30 10:55 19 ->/db/databases/orcl/redo-03-a/redo-t01-g01-m2.log lrwx------ 1 oracle dba 64 Dec 30 10:55 20 ->/db/databases/orcl/redo-02-a/redo-t01-g02-m1.log lrwx------ 1 oracle dba 64 Dec 30 10:55 21 ->/db/databases/orcl/redo-04-a/redo-t01-g02-m2.log lrwx------ 1 oracle dba 64 Dec 30 10:55 22 ->/db/databases/orcl/redo-01-a/redo-t01-g03-m1.log lrwx------ 1 oracle dba 64 Dec 30 10:55 23 ->/db/databases/orcl/redo-03-a/redo-t01-g03-m2.log lrwx------ 1 oracle dba 64 Dec 30 10:55 24 ->/db/databases/orcl/redo-02-a/redo-t01-g04-m1.log lrwx------ 1 oracle dba 64 Dec 30 10:55 25 ->/db/databases/orcl/redo-04-a/redo-t01-g04-m2.log |
現在能看到我機器當前日誌檔案的控制代碼分別是20和21。
現在我們得到如下結果
| 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 | 11:13:55.603245 pwrite(20,"\1\"\0\0J!"..., 1536, 4363264) = 1536 11:13:55.603569 pwrite(21,"\1\"\0\0J!"..., 1536, 4363264) = 1536 11:13:55.606888 pwrite(20,"\1\"\0\0M!"..., 1536, 4364800) = 1536 11:13:55.607172 pwrite(21,"\1\"\0\0M!"..., 1536, 4364800) = 1536 11:13:55.607934 pwrite(20,"\1\"\0\0P!"..., 1536, 4366336) = 1536 11:13:55.608199 pwrite(21,"\1\"\0\0P!"..., 1536, 4366336) = 1536 11:13:55.610260 pwrite(20,"\1\"\0\0S!"..., 1536, 4367872) = 1536 11:13:55.610530 pwrite(21,"\1\"\0\0S!"..., 1536, 4367872) = 1536 11:14:00.602446 pwrite(20,"\1\"\0\0V!"..., 1536, 4369408) = 1536 11:14:00.602750 pwrite(21,"\1\"\0\0V!"..., 1536, 4369408) = 1536 11:14:00.606386 pwrite(20,"\1\"\0\0Y!"..., 1536, 4370944) = 1536 11:14:00.606676 pwrite(21,"\1\"\0\0Y!"..., 1536, 4370944) = 1536 11:14:00.607900 pwrite(20,"\1\"\0\0\\"..., 1024, 4372480) = 1024 11:14:00.608161 pwrite(21,"\1\"\0\0\\"..., 1024, 4372480) = 1024 11:14:00.608816 pwrite(20,"\1\"\0\0^!"..., 1024, 4373504) = 1024 11:14:00.609071 pwrite(21,"\1\"\0\0^!"..., 1024, 4373504) = 1024 11:14:00.611142 pwrite(20,"\1\"\0\0`!"..., 1536, 4374528) = 1536 11:14:00.611454 pwrite(21,"\1\"\0\0`!"..., 1536, 4374528) = 1536 11:14:05.602804 pwrite(20,"\1\"\0\0c!"..., 1024, 4376064) = 1024 11:14:05.603119 pwrite(21,"\1\"\0\0c!"..., 1024, 4376064) = 1024 11:14:05.607731 pwrite(20,"\1\"\0\0e!"..., 1024, 4377088) = 1024 11:14:05.608020 pwrite(21,"\1\"\0\0e!"..., 1024, 4377088) = 1024 11:14:05.608690 pwrite(20,"\1\"\0\0g!"..., 1024, 4378112) = 1024 11:14:05.608962 pwrite(21,"\1\"\0\0g!"..., 1024, 4378112) = 1024 11:14:05.611022 pwrite(20,"\1\"\0\0i!"..., 1536, 4379136) = 1536 11:14:05.611283 pwrite(21,"\1\"\0\0i!"..., 1536, 4379136) = 1536 |
很遺憾的是我們看到的寫日誌檔案的操作是每5s進行一次，可能是因為這個系統空閒的原因？這個還需要再研究一下。
相關推薦
Linux 中用 strace 追蹤系統呼叫和訊號值 （原文棒棒噠）
間接轉載地址：http://www.cnblogs.com/itech/archive/2013/02/28/2937836.html 什麼是strace 開啟man strace，我們能看到對strace的最簡潔的介紹就是”strace – tr
Linux strace工具，程序診斷、排錯、跟蹤系統呼叫和訊號量
strace 跟蹤系統呼叫和訊號量，是一個很好的診斷、排錯的工具。 每行輸出都是一個系統呼叫，包括函式和返回值。 示例--直接列印資訊的方式 [[email protected] ~]$ strace cat /dev/null execve("/bin/cat
Linux核心2.6.34.14新增系統呼叫及編譯方法（CentOS-6.4-x86_64）
<?xml version="1.0" encoding="UTF-8"?> //我新增系統呼叫步驟，僅供參考，尤其是系統呼叫的實現部分，建議大家自己寫，除了我這種好像還可以用sys_open系列來寫 #define 核心版本 linux-2.6.34.14
Linux日誌文件查看和搜查命令（錯誤日誌排查定位）
設備 日誌文件 語法 寫入 -i 字節數 不顯示 連接 linux 一、cat命令 cat 命令用於連接文件並打印到標準輸出設備上，主要用來查看文件內容，創建文件，文件合並，追加文件內容等功能。 語法格式 cat [-AbeEnstTuv] fileName
三十三、Linux 程序與訊號——中斷系統呼叫和函式可重入性
33.1 中斷系統呼叫 程序呼叫 “慢” 系統呼叫時，如果發生了訊號，核心會重啟系統呼叫。 慢系統呼叫 可能會永久阻塞的系統呼叫 從終端裝置、管道或網路裝置上的檔案讀取 向上述檔案寫入 某些裝置上的檔案開啟 pause 和 wait 系統呼叫
Linux系統的中斷、系統呼叫和排程概述
最近學習Linux作業系統，關於中斷系統呼叫和程序的級別總是感覺有些模糊的地方，特在此做個小結，整理下思路。 所謂的中斷就是在計算機執行程式的過程中，由於出現了某些特殊事情，使得CPU暫停對程式的執行，轉而去執行處理這一事件的程式。等這些特殊事情處理完之後再回去執行之前的程
Linux下的檔案操作（Linux系統呼叫和ANSIC檔案操作）
1、Linux系統呼叫 系統呼叫常用於 I/O 檔案操作，系統呼叫常用的函式有 open、 close、 read、write、 lseek、ulink 等。 open：開啟或建立檔案 close：關閉檔案 read ：從指定的檔案描述符中讀出的資料放到緩衝區，並
Linux下通過ioctl系統呼叫來獲取和設定網路資訊
#include <stdio.h>#include <stdlib.h>#include <string.h>#include <unistd.h>#include <sys/ioctl.h>#includ
Linux檔案操作總結（系統呼叫和標準IO庫函式）
一、系統呼叫 ❑ open: Open a file or device ❑ read: Read from an open file or device ❑ write: Write to a file or device ❑ close: Close the file
linux系統呼叫和庫函式呼叫的區別
Linux下對檔案操作有兩種方式：系統呼叫（system call）和庫函式呼叫（Library functions）。可以參考《Linux程式設計》（英文原版為《Beginning Linux Programming》，作者是Neil Matthew和Richard St
linux系統——程序和訊號
一、程序 ** 1、啟動新執行緒 ** #include int system(const char *string); 比如：system(“pa ax &”) , 相當於在shell內呼叫ps sx &(&是後臺執行的意思) 函式返回
linux虛擬機ping不通主機和外網（包括剛裝系統遇到的一些問題）
執行 eth0 linux ted ubunt ping通 包括 rtu cte 自己ubuntu系統安裝了一個virtualBox虛擬機，裏面又裝了一個ubuntu-server系統； 1.先設置一下字符集,因為一開始裝系統的時候選擇的是中文,但裏面始終無法支持中文，
Linux 基礎教程 41-系統關機和重啟
mage linux系統 本機 gem tro 電源 ges 就是 系統 ? ? 在Linux系統中，僅僅是關機和重啟相關的命令就至少有5個，shutdown、 halt、poweroff、reboot、init。各個命令作用如下所示： 命令 說明 shutd
Linux 檔案系統呼叫open七日遊（三）
接著上回，當對“.”和“..”處理完成後就直接返回進入下一個子路徑迴圈了，但如果當前子路徑不是“.”或“..”呢？ 【fs/namei.c】 sys_open > do_sys_open > do_filp_open >&
linux 系統呼叫open 七日遊（二）
接著昨日的旅程，我們應該開始處理具體的子路徑了： 【fs/namei.c】 sys_open->do_sys_open->do_filp_open->path_openat->link_path_walk 點選(此處)摺疊或開啟 &n
linux系統呼叫open七日遊（一）
友情提示：您需要一個 kernel 3.15.6，下載地址： https://www.kernel.org/pub/linux/kernel/v3.0/linux-3.15.6.tar.xz 我們將以 Linux 系統呼叫 open 為主線，參
Linux 系統呼叫 open 七日遊（七）
【場景三】open(pathname, O_WRONLY | O_CREAT | O_EXCL, S_IRUSR | S_IWUSR) 在這個場景中我們希望建立一個新檔案（O_CREAT），並賦予該檔案使用者可讀（S_IRUSR）和使用者可寫（S_IW
Linux檔案系統呼叫open 七日遊 （六）
還記得在上一個場景中，build_open_flags裡面有一個對標誌位O_PATH的判斷麼？現在我們就來看看這個標誌位是幹啥的： 【場景二】open（pathname，O_PATH） 這個O_PATH似乎是不常用的，咱們先看看它的使用
linux檔案系統呼叫 open 七日遊（四）
現在，我們的“路徑行走”只剩下最後一個小問題需要處理了——符號連結。 【fs/namei.c】 sys_open > do_sys_open > do_filp_open > path_openat &g
系統呼叫和庫函式及API的區別
在寫程式的過程中，像MFC，VC++這些程式設計，都會涉及到函式的呼叫，有庫函式也有系統函式，下面看一看它們的區別！！ 系統呼叫（system call）和庫函式呼叫(Library function call)的區別？