Linuxデバッグコマンド strace の基本的な使い方
プロセスに attach してトレースするデバッグコマンド strace の基本的な使い方です。
1. 実行コマンドをトレースする
$ strace ls execve("/bin/ls", ["ls"], [/* 46 vars */]) = 0 brk(0) = 0x1ab9000 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory) mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fcf695fb000 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory) open("/etc/ld.so.cache", O_RDONLY) = 3 fstat(3, {st_mode=S_IFREG|0644, st_size=102786, ...}) = 0 mmap(NULL, 102786, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fcf695e1000 close(3) = 0 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory) open("/lib/librt.so.1", O_RDONLY) = 3 (省略)
2. 実行中のプロセスをトレースする
p オプションで PID を指定して strace します。
$ strace -p 2097
権限のないプロセスを strace すると、以下のようなエラーになります。
$ strace -p 2129 attach: ptrace(PTRACE_ATTACH, ...): Operation not permitted
3. 特定のシステムコールのみをトレースする
特定のシステムコールに絞ってトレースする場合は、 e オプションを使用します。
サンプルとして、システムコール open に絞ってトレースしてみます。
$ strace -e open ls open("/etc/ld.so.cache", O_RDONLY) = 3 open("/lib/librt.so.1", O_RDONLY) = 3 open("/lib/libselinux.so.1", O_RDONLY) = 3 open("/lib/libacl.so.1", O_RDONLY) = 3 open("/lib/libc.so.6", O_RDONLY) = 3 (省略)
複数のシステムコールをトレースする場合は、以下のような感じです。
$ strace -e trace=open,read ls open("/etc/ld.so.cache", O_RDONLY) = 3 open("/lib/librt.so.1", O_RDONLY) = 3 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\220!\0\0\0\0\0\0"..., 832) = 832 open("/lib/libselinux.so.1", O_RDONLY) = 3 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\20Y\0\0\0\0\0\0"..., 832) = 832
4. トレース結果をファイルに出力する
o オプションでトレース結果を出力するファイル名を指定します。
$ strace -o strace-output.txt ls
p プロセスと一緒に使うと、ファイルに出力しながら実行中のプロセスをトレースすることができます。
$ strace -p 2097 -o strace-output.txt $ tail -f strace-output.txt
5. トレース結果にタイムスタンプを出力する
t オプションでシステムコールの実行時間が出力されます。
$ strace -t ls 17:43:25 execve("/bin/ls", ["ls"], [/* 47 vars */]) = 0 17:43:25 brk(0) = 0x8ad000 17:43:25 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory) 17:43:25 mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb41137b000 17:43:25 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
r オプションでシステムコールが処理にかかった時間が出力されます。
$ strace -r ls 0.000000 execve("/bin/ls", ["ls"], [/* 47 vars */]) = 0 0.000287 brk(0) = 0x1dab000 0.000052 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory) 0.000057 mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7ffadfb22000 0.000049 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
6. トレース結果の統計情報(サマリー)を出力する
c オプションで統計情報が出力されます。
$ strace -c ls % time seconds usecs/call calls errors syscall ------ ----------- ----------- --------- --------- ---------------- -nan 0.000000 0 11 read -nan 0.000000 0 4 write -nan 0.000000 0 26 1 open -nan 0.000000 0 27 close -nan 0.000000 0 25 fstat -nan 0.000000 0 39 mmap -nan 0.000000 0 16 mprotect -nan 0.000000 0 4 munmapstrace コマンドを使うと、 -nan 0.000000 0 3 brk -nan 0.000000 0 2 rt_sigaction -nan 0.000000 0 1 rt_sigprocmask -nan 0.000000 0 2 ioctl -nan 0.000000 0 9 9 access -nan 0.000000 0 1 execve -nan 0.000000 0 1 fcntl -nan 0.000000 0 2 getdents -nan 0.000000 0 1 getrlimit -nan 0.000000 0 1 statfs -nan 0.000000 0 1 arch_prctl -nan 0.000000 0 3 1 futex -nan 0.000000 0 1 set_tid_address -nan 0.000000 0 1 set_robust_list ------ ----------- ----------- --------- --------- ---------------- 100.00 0.000000 181 11 total
strace コマンドを使うと、何気に使っているコマンドが、どのようなシステムコールやライブラリを呼び出しているかトレースできるので意外な発見があるかもしれません。
他にも様々なオプションがあるので、いろいろ試してみると勉強になると思います。
