strace指令

strace指令是一個集診斷、調試、統計與一體的工具，我們可以使用strace對應用的系統調用和信号傳遞的跟蹤結果來對應用進行分析，以達到解決問題或者是了解應用工作過程的目的。當然strace與專業的調試工具比如說gdb之類的是沒法相比的，因為它不是一個專業的調試器。

strace的最簡單的用法就是執行一個指定的指令，在指定的指令結束之後它也就退出了。在指令執行的過程中，strace會記錄和解析指令程序的所有系統調用以及這個程序所接收到的所有的信号值。

文法

strace  [  -dffhiqrtttTvxx  ] [ -acolumn ] [ -eexpr ] ...
    [ -ofile ] [-ppid ] ...  [ -sstrsize ] [ -uusername ]
    [ -Evar=val ] ...  [ -Evar  ]...
    [ command [ arg ...  ] ]

strace  -c  [ -eexpr ] ...  [ -Ooverhead ] [ -Ssortby ]
    [ command [ arg...  ] ]

選項

-c 統計每一系統調用的所執行的時間,次數和出錯的次數等.
-d 輸出strace關于标準錯誤的調試資訊.
-f 跟蹤由fork調用所産生的子程序.
-ff 如果提供-o filename,則所有程序的跟蹤結果輸出到相應的filename.pid中,pid是各程序的程序号.
-F 嘗試跟蹤vfork調用.在-f時,vfork不被跟蹤.
-h 輸出簡要的幫助資訊.
-i 輸出系統調用的入口指針.
-q 禁止輸出關于脫離的消息.
-r 列印出相對時間關于,,每一個系統調用.
-t 在輸出中的每一行前加上時間資訊.
-tt 在輸出中的每一行前加上時間資訊,微秒級.
-ttt 微秒級輸出,以秒了表示時間.
-T 顯示每一調用所耗的時間.
-v 輸出所有的系統調用.一些調用關于環境變量,狀态,輸入輸出等調用由于使用頻繁,預設不輸出.
-V 輸出strace的版本資訊.
-x 以十六進制形式輸出非标準字元串
-xx 所有字元串以十六進制形式輸出.
-a column 設定傳回值的輸出位置.預設 為40.
-e expr 指定一個表達式,用來控制如何跟蹤.格式：[qualifier=][!]value1[,value2]...
qualifier隻能是 trace,abbrev,verbose,raw,signal,read,write其中之一.value是用來限定的符号或數字.預設的 qualifier是 trace.感歎号是否定符号.例如:-eopen等價于 -e trace=open,表示隻跟蹤open調用.而-etrace!=open 表示跟蹤除了open以外的其他調用.有兩個特殊的符号 all 和 none. 注意有些shell使用!來執行曆史記錄裡的指令,是以要使用\\.
-e trace=set 隻跟蹤指定的系統 調用.例如:-e trace=open,close,rean,write表示隻跟蹤這四個系統調用.預設的為set=all.
-e trace=file 隻跟蹤有關檔案操作的系統調用.
-e trace=process 隻跟蹤有關程序控制的系統調用.
-e trace=network 跟蹤與網絡有關的所有系統調用.
-e strace=signal 跟蹤所有與系統信号有關的 系統調用
-e trace=ipc 跟蹤所有與程序通訊有關的系統調用
-e abbrev=set 設定strace輸出的系統調用的結果集.-v 等與 abbrev=none.預設為abbrev=all.
-e raw=set 将指定的系統調用的參數以十六進制顯示.
-e signal=set 指定跟蹤的系統信号.預設為all.如 signal=!SIGIO(或者signal=!io),表示不跟蹤SIGIO信号.
-e read=set 輸出從指定檔案中讀出 的資料.例如: -e read=3,5
-e write=set 輸出寫入到指定檔案中的資料.
-o filename 将strace的輸出寫入檔案filename
-p pid 跟蹤指定的程序pid.
-s strsize 指定輸出的字元串的最大長度.預設為32.檔案名一直全部輸出.
-u username 以username的UID和GID執行被跟蹤的指令

執行個體

追蹤系統調用

