はじめに
DTrace とは
皆さんは DTrace をご存知でしょうか？
DTrace は Sun Microsystems のブライアン・
キャントリル氏へのインタビューでも語られているように、
しかし、
また、
カーネル開発に関わったことがある方ならもちろん、
- リリース用のバイナリで発生するバグが、
ログ出力するデバッグ用バイナリだと発生しない - デバッグ用バイナリは、
実行が遅くて作業が進まない - 速度低下が怖くて、
稼動中のシステムでは解析用のログ出力を有効にできない - 丁度良い量／
内容のログを採取するのが難しい
利用可能OSの広がり
DTraceはもちろんSolaris10／
さらにこれらSolarisプラットフォーム以外でも、
- FreeBSD
（7. 1-RELEASEから公式サポート ） - MacOS X
（ ja. wikipedia. org/ wiki/ DTrace">10. 5 Leopardからサポート）
利用者の多い Linux では、
本特集の対象読者
カーネルのパフォーマンスチューニングや、
そこでこの連載では、
- 開発
- テスト／
障害解析 - 性能チューニング
などに関わる方を対象に、
なお、
DTrace Day 2010.03 開催のお知らせ
筆者も何コマか発表を担当しており、
事前準備
本特集での説明を読みながら、
ルート権限
繰り返しになりますが、
その反面、
そのため、
しかし幸いなことに、
もちろん、
プログラム開発環境
連載後半では、
また、
C++プログラマの方へ
本特集は
しかし、
符号化された関数名は、
このような用途には、c++filt やdemコマンドなどが使用可能
コマンド実行時の関数フロー採取
まずはコマンド実行時の関数フローを採取してみましょう。
エディタ等を使用して、
watch_flow_whole.d ）pid$target:$1::entry,
pid$target:$1::return
{
}これはDTraceによるトレース採取手順を書いたもので、
上記Dスクリプトをwatch_という名前で保存したなら、
$ dtrace -s ./watch_flow_whole.d \
-F \
-o /tmp/trace.log \
-c '/bin/ls -l' \
ls
dtrace: script './watch_flow_whole.d' matched 63 probes
....
dtrace: pid 11077 has exited
実行結果の前後に見慣れないメッセージが表示されはします/bin/'が実行されたことと思います。
それでは/tmp/ファイル
/tmp/trace.log ）CPU FUNCTION
0 -> _start
0 -> __fsr
0 <- __fsr
0 -> main
0 -> gstat
0 <- gstat
0 -> pem
0 <- pem
0 -> new_line
0 <- new_line
0 -> pdirectory
0 -> rddir
0 -> makename
0 <- makename
........（以下略）
ファイルに記録されているのは、/bin/' を実行した際の'/bin/' コマンド内部での関数呼び出しフローです。
呼び出されてすぐに復帰している関数new_）pdirectory）
ここで重要なのは、/bin/' が、-p オプション付きでビルドされたわけでも、-g オプション付きでビルドされたわけでもない、ごく普通のバイナリファイル
D スクリプト／コマンド行指定の詳細
それではここで先ほどの実行例にいったん戻って、
まずはコマンド行から見て行きましょう。
dtrace -s ./watch_flow_whole.d \
-F \
-o /tmp/trace.log \
-c '/bin/ls -l' \
ls
コマンド行の各要素は、
-s |
実行するDスクリプトが格納されているファイル指定します。 本実行例ではファイル watch_からDスクリプトを読み込みます。 |
|---|---|
-F |
採取されたトレースを表示する際に、 |
-o |
採取したトレースの書き出し先を指定します。すでにファイルが存在する場合、 本実行例では、 /tmp/に採取したトレースが書き出されます。 |
-c |
dtrace 実行に先立って指定されたコマンドを新規に実行します。コマンド実行が完了した段階で dtrace 実行も終了します。 コマンドに対して引数を指定する場合は、 -c オプションに対する単一値として指定してください。 |
上記のオプション記述以降は、
この実行例では、ls"という引数が1つ指定され、
では次に、
watch_flow_whole.d ）pid$target:$1::entry,
pid$target:$1::return
{
}Dスクリプトの各要素は、
pid |
プロセスIDで指定されたユーザプロセスにおける、pid の後ろに続く部分$target） |
|---|---|
$target |
dtraceコマンドの-cオプションで指定されたコマンドを実行する際のプロセスIDで置換されます。本実行例では、 /bin/'
を実行するプロセスのプロセス ID で置換されます。
|
$1 |
この位置には、$1 は、本実行例では、 lsで置換されます。 |
entry |
関数の呼び出しを監視することを意味します。 |
return |
関数からの復帰を監視することを意味します。 |
{} |
波括弧の中には、 本実行例では特に何もしませんので、 |
つまり今回のdtraceコマンド実行は、
- '
/bin/'実行時の関数トレースを採取ls -l - トレース採取対象は
lsバイナリファイルに含まれる情報 - 関数の出入りを共に監視
- 関数呼び出しの深さに応じて字下げを実施
実行中プロセスの関数フロー採取
先のDスクリプトの説明を見て
$targetの代わりに直接プロセスIDを指定すれば、実行中プロセスの関数フローも採取できるのでは？
と思われた方もいることでしょう。
ご想像の通り、
watch_flow_attach.d ）pid$1:$2::entry,
pid$1:$2::return
{
}先のDスクリプトとは以下のような違いこそありますが、
- プロセスIDの指定に
$targetではなく、第1引数と置換される $1を使用 - トレース採取対象とするバイナリファイル名に、
第1引数と置換される $1ではなく、第2引数と置換される $2を使用
それでは、
採取対象としては、
dtraceコマンド実行における重要な情報は、
$ dtrace -s ./watch_flow_attach.d \
-F \
PID \
FILENAME
dtraceコマンド経由でlsコマンドを起動した先の例と異なり、-oオプションを省略してみました。
採取対象で何らかの処理が行われるつど、
なお、
追記
dtrace コマンド起動の際に、-c オプションによるコマンド指定の代わりに、-p オプションによるプロセスID指定を行えば、watch_スクリプトをそのまま使用することができますし、dtraceコマンドも終了します。
ただし、dbx等のデバッガでattach中のプロセスに対しては、
関数フローの不整合
大変手軽に採取できる関数フローですが、
たとえば、
static void f1(){ /* nop */ }
static void f2(){ f1(); }
static void f3(){ f1(); f2(); }
int
main(int argc,
const char* argv[])
{
f3();
return 0;
}特にオプション指定をしないコンパイル結果のバイナリファイルからは、
0 -> main
0 -> f3
0 -> f1
0 <- f1
0 -> f2
0 -> f1
0 <- f1
0 <- f2
0 <- f3
0 <- main見ての通り、
しかし、-O3を指定して生成したバイナリファイルや、-O4を指定して生成したバイナリファイルからは、
-O3最適化時の関数フロー 0 -> main
0 -> f3
0 -> f1
0 <- f1
0 <- f3
0 -> f2
0 <- f2
0 -> f1
0 <- f1
0 <- main-O4最適化時の関数フロー 0 -> main
0 <- main関数フロー出力において、
コンパイラの最適化技法の話に踏み込むことになりますので、
次回予告
まずは手始めに実行時関数フローを採取してみましたが、
次回は、