トップ > IT > システムコールをトレースするツール (BINARY HACKS)

システムコールをトレースするツール (BINARY HACKS)

IT Linux

六本木ヒルズ


UNIX/Linuxには、システムコールをトレースする「strace」と呼ばれる古から伝わる素晴らしいツールがあります。


ところで、私が会社内で開発・運用している社内SNSは、Ruby on Railsと呼ばれるフレームワークを使って開発しており、それをlighttpd + FastCGIの上で動かしています。OSは、Debian GNU/Linux(Etch)を使っています。


口コミでユーザ数も増え続け、順調に成長しつつあるのですが、今年に入ってから、2度ばかり原因不明の接続不能状態に陥る状態が起こりました。


状況としては、ログからlighttpdが問題なく稼動できている部分までは確認していて、FastCGIの処理受付(got)のログはあるものの処理完了(release)のログが刻まれていないという感じ。

最初に発生したときは、さっぱり原因が分からず、復旧を優先。FastCGIをデバッグモードで稼動させて臨んだ2回目は、上記以上の大きな収穫は得られず、復旧を優先させたため、再度苦渋を舐めるはめに。


というわけで、最近straceの存在を知り、少しずつ勉強をしています。
システムでは、未だ原因不明のため再現待ちの状態です。次に再現したときにstraceを使って原因に近づいてみようという作戦。

次に再現したときに、調査を行う時間を確保するために、システムの最前面にApache2.2によるリバースプロキシ＋ロードバランサ(mod_proxy_balancer)を設置し、AP処理部分の可用性を高めてみました。


さて、まずインストール。


Debian GNU/Linuxの場合は、、、

$ sudo apt-get install strace

で完了。aptが超便利。
早速、オプションを指定せずに実行してみると、Usageが表示されます。ヘルプですね。

$ strace
usage: strace [-dffhiqrtttTvVxx] [-a column] [-e expr] ... [-o file]
              [-p pid] ... [-s strsize] [-u username] [-E var=val] ...
              [command [arg ...]]
   or: strace -c [-e expr] ... [-O overhead] [-S sortby] [-E var=val] ...
              [command [arg ...]]
-c -- count time, calls, and errors for each syscall and report summary
-f -- follow forks, -ff -- with output into separate files
-F -- attempt to follow vforks, -h -- print help message
-i -- print instruction pointer at time of syscall
-q -- suppress messages about attaching, detaching, etc.
-r -- print relative timestamp, -t -- absolute timestamp, -tt -- with usecs
-T -- print time spent in each syscall, -V -- print version
-v -- verbose mode: print unabbreviated argv, stat, termio[s], etc. args
-x -- print non-ascii strings in hex, -xx -- print all strings in hex
-a column -- alignment COLUMN for printing syscall results (default 40)
-e expr -- a qualifying expression: option=[!]all or option=[!]val1[,val2]...
   options: trace, abbrev, verbose, raw, signal, read, or write
-o file -- send trace output to FILE instead of stderr
-O overhead -- set overhead for tracing syscalls to OVERHEAD usecs
-p pid -- trace process with process id PID, may be repeated
-s strsize -- limit length of print strings to STRSIZE chars (default 32)
-S sortby -- sort syscall counts by: time, calls, name, nothing (default time)
-u username -- run command as username handling setuid and/or setgid
-E var=val -- put var=val in the environment for command
-E var -- remove var from the environment for command

straceは、OSの提供するデバッグ用インターフェース(Linuxではptrace)を用いてシステムコールをトレースしているそうです。
このstraceの仕組みや動きについては、straceをstraceするとよ〜く分かります(笑)


例えば、emacsを実行中のシステムコールの呼び出しをトレースしたい場合などは、

$ strace -o log.txt emacs

と実行し、emacs上での作業を終えた後に、log.txtを見ることで、emacsがどのようなシステムコールを呼んだのかが分かります。


以下は、emacsを起動した後に終了しただけなのですが、参照されたファイルがこんなにもあるという例です。

