strace

中午在 ijliao 的 del.icio.us 書籤上看到介紹 strace 的文章 (Fun with strace and the GDB Debugger)，就到 ports 裝起來 (在 devel/strace)，發現比起 FreeBSD 的 ktrace & dump 好用不少。

裝好 strace 後可以簡單玩看看：

$ strace id

應該會出現像這樣開頭一長串的資訊：

execve(0xbfbfe240, [0xbfbfe710], [/* 0 vars */]) = 0
mmap(0, 3616, PROT_READ|PROT_WRITE, MAP_ANON, -1, 0) = 0x28070000
munmap(0x28070000, 3616)                = 0
__sysctl([...], 0x2806cb58, 0xbfbfe4c4, NULL, 0) = 0

有時候不會出現是因為 id 已經先結束了，strace 才去 trace，這時候就會出現錯誤訊息：

execve(0xbfbfe240, [0xbfbfe710], [/* 0 vars */]PIOCWSTOP: Input/output error

除了對於還沒執行的指令另外，你還可以追正在執行的 process，譬如拿我的 ssh-agent 來當白老鼠，他的 pid 是 1156：

$ strace -p 1156
Process 1156 attached - interrupt to quit
accept(3, {...}, 0xbfbfe4dc)            = 4
getsockopt(4, IPPROTO_IP, IP_OPTIONS, 0xbfbfe3f0, 0xbfbfe3ec) = 0
getuid()                                = 1000 (euid 1000)
fcntl(4, F_GETFL)                       = 0x6 (flags O_RDWR|O_NONBLOCK)
select(5, [3 4], [], NULL, NULL)        = 1 (in [4])

按 Ctrl-C 就可以跳出來停止追蹤。

有時候你想要知道這些 syscall 花了多少時間：

$ strace -p 1156 -T
Process 1156 attached - interrupt to quit
accept(3, {...}, 0xbfbfe4dc)            = 4 <0.000123>
getsockopt(4, IPPROTO_IP, IP_OPTIONS, 0xbfbfe3f0, 0xbfbfe3ec) = 0 <0.000042>
getuid()                                = 1000 (euid 1000) <0.000036>
fcntl(4, F_GETFL)                       = 0x6 (flags O_RDWR|O_NONBLOCK) <0.000049>
select(5, [3 4], [], NULL, NULL)        = 1 (in [4]) <0.000033>

或者想要知道每個 syscall 是什麼時候被叫用的：

$ strace -p 1156 -tt
Process 1156 attached - interrupt to quit
03:48:35.412544 accept(3, {...}, 0xbfbfe4dc) = 4
03:48:35.413028 getsockopt(4, IPPROTO_IP, IP_OPTIONS, 0xbfbfe3f0, 0xbfbfe3ec) = 0
03:48:35.413160 getuid()                = 1000 (euid 1000)
03:48:35.413258 fcntl(4, F_GETFL)       = 0x6 (flags O_RDWR|O_NONBLOCK)
03:48:35.413365 select(5, [3 4], [], NULL, NULL) = 1 (in [4])

這些都是蠻基本的功能，但對於 debug 或 benchmark 很有用，像是 lighttpd 就用 strace 找出是哪邊浪費掉了時間：reducing Requests-Setup-Costs。(當然，裡面也有一些 strace 的範例可以看)

其他的功能可以直接打 strace 看到說明，或是直接看 manual (man strace)，裡面也寫的蠻詳細的。