C/C++プログラマのためのDTrace入門

第5回統計情報の採取

これまでの回でDTraceが実施するDスクリプトにおける変数は、基本的には単純な値のみを保持する、いわゆるスカラー(scalar)型のものでした。

しかし、DTraceにはスカラー型以外の変数もあります。

今回は、統計情報の採取を題材に、スカラー型以外の変数について説明したいと思います。

呼び出し頻度の採取

まずは統計情報採取の簡単な例として、特定の関数の呼び出し頻度を採取してみましょう。

集積体

DTrace での統計情報採取には、集積体(aggregation)と呼ばれる型を持つ変数を使用します。

集積体は以下の様な点で通常の変数と異なります。

  • 変数名の冒頭に必ずアットマーク("@")が付く
  • 変数名を省略可能(省略した場合は "@_" 相当とみなされます)
  • 大域変数としてしか定義できない
  • 集積体に代入できる値は(後述する)集積関数の戻り値のみ

目下の目標である「特定の関数の呼び出し頻度を採取」するDスクリプトは以下のようになります。

リスト1 呼び出し頻度の採取watch_count.d
pid$target:$1:$2:entry
{
    @total = count();
}

リスト1は、dtraceコマンドの引数として、採取対象のモジュール名(実行バイナリ名)と関数名を指定することを前提としています$1および$2と置換⁠⁠。

それでは実際に実行してみましょう。ここでは実行例として、OpenSolaris同梱のlsコマンドにおけるformat_time()関数の呼び出し回数を採取してみます。

図1 関数呼び出し回数の採取
$ dtrace -s watch_count.d \
         -c '/usr/bin/ls -l' \
         ls format_time
dtrace: script 'watch_count.d' matched 1 probe
total 2659
        :
        :
dtrace: pid 744 has exited

               16
$

最後に表示される "16" がformat_time() 関数の呼び出し回数です。

統計結果の表示

先ほどの実行例では、dtraceコマンド終了時点で、集積体@totalの格納値が自動的に出力されました。

これは、dtrace コマンド終了におけるデフォルトの処理が、集積体の内容出力を行うようになっているためです。

しかしたとえば複数の集積体を使用している場合などに、このような形式で出力されたのでは、情報の識別が困難になってしまいます。

そこで、集積体専用の出力書式指定を行うprinta()アクションを使用して、明示的に集積体の格納値を出力してみましょう。

リスト2 統計情報出力の書式指定watch_count2.d
pid$target:$1:$2:entry
{
    @total = count();
}
END
{
    printa("total=%@u\n", @total);
}

ENDなる記述がありますが、実はこれもプローブの1つで、dtraceプロバイダによって提供されているものです。

このプローブは、Dスクリプトの実行終了の際に実施される処理を記述するためのものです。⁠Dスクリプトの実行終了」とは、以下のようなケースを指します。

  • "-c" オプション指定で実行されたプロセスが終了した場合
  • "-p" オプション指定で監視しているプロセスが終了した場合
  • "exit()" アクションで明示的に終了した場合
  • Ctrl-C等によりdtraceコマンドの実行を中断した場合

Dスクリプトの開始時点で実施する処理を記述するためのBEGINプローブもあります。

さて、肝心の集積体の表示ですが、リスト2に記述されているようにprinta()アクションで実施することができます。

printa()の機能はおおむねprintf()と同じですが、集積体値を表示するための書式指定には、通常の "%" ではなく "%@"を冒頭に持つ書式指定を使用してください。

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

図2 集積体の書式指定
$ dtrace -s watch_count.d \
         -c '/usr/bin/ls -l' \
         ls format_time
dtrace: script 'watch_count2.d' matched 2 probes
total 2665
        :
        :
dtrace: pid 784 has exited
CPU     ID                    FUNCTION:NAME
  0      2                             :END total=16

$

集積体による統計情報取得

集積関数

実のところ、先述した呼び出し頻度の採取のように単純に回数を記録するだけであれば、大域変数を使用して同等のことが実現できますから、わざわざ集積体を使用するメリットを感じられないかもしれません。しかし、count() 以外にもDTraceは以下のような集積関数を提供しています。

表1 集積関数一覧
集積関数 算出対象
sum() 指定された値の合計値
avg() 指定された値の平均値
min() 指定された値の最小値
max() 指定された値の最大値
lquantize() 指定された値の線形度数分布
quantize() 指定された値の二乗分布

