関数呼び出しにおける基本的な情報採取に関しては、前回までに説明した手法で十分なのですが、実際の情報採取の際には気を付けるべきトピックが幾つかあります。

今回は、それらのトピックについて説明したいと思います。

マルチスレッド

マルチスレッド化によって性能や応答性の向上を実現するケースは、少なくないでしょう。

特に近年は、個人のデスクトップPCやノートPCでさえ、物理的に複数コアのCPUを搭載するご時勢ですので、CPUの使用効率を高める上でもマルチスレッド化の流れは加速するものと思われます。

マルチスレッド稼動時の関数フロー

マルチスレッドで稼働中のプロセスから DTraceで関数フローを採取した場合、どのような出力が得られるでしょうか？

各スレッドで、リスト1に示すような処理を行う状況を仮定します。

void*
running(void* arg)
{
    int loops = (int)arg;
    int i;

    for(i = 0 ; i 

ループ内で呼び出している関数 f3() については、連載第1回のリスト6を参照してください。

この処理を複数のスレッドで実行する際の関数フローを採取してみましょう。関数フロー採取には、リスト2のwatch_flow_whole.dスクリプトを使用します。

pid$target:$1::entry,
pid$target:$1::return
{
}

5つのスレッドを並走させて採取された関数フローの例を、以下に示します（※1⁠）⁠。

CPU FUNCTION
  0  -> _start
  0    -> __fsr
  0    <- __fsr
  0    -> main
  0      -> running
  0        -> running
  0          -> running
  0            -> running
  0              -> running
  0  -> f3
  0    -> f1
  0    <- f1
  0    -> f2
  0      -> f1
  0      <- f1
  0    <- f2
  0  <- f3
  0  -> f3
  0    -> f1
  0    <- f1
  0    -> f2
....

どの関数フローがどのスレッドで実行されたものか判別がつきませんね。

関数フローが複雑な場合や、より多くのスレッドが関与する場合、各スレッドごとの関数フローの対応を取るだけでもウンザリすることでしょう。

スレッド識別情報の使用

マルチスレッド稼動時の DTrace 出力の問題点は、それがどのスレッドで採取されたものかがわからない点にあります。

しかし裏を返せば、どのスレッドで採取された情報であるかがわかるようにしてやれば良い、ということにもなります。

Dスクリプトで使用可能な組み込み変数には、スレッドの識別情報として使用可能なtid変数があります。リンク先の説明にもあるように、ユーザプロセスでの採取においてこの変数を使用した場合、pthread_self(3C)呼び出し結果と同等の値を得ることができます。

それでは、組み込み変数tidを併用して関数フローを採取してみましょう。

pid$target:$1::entry,
pid$target:$1::return
{
    printf("tid=%d", tid);
}

上記Dスクリプトは、関数の入り（entry）と出（return）の両方で、組み込み変数tidの値を表示することで、どのスレッド上での関数フローであるかを識別可能にしています。

CPU FUNCTION
  0  -> _start                                tid=1
  0    -> __fsr                               tid=1
  0    <- __fsr                               tid=1
  0    -> main                                tid=1
  0      -> running                           tid=2
  0        -> running                         tid=3
  0          -> running                       tid=4
  0            -> running                     tid=5
  0              -> running                   tid=6
  0  -> f3                                    tid=2
  0    -> f1                                  tid=2
  0    <- f1                                  tid=2
  0    -> f2                                  tid=2
  0      -> f1                                tid=2
  0      <- f1                                tid=2
  0    <- f2                                  tid=2
  0  <- f3                                    tid=2
  0  -> f3                                    tid=3
  0    -> f1                                  tid=3
  0    <- f1                                  tid=3
  0    -> f2                                  tid=3
....

スレッド識別情報を表示することで、各スレッド上での関数フローの対応関係が明確になりました。

子プロセス

マルチスレッド化と同様に、子プロセスを生成してのマルチプロセス化も、高速化の手法として多くの局面で採用されます。

fork() 時のトレース採取

これまで説明に使用してきたDスクリプトでは、pidプロバイダに対してプロセスIDを明示的に指定してきました。

しかし、情報採取対象となっている親プロセスと、fork()システムコールで生成された子プロセスでは、プロセスIDは当然異なるものとなります。

つまり、親プロセスから情報採取するためのDスクリプトでは、子プロセスから引き続き関数フローの採取を行うことはできません。

新規に生成された子プロセスから情報採取を行う簡単な方法は、デバッガ等を使用して子プロセスの生成契機を補足し、生成された子プロセスのプロセスIDを取得することで、改めてdtraceの適用を行う、というものです。

たとえば、リスト6に示すような、fork()により子プロセスを生成するプログラムshow_mpを仮定します（エラー処理記述は割愛しています⁠）⁠。

int
main(int argc,
     const char* argv[])
{
    pid_t pid;
    int loops = atoi(argv[1]);

    if(0 == (pid = fork())){ /* 子プロセス */
        running(loops);
    }
    else if(0 

それではデバッガを使って、子プロセスの生成契機を補足してみましょう。

以降の実行例は、Solaris の標準デバッガであるdbx を使用したものです。

$ dbx show_mp
....
(dbx) dbxenv follow_fork_mode child ※ 子プロセスの追跡を指定
(dbx) run 10 ※ 実行開始
Running: show_mp 10
(process id 12161)
detaching from process 12161 ※ 親プロセスの切り離し
Attached to process 12162 ※ 子プロセスとの接続
stopped in __forkx at 0xd2af207b ※ fork() 完了時点で停止
0xd2af207b: __forkx+0x000b:     popl     %ecx
(dbx)

"Attached to process ....." 部分に、fork()により生成された子プロセスのプロセスID（上記実行例の場合は12162）が表示されますから、dbx の contコマンドで子プロセスの実行を再開する前に、当該プロセスに対してdtraceコマンドを適用して、情報採取を開始してください。

ただし、デバッガにより停止状態にあるプロセスに対して、dtraceコマンドの-p オプションによる採取対象プロセス ID 指定を行うと、以下のようなエラーが表示されます。

$ dtrace -p 12162 ....
dtrace: failed to grab pid 12162: process is traced
$

デバッガの制御下にあるプロセスに対してdtrace コマンドを適用する場合は、-pオプションを使用しないようにしてください。

なお、dbxをコマンドラインから使用した場合、親プロセスか子プロセスの一方しか停止できません（※2⁠）⁠。そのため上記の手順では、親プロセスが次々と子プロセスを生成するような状況で、生成された全ての子プロセスに対するdtraceコマンド適用を行うことはできません。

このような場合には、以下の2つの処理を組み合わせるようなスクリプトを作成するなどして、生成された子プロセスに対して順次dtraceを適用する、といった実現方式が考えられます。

• truss コマンド出力の加工などによるfork() 戻り値＝子プロセスのプロセスIDの抽出
• 与えられたプロセスIDに対するdtrace コマンドの適用

ただしこの方法の場合、trussコマンドによるfork()実行の検出から、子プロセスに対するdtrace適用までに時間差が生じますので、子プロセスからのトレース採取に漏れが生じる可能性があります。

exec() 時のトレース採取

厳密には、exec()（※3）の実行は子プロセスに限定された話では無いのですが、fork() した子プロセス側で実施されるのが一般的ですので、「⁠子プロセス」のトピックとして扱いたいと思います。

たとえば、リスト7に示すような、指定された引数で新たなプログラムをexec()するプログラムshow_execを仮定します。

int
main(int argc,
     char* argv[])
{
    execv(argv[1], argv + 1);

    /* execv() 成功時は、ここには到達しません */
    return 1;
}

exec() に関する注意点を説明するに当たり、ここで少々DTraceの情報採取の実現方式に関して説明をしようと思います。

まずはデバッガを使用して、show_execプログラムのmain関数冒頭を逆アセンブルしてみましょう。

$ dbx show_exec
....
(dbx) dis main
0x08050af0: main       : pushl %ebp
0x08050af1: main+0x0001: movl  %esp,%ebp
0x08050af3: main+0x0003: subl  $0x00000004,%esp
0x08050af6: main+0x0006: movl  0x0000000c(%ebp),%edx
0x08050af9: main+0x0009: movl  0x0000000c(%ebp),%eax
0x08050afc: main+0x000c: addl  $0x00000004,%eax
....

上記の結果を踏まえて、以下の操作を行います。

1. main 冒頭にブレークポイントを設定
2. プログラムを実行 ～ main で停止
3. main のブレークポイントを無効化

dbxでの実行例を以下に示します。

(dbx) stop in main ※ ブレークポイント設定
(2) stop in main
(dbx) run /usr/bin/ls -l /tmp ※ 実行開始
Running: show_exec /usr/bin/ls -l /tmp
(process id 12493)
stopped in main at 0x08050af0 ※ ブレークポイントで停止
0x08050af0: main       :        pushl    %ebp
(dbx) status
*(2) stop in main
(dbx) handler -disable 2 ※ ブレークポイントの無効化
(dbx) status
*[2] stop in main -disable

この段階でデバッグ中のプロセス（上記の例ではプロセスID 12493）に対してdtraceコマンドを適用し、関数フロー採取を開始します。

dtraceコマンドによる採取が開始されたなら、もう一度先ほどの関数冒頭部分を逆アセンブルしてみましょう。

(dbx) dis main
0x08050af0: main       : int   $0x3
0x08050af1: main+0x0001: movl  %esp,%ebp
0x08050af3: main+0x0003: subl  $0x00000004,%esp
0x08050af6: main+0x0006: movl  0x0000000c(%ebp),%edx
0x08050af9: main+0x0009: movl  0x0000000c(%ebp),%eax
0x08050afc: main+0x000c: addl  $0x00000004,%eax
....

dtrace コマンドの適用前までは"pushl %ebp"であった関数冒頭部分に、"int $0x3" 命令が埋め込まれています。

上記の結果からわかるように、pidプロバイダを使用したDスクリプトを実行する際には、情報採取対象プロセスのプログラム領域の書き換えが発生しています。

一方で、exec()が実施された際にも、新たに実行されるプログラムの内容によって、プログラム領域が書き換えられます。

ということは、DTraceによる関数フロー採取のためのプログラム書き換えは、exec()の実施によって全て上書きされてしまいますから、exec()後のプロセスからは情報採取ができないことを意味します。

つまり、exec()後のプロセスから情報採取をしようとするなら、改めてDTraceによる対象プロセスのプログラム書き換えを実施する必要がある、というわけです。

dbxを使用している場合であれば、exec() が完了して新たなプログラムの実行が開始された段階で、プログラムの実行が一旦中断されます（図4の続きから継続する場合は、dbxのcontコマンドを使用してください⁠）⁠。

(dbx) run /usr/bin/ls -l /tmp ※ 実行開始
Running: show_exec /usr/bin/ls -l /tmp
(process id 12493)
dbx: process 12493 about to exec("/usr/bin/ls")
dbx: program "/usr/bin/ls" just exec'ed
dbx: to go back to the original program use "debug $oprog"
Reading ls
stopped in main at 0x080520ac ※ exec() 完了時点で停止
0x080520ac: main       :        pushl    %ebp
(dbx)

この時点で改めて dtraceコマンドを対象プロセス（上記の例ではプロセスID 12493）に適用することで、exec()後のプロセスからも情報採取を行うことができます。

なお、dbxの適用対象プロセスがexec()を実施した場合、dbxはそれ以後のデバッグ対象をexec()されたプログラムに変更します（上記の例では "/usr/bin/ls"⁠）⁠。

exec()前の段階から再度実行し直したい場合は、デバッグ対象プログラムの変更を "debug $oprog" によってdbxに通知してください。

共有ライブラリ

今時のプログラムは共有ライブラリ（いわゆるlib*.so）を使用するのが一般的になっています。

主要な機能の大半が共有ライブラリによって実現されている、といったケースも多々ありますので、共有ライブラリからの情報採取の重要性は非常に高いと言えます。

共有ライブラリの問題

リスト8に示すスクリプトwatch_flow_whole.dを使用して、ZFSの/usr/sbin/zpoolコマンド実行時のlibc.so 中の関数に対する呼び出しフローを採取してみましょう。

pid$target:$1::entry,
pid$target:$1::return
{
}

以下に実行例を示します。

$ dtrace -F \
         -s watch_flow_whole.d \
         -c '/usr/sbin/zpool status' \
         libc.so
dtrace: script 'watch_flow_whole.d' matched 5815 probes
CPU FUNCTION
  0  -> __tls_static_mods
  0    -> lmalloc
  0      -> getbucketnum
  0      <- getbucketnum
  0      -> initial_allocation
  0        -> __systemcall
  0        <- __systemcall
  0      <- initial_allocation
  0    <- lmalloc
  0    -> tls_modinfo_alloc
....

dtrace コマンドに渡している引数"libc.so" は、watch_flow_whole.dでのプローブ記述のモジュール指定部分に記述された"$1"と置換されます。

第2回での文法の説明の際には割愛しましたが、プローブ記述のモジュール指定部分には、コマンド名以外にも共有ライブラリ名を指定することができます。共有ライブラリ名を指定した場合、共有ライブラリ中の関数が情報採取の対象となります。

それではlibc.so以外の共有ライブラリの関数フローも採取してみましょう。まずはzpoolが参照している共有ライブラリの一覧を取得します。

$ ldd /usr/sbin/zpool
        libzfs.so.1 =>      /lib/libzfs.so.1
        libnvpair.so.1 =>   /lib/libnvpair.so.1
        libdevid.so.1 =>    /lib/libdevid.so.1
.....
$ 

先ほどはlibc.soの関数フローを採取しましたので、同じ要領で今度はlibzfs.soの関数フローを採取してみましょう。

$ dtrace -F \
         -s watch_flow_whole.d \
         -c '/usr/sbin/zpool status' \
         libzfs.so
dtrace: failed to compile script watch_flow_whole.d: line 1: \
  probe description pid12634:libzfs.so::entry \
  does not match any probes
$ 

どうやら思ったようには実行されません。「⁠指定と合致するプローブが無い」と言っているようです。

実はこの問題は、共有ライブラリのローディング契機に由来するものです。

通常のC/C++プログラムの起動では、シンボル解決の必要上、プロセスが起動された時点で当該プロセスの空間にlibc.soがマッピングされます（※4⁠）⁠

プロセスが起動された段階で、当該プロセスのアドレス空間からlibc.soを参照することができるため、DTrace は情報採取用のコードを埋め込むことができます。

しかし libzfs.so の場合、共有ライブラリ内のいずれかの関数が呼ばれるまでは、プロセスの空間内にマッピングされません。

そのため、DTraceによる情報採取コードの埋め込みをコマンド起動時点で行うことができず、結果として上記のようなエラーメッセージが表示されてしまうわけです。

共有ライブラリ中の関数フローの採取

対象とする共有ライブラリからの情報採取ができないのは、プロセス起動の段階で共有ライブラリがマッピングされていないのが原因ですから、以下の様な解決策が考えられます。

1. 共有ライブラリがマッピングされるまで待ってから採取を開始する
2. プロセス起動時点で共有ライブラリをマッピングさせる

前者の方法は、デバッガ等を使用することで共有ライブラリのマッピング契機を検知し、その時点からdtraceコマンドの適用を開始する、というものですが、あまり簡単な方法とは言えません（※5⁠）⁠。

後者の方法は、LD_PRELOAD_32環境変数（※6）に共有ライブラリを設定することによって、プロセス起動時点で指定共有ライブラリのマッピングが実施される、という性質を利用するもので、非常に簡単に実現できますから、ここではこちらの方法を説明したいと思います。

説明とは言うものの、採取対象としたい共有ライブラリをLD_PRELOAD_32環境変数に指定した状態でdtraceコマンドを起動する、という簡単な手順です。

$ export LD_PRELOAD_32=/lib/libzfs.so.1
$ dtrace -F \
        -s watch_flow_whole.d \
        -c '/usr/sbin/zpool status' \
        libzfs.so
dtrace: script 'watch_flow_whole.d' matched 828 probes
CPU FUNCTION
  0  -> zfs_iscsi_init
  0  <- zfs_iscsi_init
  0  -> _zfs_init_libshare
  0  <- _zfs_init_libshare
  0  -> libzfs_init
  0    -> zfs_prop_init
  0      -> register_index
  0        -> register_impl
  0          -> zprop_get_proptable
....

今度は期待通りに共有ライブラリlibzfs.soの関数フローを採取することができました。

採取用スクリプトのプローブ記述を複数列挙すれば、libzfs.so 中の関数の呼び出し元となるzpool コマンド中の関数フローと併せて採取することもできます。

pid$target:zpool::entry,
pid$target:zpool::return,
pid$target:libzfs.so::entry,
pid$target:libzfs.so::return
{
}

ちなみに、Solaris環境においてdtrace実行にpfexecを併用している場合、ユーザ権限でLD_PRELOAD_32を設定した状況でpfexecを実行すると、セキュリティ的な観点からLD_PRELOAD_32設定が無視されます。

$ export LD_PRELOAD_32=/lib/libzfs.so.1
$ pfexec dtrace -F \
                -s watch_flow_whole.d \
                -c '/usr/sbin/zpool status' \
                libzfs.so
ld.so.1: pfexec: warning: /lib/libzfs.so.1: open failed: \
  illegal insecure pathname
....

LD_PRELOAD_32の設定は、事前にroot権限への昇格を行ってから実施するようにしてください。

次回予告

次回は、関数やモジュールの指定以外の手法で情報採取対象を絞り込む方法など、より踏み込んだDTraceの使用方法について説明します。