$ grep open log.txt
open("/etc/ld.so.preload", O_RDONLY)    = -1 ENOENT (No such file or directory)
open("/usr/X11R6/lib/libXaw3d.so.6", O_RDONLY) = 3
open("/usr/X11R6/lib/libXmu.so.6", O_RDONLY) = 3
open("/usr/X11R6/lib/libXt.so.6", O_RDONLY) = 3
open("/usr/X11R6/lib/libSM.so.6", O_RDONLY) = 3
open("/usr/X11R6/lib/libICE.so.6", O_RDONLY) = 3
open("/usr/X11R6/lib/libXext.so.6", O_RDONLY) = 3
open("/usr/X11R6/lib/libtiff.so.4", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY)      = 3
open("/usr/lib/libtiff.so.4", O_RDONLY) = 3
open("/usr/X11R6/lib/libjpeg.so.62", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/lib/libjpeg.so.62", O_RDONLY) = 3
open("/usr/X11R6/lib/libpng12.so.0", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/lib/libpng12.so.0", O_RDONLY) = 3
open("/usr/X11R6/lib/libz.so.1", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/lib/libz.so.1", O_RDONLY)    = 3
open("/usr/X11R6/lib/libm.so.6", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/lib/libm.so.6", O_RDONLY)        = 3
open("/usr/X11R6/lib/libungif.so.4", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/lib/libungif.so.4", O_RDONLY) = 3
open("/usr/X11R6/lib/libXpm.so.4", O_RDONLY) = 3
open("/usr/X11R6/lib/libX11.so.6", O_RDONLY) = 3
open("/usr/X11R6/lib/libncurses.so.5", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/lib/libncurses.so.5", O_RDONLY)  = 3
open("/usr/X11R6/lib/libc.so.6", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/lib/libc.so.6", O_RDONLY)        = 3
open("/usr/X11R6/lib/libdl.so.2", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/X11R6/lib/libdl.so.2", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/lib/libdl.so.2", O_RDONLY)       = 3
open("/usr/lib/locale/locale-archive", O_RDONLY|O_LARGEFILE) = 3
open("/usr/lib/gconv/gconv-modules.cache", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/lib/gconv/gconv-modules", O_RDONLY) = 3
open("/usr/lib/gconv/EUC-JP.so", O_RDONLY) = 3
open("/usr/lib/gconv/libJIS.so", O_RDONLY) = 3
open("/usr/share/terminfo/k/kterm", O_RDONLY) = 3
open("/etc/resolv.conf", O_RDONLY)      = 3
open("/etc/nsswitch.conf", O_RDONLY)    = 3
open("/usr/X11R6/lib/libnss_files.so.2", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY)      = 3
open("/lib/libnss_files.so.2", O_RDONLY) = 3
open("/etc/host.conf", O_RDONLY)        = 3
open("/etc/hosts", O_RDONLY)            = 3
open("/usr/X11R6/lib/libnss_compat.so.2", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY)      = 3
open("/lib/libnss_compat.so.2", O_RDONLY) = 3
open("/usr/X11R6/lib/libnsl.so.1", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/lib/libnsl.so.1", O_RDONLY)      = 3
open("/usr/X11R6/lib/libnss_nis.so.2", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY)      = 3
open("/lib/libnss_nis.so.2", O_RDONLY)  = 3
open("/etc/passwd", O_RDONLY)           = 3
open("/etc/passwd", O_RDONLY)           = 3
open("/usr/share/emacs/21.4/site-lisp/subdirs.el", O_RDONLY|O_LARGEFILE) = 3
open("/usr/share/emacs/21.4/site-lisp/subdirs.el", O_RDONLY|O_LARGEFILE) = 3
open("/usr/share/emacs/21.4/site-lisp/subdirs.el", O_RDONLY|O_LARGEFILE) = 3
open("/dev/null", O_RDONLY|O_NONBLOCK|O_DIRECTORY) = -1 ENOTDIR (Not a directory)
open("/usr/share/emacs/21.4/site-lisp", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY) = 3
open("/usr/share/emacs/21.4/site-lisp/dictionaries-common", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY) = 3
open("/usr/share/emacs/21.4/site-lisp/egg", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY) = 3
open("/usr/share/emacs/21.4/site-lisp/egg/leim-list.el", O_RDONLY|O_LARGEFILE) = 3
open("/usr/share/emacs/21.4/site-lisp/egg/leim-list.el", O_RDONLY|O_LARGEFILE) = 3
open("/usr/share/emacs/21.4/site-lisp/egg/leim-list.el", O_RDONLY|O_LARGEFILE) = 3
open("/usr/share/emacs/21.4/leim/leim-list.el", O_RDONLY|O_LARGEFILE) = 3
open("/usr/share/emacs/21.4/leim/leim-list.el", O_RDONLY|O_LARGEFILE) = 3
open("/usr/share/emacs/21.4/leim/leim-list.el", O_RDONLY|O_LARGEFILE) = 3
open("/usr/share/emacs/21.4/lisp/subdirs.el", O_RDONLY|O_LARGEFILE) = 3
open("/usr/share/emacs/21.4/lisp/subdirs.el", O_RDONLY|O_LARGEFILE) = 3
open("/usr/share/emacs/21.4/lisp/subdirs.el", O_RDONLY|O_LARGEFILE) = 3
open("/usr/lib/X11/locale/locale.alias", O_RDONLY|O_LARGEFILE) = 3
open("/usr/share/emacs/21.4/lisp/language/japan-util.elc", O_RDONLY|O_LARGEFILE) = 3
open("/usr/share/emacs/21.4/lisp/disp-table.elc", O_RDONLY|O_LARGEFILE) = 3
open("/usr/share/emacs/21.4/site-lisp/debian-startup.elc", O_RDONLY|O_LARGEFILE) = 3
open("/etc/emacs21/site-start.d", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY) = 3
open("/etc/emacs/site-start.d", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY) = 3
open("/etc/emacs21/site-start.d/00debian-vars.elc", O_RDONLY|O_LARGEFILE) = 3
open("/etc/mailname", O_RDONLY|O_LARGEFILE) = 4
open("/etc/mailname", O_RDONLY|O_LARGEFILE) = 4
open("/etc/emacs/site-start.d/50dictionaries-common.el", O_RDONLY|O_LARGEFILE) = 3
open("/etc/emacs/site-start.d/50dictionaries-common.el", O_RDONLY|O_LARGEFILE) = 3
open("/etc/emacs/site-start.d/50dictionaries-common.el", O_RDONLY|O_LARGEFILE) = 3
open("/var/cache/dictionaries-common/emacsen-ispell-dicts.el", O_RDONLY|O_LARGEFILE) = 3
open("/var/cache/dictionaries-common/emacsen-ispell-dicts.el", O_RDONLY|O_LARGEFILE) = 3
open("/var/cache/dictionaries-common/emacsen-ispell-dicts.el", O_RDONLY|O_LARGEFILE) = 3
open("/usr/share/emacs21/site-lisp/dictionaries-common/debian-ispell.elc", O_RDONLY|O_LARGEFILE) = 3
open("/var/cache/dictionaries-common/emacsen-ispell-default.el", O_RDONLY|O_LARGEFILE) = 4
open("/var/cache/dictionaries-common/emacsen-ispell-default.el", O_RDONLY|O_LARGEFILE) = 4
open("/var/cache/dictionaries-common/emacsen-ispell-default.el", O_RDONLY|O_LARGEFILE) = 4
open("/etc/emacs21/site-start.d/50egg-init.el", O_RDONLY|O_LARGEFILE) = 3
open("/etc/emacs21/site-start.d/50egg-init.el", O_RDONLY|O_LARGEFILE) = 3
open("/etc/emacs21/site-start.d/50egg-init.el", O_RDONLY|O_LARGEFILE) = 3
open("/etc/emacs/site-start.el", O_RDONLY|O_LARGEFILE) = 3
open("/etc/emacs/site-start.el", O_RDONLY|O_LARGEFILE) = 3
open("/etc/emacs/site-start.el", O_RDONLY|O_LARGEFILE) = 3
open("/home/rx7/.emacs", O_RDONLY|O_LARGEFILE) = 3
open("/home/rx7/.emacs", O_RDONLY|O_LARGEFILE) = 3
open("/home/rx7/.emacs", O_RDONLY|O_LARGEFILE) = 3
open("/usr/share/emacs/21.4/lisp/international/encoded-kb.elc", O_RDONLY|O_LARGEFILE) = 3
open("/usr/share/emacs/21.4/lisp/jka-compr.elc", O_RDONLY|O_LARGEFILE) = 3
open("/usr/share/emacs21/site-lisp/egg/egg/canna.elc", O_RDONLY|O_LARGEFILE) = 3
open("/usr/share/emacs21/site-lisp/egg/egg.elc", O_RDONLY|O_LARGEFILE) = 4
open("/usr/share/emacs21/site-lisp/egg/egg-edep.elc", O_RDONLY|O_LARGEFILE) = 5
open("/usr/share/emacs21/site-lisp/egg/its.elc", O_RDONLY|O_LARGEFILE) = 5
open("/usr/share/emacs21/site-lisp/egg/its-keydef.elc", O_RDONLY|O_LARGEFILE) = 6
open("/usr/share/emacs21/site-lisp/egg/menudiag.elc", O_RDONLY|O_LARGEFILE) = 5
open("/usr/share/emacs21/site-lisp/egg/egg-mlh.elc", O_RDONLY|O_LARGEFILE) = 5
open("/usr/share/emacs21/site-lisp/egg/egg-cnv.elc", O_RDONLY|O_LARGEFILE) = 5
open("/usr/share/emacs21/site-lisp/egg/egg-com.elc", O_RDONLY|O_LARGEFILE) = 5
open("/usr/share/emacs21/site-lisp/egg/egg/cannarpc.elc", O_RDONLY|O_LARGEFILE) = 4
open("/usr/share/emacs21/site-lisp/egg/its/hira.elc", O_RDONLY|O_LARGEFILE) = 3
open("/usr/share/emacs/21.4/lisp/font-lock.elc", O_RDONLY|O_LARGEFILE) = 3
open("/usr/share/emacs/21.4/lisp/emacs-lisp/regexp-opt.elc", O_RDONLY|O_LARGEFILE) = 4
open("/usr/share/emacs/21.4/lisp/jit-lock.elc", O_RDONLY|O_LARGEFILE) = 4
open("/proc/loadavg", O_RDONLY)         = 5
open("/proc/loadavg", O_RDONLY)         = 5
open("/etc/localtime", O_RDONLY)        = 3
open("/home/rx7/.emacs.d/auto-save-list/.saves-394-KURO-BOX~", O_WRONLY|O_CREAT|O_TRUNC|O_LARGEFILE, 0666) = -1 ENOENT (No such file or directory)

もちろん、上はシステムコールのうち"open"のみをgrepしただけですので、実際にはもっとたくさんのシステムコールが呼ばれています。


ちなみにここの書いてあることは、以下の「BINARY HACKS」を参考にしています。
興味のある方は是非どうぞ！
# ちょっと前ですが、私もようやく購入しました。バイナリアン・・・。


Binary Hacks ―ハッカー秘伝のテクニック100選

Binary Hacks ―ハッカー秘伝のテクニック100選

  • 作者: 高林哲,鵜飼文敏,佐藤祐介,浜地慎一郎,首藤一幸
  • 出版社/メーカー: オライリー・ジャパン
  • 発売日: 2006/11/14
  • メディア: 単行本（ソフトカバー）
  • 購入: 23人 クリック: 383回
  • この商品を含むブログ (223件) を見る

rx7 読者になる

関連記事
コメントを書く