2010年9月30日　ユーザランドDTrace登場

heads-up

Rui Paulo氏が開発を進めてきたユーザランドDTraceの機能が9-CURRENTにマージされました。2010年9月26日以降の9-CURRENTで利用できます。安定版ブランチではFreeBSD 8.2および7.4で登場することになる見通しです。FreeBSDは7.0からDTraceをサポートしていますが、これまでサポートしていたのはカーネルにおけるDTraceでした。今回ユーザランドDTraceが導入されたことで、プロセスを指定して内部の動作を詳しく調査することが可能になります。

DTraceを利用するには、次の設定をカーネルオプションファイルに追加してカーネルを再構築する必要があります。i386を使っている場合にはKDTRACE_FRAMEは不要です。amd64を使ってる場合にはKDTRACE_FRAMEが必要になります。

リスト　DTraceを使用するためのカーネルオプション

makeoptions     WITH_CTF=1
options         KDTRACE_FRAME
options         KDTRACE_HOOKS
options         DDB_CTF

DTraceに対応したカーネルを起動したら、kldload(8)でdtraceallカーネルモジュールを読み込ませます。

図　DTrace関連のカーネルモジュールを読み込み

# kldload dtraceall

以後、ユーザランドDTraceの機能を利用できます。ユーザランドDTraceの動作を手っ取り早く確認するにはdtruss(1)コマンドが便利です。これは指定されたプロセスやコマンドのシステムコールやユーザランドスタックの動きをトレースして表示するというものです。

図　dtruss(1)でtrue(1)コマンドの動きをトレースした場合

# dtruss -a true
PID/LWP    RELATIVE  ELAPSD    CPU SYSCALL(args) 		 = return
 70043/100531:        54     144      4 mmap(0x0, 0x8000, 0x3)		 = 5443584 0
 70043/100531:        61       3      0 issetugid(0x0, 0x0, 0x0)		 = 0 0
 70043/100531:        87      18     14 open("/etc/libmap.conf\0", 0x0, 0x1B6)		 = -1 Err#2
 70043/100531:        99      11      9 open("/var/run/ld-elf.so.hints\0", 0x0, 0x2F)		 = 3 0
 70043/100531:       106       9      6 read(0x3, "Ehnt\001\0", 0x80)		 = 128 0
 70043/100531:       452     140      0 sigprocmask(0x1, 0x800639360, 0x7FFFFFFFE380)		 = 0x0 0
 70043/100531:       455       2      0 sigprocmask(0x3, 0x800639370, 0x0)		 = 0x0 0
 70043/100531:       505       2      0 sigprocmask(0x1, 0x800639360, 0x7FFFFFFFE350)		 = 0x0 0
 70043/100531:       506       1      0 sigprocmask(0x3, 0x800639370, 0x0)		 = 0x0 0
 70043/100531:       528       2      0 sigprocmask(0x1, 0x800639360, 0x7FFFFFFFE9C0)		 = 0x0 0
 70043/100531:       528       1      0 sigprocmask(0x3, 0x800639370, 0x0)		 = 0x0 0
 70043/100531:       535       2      0 sigprocmask(0x1, 0x800639360, 0x7FFFFFFFE970)		 = 0x0 0
 70043/100531:       536       1      0 sigprocmask(0x3, 0x800639370, 0x0)		 = 0x0 0
 70043/100531:       111       3      0 lseek(0x3, 0x80, 0x0)		 = 128 0
 70043/100531:       113       3      1 read(0x3, "/lib:/usr/lib:/usr/lib/compat:/usr/local/lib:/usr/local/lib/compat/pkg:/usr/local/kde4/lib:/usr/local/lib/gegl-0.1:/usr/local/lib/graphviz:/usr/local/lib/nss:/usr/local/lib/qt4:/usr/local/lib/virtualbox:/usr/local/lib/zsh\0", 0xDE)		 = 222 0
 70043/100531:       116       5      2 close(0x3)		 = 0 0
 70043/100531:       129      11      7 access("/lib/libc.so.7\0", 0x0, 0x0)		 = 0 0
 70043/100531:       133       5      3 open("/lib/libc.so.7\0", 0x0, 0x63A480)		 = 3 0
 70043/100531:       137       5      3 fstat(0x3, 0x7FFFFFFFE2D0, 0x0)		 = 0 0
 70043/100531:       146       8      5 pread(0x3, "\177ELF\002\001\001\t\0", 0x1000)		 = 4096 0
 70043/100531:       149       2      1 mmap(0x0, 0x247000, 0x0)		 = 6582272 0
 70043/100531:       155       7      6 mmap(0x800647000, 0x10D000, 0x5)		 = 6582272 0
 70043/100531:       165      11      9 mmap(0x800853000, 0x20000, 0x3)		 = 8728576 0
 70043/100531:       172       3      0 mprotect(0x800873000, 0x1B000, 0x3)		 = 0 0
 70043/100531:       187       3      1 close(0x3)		 = 0 0
 70043/100531:       193       3      0 sysarch(0x81, 0x7FFFFFFFE3B0, 0x0)		 = 0 0
 70043/100531:       196       4      1 munmap(0x800538000, 0x1000)		 = 0 0
 70043/100531:       198       2      1 mmap(0x0, 0x19000, 0x3)		 = 5472256 0

CALL                                        COUNT
access                                          1
exit                                            1
fstat                                           1
issetugid                                       1
lseek                                           1
mprotect                                        1
munmap                                          1
pread                                           1
sysarch                                         1
close                                           2
read                                            2
open                                            3
mmap                                            5
sigprocmask                                     8
#

D言語を使ってユーザランドアプリケーションのどの動作をトレースするかを示した簡単なサンプルがDTrace - FreeBSD Wikiに掲載されています。次のような1秒スリープを繰り返すプログラムをトレースするというものです。ここではsleep-loopとしてコンパイルしておきます。

リスト　sleep-loop.c

int
main()
{
	for (;;)
		sleep(1);
}

main関数とsleep関数に入った段階でその旨を出力するスクリプトを書きます。

リスト　pid.d

pid$target:sleep-loop:main:entry
{
}
pid$target:libc.so.7:sleep:entry
{
}

この2つを指定してdtrace（1m）を実行すると、sleep-loopの動作から指定された内容をトレースして次のように出力されます。

図　drace(1m)コマンドの実行例

# dtrace -s pid.d -c ./sleep-loop
dtrace: script 'pid.d' matched 2 probes
CPU     ID                    FUNCTION:NAME
  2  46068                       main:entry 
  0  46069                     _sleep:entry 
  0  46069                     _sleep:entry 
  0  46069                     _sleep:entry 
...

ユーザランドDTraceが使えるようになると大規模で複雑なアプリケーションのデバッグや性能改善などの作業が従来よりも取り組みやすくなります。Ports CollectionのMySQLとPostgreSQLはすでにDTraceに対応したビルドをするためのオプションが取り込まれています。ユーザランドDTraceはアプリケーションやユーティリティの移植作業におけるツールとしても有益です。