本連載では第一線のPerlハッカーが回替わりで執筆していきます。今回のハッカーはMobageオープンプラットフォームの開発に携わっている横江直輔
strace──システムコールレベルでのデバッグツール
straceとは何か
straceとは、
システムコールとは何か
straceでシステムコールの流れをトレースするにあたりシステムコールとは何かという話題を避けては通れませんので、
Linuxを始めとする現代のOSでは、
たとえば、
すべてのシステムコールがそうというわけではありませんが、
- 自分と同じプロセスを複製したい
- →fork(2)を使って新しいプロセスを
「借りる」 - メモリを確保したい
- →brk(2)を使ってメモリ空間を
「借りる」 - ネットワーク通信がしたい
- →socket(2)を使ってネットワークスタックの機能を
「借りる」 - ディスクに書き込みたい
- →open(2)を使ってディスクデバイスを
「借りる」
なお、
straceの使い方
本節では、
straceはCentOSやDebian GNU/
最もシンプルな使い方
straceの最もシンプルな使い方は以下です。$cmdの部分には実行可能なコマンドが入ると考えてください。
$ strace $cmdたとえば$cmdがcat hogeであった場合、
execve("/bin/cat", ["cat", "hoge"], [/* 24 vars */]) = 0
...
（中略）
...
open("hoge", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0664, st_size=13, ...}) = 0
read(3, "This is hoge\n", 32768) = 13
write(1, "This is hoge\n", 13) = 13
read(3, "", 32768) = 0
close(3) = 0
close(1) = 0
close(2) = 0
exit_group(0); = ?なんとなくcat hogeがやっていそうな内容だなぁ」
straceは、=付きで表記されています。たとえば上記の例において、hogeおよびO_であり、3となります。
既存プロセスへのattach
特にWebアプリケーションのデバッグ目的の場合、
$ strace -p $pid表示される内容は先ほどの例とほぼ同じなので、
straceのコマンドラインオプション
ここでは、
-ttオプション──タイムスタンプの表示
-ttオプションを指定することで、
「おおむね」
$ strace -p $pid -tt
15:44:56.351227 accept(4, {sa_family=AF_INET, sin_
port=htons(59812), sin_addr=inet_addr("127.0.0.1")}, [16]) = 5
15:45:00.771790 ioctl(5, SNDCTL_TMR_TIMEBASE or TCGETS, 0x
7fffce10ff10) = -1 EINVAL (Invalid argument)
15:45:00.771872 lseek(5, 0, SEEK_CUR) = -1 ESPIPE (Illeg
al seek)
15:45:00.771937 ioctl(5, SNDCTL_TMR_TIMEBASE or TCGETS, 0x
7fffce10ff10) = -1 EINVAL (Invalid argument)
15:45:00.771972 lseek(5, 0, SEEK_CUR) = -1 ESPIPE (Illeg
al seek)
15:45:00.772001 fcntl(5, F_SETFD, FD_CLOEXEC) = 0
15:45:00.772242 fcntl(5, F_GETFL) = 0x2 (flags O_RDWR)
15:45:00.772324 fcntl(5, F_SETFL, O_RDWR|O_NONBLOCK) = 0
15:45:00.772378 setsockopt(5, SOL_TCP, TCP_NODELAY, [1], 4) = 0
15:45:00.772509 read(5, "GET / HTTP/1.0\r\nHost: xxx-xxxxx
x"..., 131072) = 308straceには-tt以外にも時間表示用のオプションがありますが、
-sオプション──表示する文字列の最大長の指定
-sオプションで数値を指定することにより、
次の出力例では、
$ strace -p $pid -tt -s $strsize
16:33:42.649421 accept(4, {sa_family=AF_INET, sin_port=htons(60
543), sin_addr=inet_addr("127.0.0.1")}, [16]) = 5
16:33:45.630289 ioctl(5, SNDCTL_TMR_TIMEBASE or TCGETS, 0x7fffc
e10ff10) = -1 EINVAL (Invalid argument)
16:33:45.630360 lseek(5, 0, SEEK_CUR) = -1 ESPIPE (Illegal se
ek)
16:33:45.630399 ioctl(5, SNDCTL_TMR_TIMEBASE or TCGETS, 0x7fffc
e10ff10) = -1 EINVAL (Invalid argument)
16:33:45.630432 lseek(5, 0, SEEK_CUR) = -1 ESPIPE (Illegal se
ek)
16:33:45.630461 fcntl(5, F_SETFD, FD_CLOEXEC) = 0
16:33:45.630564 fcntl(5, F_GETFL) = 0x2 (flags O_RDWR)
16:33:45.630607 fcntl(5, F_SETFL, O_RDWR|O_NONBLOCK) = 0
16:33:45.630658 setsockopt(5, SOL_TCP, TCP_NODELAY, [1], 4) = 0
16:33:45.630788 read(5, "GET / HTTP/1.0\r\nHost: xxx-xxxxx
xx.xxxxxx.jp\r\nX-Forwarded-Host: xxx-xxxxxxx.xxxxxx.jp\r\
nX-Forwarded-Server: xxx-xxxxxxx.xxxxxx.jp\r\nX-For
warded-For: 10.4.40.179\r\nX-Forwarded-HTTPS: on\r\nConnec
tion: close\r\nUser-Agent: curl/7.24.0 (x86_64-apple-darwin12.
0) libcurl/7.24.0 OpenSSL/0.9.8y zlib/1.2.5\r\n
Accept: */*\r\n\r\n", 131072) = 308利用上の注意
筆者の経験上、
＜続きの