たとえば、ある関数の呼び出しにおける第1引数値arg0の平均値を知りたい場合、リスト3のようなDスクリプトを使用します(終了時の出力処理は省略します⁠⁠。

リスト3 引数平均値の採取
pid$target:$1:$2:entry
{
    @val = avg(arg0);
}

通常の変数を用いて同等の処理をしようとする場合、算出対象(=集積体の変数に相当)ごとに以下の値をそれぞれ集計しておいた上で、終了時点で改めて結果を算出する必要があるわけですから、集積体の利便性がわかるのではないでしょうか。

  • 総呼び出し回数
  • 各呼び出しごとの指定値

キーによる分類

実際に統計情報採取の機能を利用する場合には、先述したような固定的な情報の記録では対応できないケースの方が多い、と言っても過言では有りません。

DTraceの集積体は、個別の値の格納の際にキーを指定することで、ひとつの集積体に対して複数の値を格納することができます。

たとえば、対象モジュールに含まれる全ての関数に対して、それぞれの総呼び出し回数を採取する場合には、リスト4のようなDスクリプトを使用します。

リスト4 関数毎呼び出し頻度の採取
pid$target:$1::entry
{
    @total[probefunc] = count();
}

なお、上記のように集積体がキーを持つ場合、printa()を使った出力書式指定は、以下の要領で行います。

リスト5 キー付き集積体の書式設定
    printa("%s = %@u\n", @total);

集積体がキーを持つ場合、printa()に指定された出力書式によるフォーマットは、各キーとそれに対応する値ごとに都度適用されます。

その際に、書式指定における"%@~"部分が集積体の値で置換される点は変わりありませんが、それ以外の置換指定部分(この場合は"%s")は、集積体のキー(この場合はprobefuncなので文字列)を使って置換されます。

リスト4では、組み込み変数probefunc値=関数名をキーに使用しましたが、キーの値には数値などを含む任意のスカラー値を指定できますから、引数の値ごとに統計採取することも可能です。

また、キーとして使用可能なスカラー値以外のものとして、ustack()User stackで得られる呼び出しスタック情報があります。アクションとして記述した場合には呼び出しスタックを表示するustack()ですが、集積体のキーとして記述することで、呼び出しスタックごとの統計採取を行うことができます(※1⁠⁠。

リスト6 スタックをキーにした呼び出し頻度集計watch_count_ustack.d
pid$target:$1::entry
{
    @total[ustack()] = count();
}

それでは実際に実行してみましょう。

図3 スタックをキーにした呼び出し頻度集計
$ dtrace -s watch_count_ustack.d \
         -c '/usr/bin/ls -l' \
         ls
dtrace: script 'watch_count_ustack.d' matched 32 probes
total 2664
        :
        :
dtrace: pid 782 has exited
        :
              ls`format_time
              ls`pentry+0x39a
              ls`pem+0x181
              ls`main+0x915
              ls`_start+0x7d
                4

              ls`format_time
              ls`pentry+0x39a
              ls`pem+0x18c
              ls`main+0x915
              ls`_start+0x7d
                4

              ls`format_time
              ls`pentry+0x39a
              ls`pem+0x197
              ls`main+0x915
              ls`_start+0x7d
                4
        :
....

ustack()をキーに使用することで、同一関数の呼び出しに対して、呼び出し元の違いによる傾向の差を確認することもできます。

上記の例では、ls`pem 関数におけるls`pentry 呼び出し位置の違いによって、異なる集計結果が表示されています。

連想配列

連想配列とは

「連想配列とは?」と題してみましたが、実際には連想配列に相当する機能を既に説明済みです。前のページでの「キーを用いた集積体の利用」がそれに相当します。

連想配列の記述形式は、他のスクリプト系言語における「連想配列」と同様に、⁠変数名」の後ろにカギ括弧で囲まれた「キー」を指定する、というものです。

キーに指定する値は、スカラー値であれば数値でも文字列でも構いませんし、集積体と同様にustackの戻り値を用いることもできます。

また、DTraceの連想配列は、多次元配列にすることも可能です(※2⁠⁠。

たとえば、リスト7のようなDスクリプトは、⁠モジュール名」「関数名」の2つの次元を持つ連想配列valueを、スレッド固有変数として持つことになります。

リスト7 多次元連想配列
pid$target:libxxxx::entry,
pid$target:commandz::entry
{
    self->value[probemod, probefunc] = arg0;
}

前提条件指定における再帰呼び出し対応

リスト8は、第4回で例示した、非0で復帰する際に呼び出し時点での第1引数arg0を表示するDスクリプトです。

リスト8 戻り値を用いた述語記述
pid$target:XXXX:xxxx:entry
{
    self->arg0 = arg0;
}

pid$target:XXXX:xxxx:return
/arg1 != 0/
{
    printf("arg0=%p", self->arg0);
}

しかし対象関数(この例の場合はXXXXモジュールのxxxx関数)が再帰的に呼び出される場合、入れ子になった呼び出しの深さを考慮していないため、このDスクリプトは期待するようには動作しません。

入れ子の深さに応じて呼び出し引数を格納できれば良いわけですから、入れ子の深さを保持するスカラー変数と、それをキーにして引数を格納する連想配列を使用したリスト9のようなDスクリプトなら、適切な引数を表示することができます。

この例での連想配列 self->arg0 は、スタック構造を形成しています。

リスト9 戻り値による述語記述(再帰対応版)
self int depth;

pid$target:XXXX:xxxx:entry
{
    self->depth += 1;
    self->arg0[self->depth] = arg0;
}
pid$target:XXXX:xxxx:return
/arg1 != 0/
{
    printf("arg0=%p", self->arg0[self->depth]);
}
/* 
 * 関数からの復帰における depth 減算は
 * 戻り値に関わらず実施する必要があるので
 * 戻り値に応じた処理を実施する節とは独立させる
 */
pid$target:XXXX:xxxx:return
{
    self->depth -= 1;
}

採取対象関数が複数である場合でも、入れ子の深さを保持するself->depthを連想配列(キーは「関数名⁠⁠)にした上で、連想配列self->arg0のキーを2次元(キーは「関数名」「深さ⁠⁠)にすることで対応可能です。

次回予告

集積体を用いた DTrace の統計情報採取機能には、今回説明できませんでしたが、統計情報を正規化するといった機能もありますので、Sun が提供するドキュメントも是非参照してみてください。

次回は、独自プロバイダを定義することで、関数呼び出しとは別な契機で情報を採取する方法について説明します。

おすすめ記事

記事・ニュース一覧