現在我們做一個很簡單的程式來示範strace的基本用法。這個程式的C語言代碼如下：

# filename test.c
#include <stdio.h>
 
int main()
{
    int a;
    scanf("%d", &a);
    printf("%09d\n", a);
    return 0;
}

然後我們用

gcc -o test test.c

編譯一下，得到一個可執行的檔案test。然後用strace調用執行：

strace ./test

執行期間會要求你輸入一個整數，我們輸入99，最後得到如下的結果：

// 直接執行test的結果
oracle@orainst[orcl]:~ $./test

// 執行的結果
99
000000099

// 通過strace執行test的結果
oracle@orainst[orcl]:~ $strace ./test

// 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

，等到等待輸入的畫面的時候不要輸入任何東西，然後打開另外一個視窗，輸入如下的指令

killall test

這時候就能看到我們的程式推出了，最後的trace結果如下：

oracle@orainst[orcl]:~
$strace ./test

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：

strace -c ./test

最後能得到這樣的trace結果：

oracle@orainst[orcl]:~
$strace -c ./test

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”的結果是一樣的。

# 這兩個指令都是将strace結果輸出到檔案test.txt中
strace -c -o test.txt ./test
strace -c ./test  2>test.txt

對系統調用進行計時

strace可以使用參數-T将每個系統調用所花費的時間列印出來，每個調用的時間花銷現在在調用行最右邊的尖括号裡面。

oracle@orainst[orcl]:~
$strace -T ./test

// 這裡隻摘錄部分結果
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個字元的數字串

strace -s 20 ./test

read(0, 2222222222222222222222222      // 我們輸入的2一共有25個
"22222222222222222222"..., 1024) = 26  // 而我們看到的結果中2隻有20個

trace一個現有的程序

strace不光能自己初始化一個程序進行trace，還能追蹤現有的程序，參數-p就是取這個作用的，用法也很簡單，具體如下。

strace -p pid

綜合例子

說了那麼多的功能和參數，現在我們來一個實用點的，就是研究下Oracle的lgwr程序，看看這個程序是不是像文檔所說的那樣沒3s鐘寫一次log檔案，考慮到lgwr寫日志的觸發條件比較多，我們需要找一個空閑的Oracle執行個體做這個實驗。

我們先要得到lgwr程序的pid，運作下面的指令

ps -ef|grep lgwr

oracle    5912     1  0 Nov12 ?        00:14:56 ora_lgwr_orcl

得到lgwr的pid是5912，現在啟動strace，然後将trace的幾個輸出到lgwr.txt檔案中，執行下面的指令

strace -tt -s 10 -o lgwr.txt -p 5912

過一會之後停止strace，然後檢視結果。由于輸出的結果比較多，為了友善我們隻看Oracle寫入log檔案時用的pwrite函數的調用

grep pwrite\(20 lgwr.txt

等等，為什麼grep的時候用的是”pwrite(2″呢？，因為我知道我這個機器打開的目前的log檔案的句柄編号都是2開始的。具體查找方法是先使用下面的語句找出目前活動的日志檔案都有哪些：

select member, v$log.status from v$log, v$logfile
where v$log.group#=v$logfile.group#;

得到

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中去找打開檔案的句柄：

ll /proc/.5912/fd/

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

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

作者：柒月

strace指令

文法

選項

執行個體

常用參數說明

綜合例子

繼續閱讀

使用JDeveloper Remote debug PLSQL程式

LoadRunner 的多種Vuser類型

淺談MFC CSting類拼接效率

性能測試（并發負載壓力）測試分析－簡要篇

C和java中關于字元串與字元數組的定義和轉化

c++十六進制轉十進制

Java：String類字元串與數組之間的轉換

Java中 byte[] 數組與 String 字元串的轉化

賦予使用者dba權限--解釋以上：

Oracle的基本操作

回文樹學習小結

為什麼要選擇UniDAC

查找檔案中的字元串

windows不能在本地計算機上運作oracleDbConsoleorcl

SQL語言基礎：常用的資料查詢語句

Oracle 批量查詢傳入List 傳回List