第 9 章 集積体
システムパフォーマンスについて計測するときは、個々のプローブによって収集されたデータについて考えるよりも、データをどのように集積できるかについて考えたほうが、明確な答えを得やすくなります。たとえば、ユーザー ID ごとにシステムコールの回数を調べたい場合、1 回 1 回のシステムコールで収集されたデータについて考慮する必要はありません。ユーザー ID とシステムコールの表を確認できれば、それで十分です。従来、このような調査が必要な場合は、システムコールごとにデータを収集し、awk(1) や perl(1) などのツールを使って、収集したデータに後処理を行なっていました。しかし、DTrace では、データの集積こそがもっとも重要な操作になります。この章では、DTrace の「集積体」の処理機能について説明します。
集積関数
次のようなプロパティを持つ関数を「集積関数」と呼びます。
f(f(x0) U f(x1) U ... U f(xn)) = f(x0 U x1 U ... U xn)
xn は、任意のデータセットです。つまり、データのサブセットに集積関数を適用し、その結果に再度集積関数を適用すると、データ全体に集積関数を適用した場合と同じ結果になります。たとえば、指定のデータセットの合計を計算する関数、SUM について考えてみましょう。生のデータが {2, 1, 2, 5, 4, 3, 6, 4, 2} である場合、このデータセット全体に SUM を適用した結果は {29} になります。同様に、最初の 3 つの要素で構成されたサブセットに SUM を適用した結果は {5}、続く 3 つの要素に SUM を適用した結果は {12}、残りの 3 つの要素に SUM を適用した結果は {12} になります。これらの結果である {5, 12, 12} に SUM を適用すると、元のデータに SUM を適用したときと同じ結果 (ここでは {29}) が得られます。このため、SUM は「集積関数」と呼ばれます。
すべての関数が集積関数として機能するわけではありません。たとえば、データセットの中央値を計算する関数、MEDIAN は、集積関数ではありません。中央値とは、データセット内の要素を大きさ順に並べたとき、ちょうど真ん中にくる要素のことです。MEDIAN を得るには、データセットをソートして、その真ん中の要素を選択します。最初の生のデータに戻りましょう。最初の 3 つの要素から成るデータセットに MEDIAN を適用した場合、結果は {2} になります (ソート済みセットは {1, 2, 2} で、中央の要素は {2} です)。同様に、次の 3 つの要素に MEDIAN を適用した結果は {4}、最後の 3 つの要素に MEDIAN を適用した結果は {4} になります。このように、3 つの要素から成る各サブセットに MEDIAN を適用した場合、{2, 4, 4} というデータセットが得られます。このデータセットに MEDIAN を適用すると、結果は {4} になります。これに対して、元のデータセットをソートすると、{1, 2, 2, 2, 3, 4, 4, 5, 6} になります。このデータセットに MEDIAN を適用すると、結果は {3} になります。このように、結果が一致しないので、MEDIAN は集積関数ではありません。
データセット関連の情報を得たいときに使用する関数の多くは、集積関数です。これらの関数を使って、データセット内の要素数を数えたり、データセットの最小値や最大値を求めたり、データセット内のすべての要素の合計を計算したりできます。データセットの平均値を特定するには、セット内の要素数を数える関数と、セット内の要素を合計する関数を使用します。
ただし、集積関数以外にも、便利な関数は存在します。たとえば、データセットのモード (もっともよく使用する要素) を計算する関数、データセットの中央値を計算する関数、データセットの標準偏差を計算する関数などです。
データのトレース時に集積関数を適用すると、多数の利点があります。
-
データセット全体を格納する必要がありません。セットに新しい要素が追加されるたびに、現在の中間結果と新しい要素から成るセットが作成され、集積関数が計算されます。新しい結果の計算が完了したら、新しい要素は破棄してかまいません。この処理により、データポイント数が非常に多くなっても、記憶域の消費量を少なく抑えることができます。
-
データ収集が原因で、スケーラビリティに問題が起こることはありません。集積関数は、中間結果を共用のデータ構造に格納せず、CPU 単位で保存します。その後、この CPU 単位の中間結果のセットに集積関数が適用され、システム全体の最終的な結果が得られます。
集積体
DTrace は、集積関数の実行結果を「集積体」と呼ばれるオブジェクト内に格納します。この集積体の結果には、連想配列で使用するものとよく似た式の組でインデックスが付けられます。D の集積体の構文は、次のとおりです。
@name[ keys ] = aggfunc ( args );
name は集積体の名前、keys は複数の D 式をコンマで区切った形式のリスト、aggfunc は DTrace 集積関数、args は指定された集積関数の引数をコンマで区切った形式のリストです。集積体 name は、特殊文字 @ で始まる D 識別子です。D プログラム内で使用するすべての集積体は大域変数です。スレッド固有の集積体、節固有の集積体は存在しません。集積体名は、その他の D 大域変数とは別の識別子用名前空間に格納されます。名前を再利用する場合、a と @a はまったく別の変数になります。単純な D プログラム内で、名前のない集積体を指定するときは、特殊な集積体名 @ を使用します。D コンパイラは、この名前を集積体名 @_ の別名と解釈します。
以下の表に、DTrace の集積関数を示します。ほとんどの集積関数は、新しいデータを表す引数を 1 つとるだけです。
表 9–1 DTrace の集積関数|
関数名 |
引数 |
結果 |
|---|---|---|
|
count |
なし |
呼び出された回数。 |
|
sum |
スカラー式 |
指定された式の合計値。 |
|
avg |
スカラー式 |
指定された式の算術平均。 |
|
min |
スカラー式 |
指定された式のうちもっとも小さい値。 |
|
max |
スカラー式 |
指定された式のうちもっとも大きい値。 |
|
lquantize |
スカラー式、下限値、上限値、ステップ値 |
指定された式の値から成る、指定された範囲の線形度数分布。指定された式より小さい、最大バケット内の値を増分します。 |
|
quantize |
スカラー式 |
指定された式の値の二乗分布。指定された式より小さい、2 のべき乗の最大バケット内の値を増分します。 |
たとえば、システム内の write(2) システムコールの回数をカウントしたい場合、通知文字列をキーに指定して、集積関数 count() を使用します。
syscall::write:entry
{
@counts["write system calls"] = count();
}
デフォルトの設定では、dtrace コマンドを実行すると、プロセスの終了時に、それが明示的な END アクションの結果であるかユーザーが Control-C キーを押したためかにかかわらず、集積体の結果が出力されます。このコマンドを実行し、しばらく待ってから Control-C キーを押すと、次のような結果が得られます。
# dtrace -s writes.d dtrace: script './writes.d' matched 1 probe ^C write system calls 179 # |
プロセス名ごとのシステムコール数をカウントしたい場合は、集積体のキーとして execname 変数を指定します。
syscall::write:entry
{
@counts[execname] = count();
}
このコマンドを実行し、しばらく待ってから Control-C キーを押すと、次のような結果が得られます。
# dtrace -s writesbycmd.d dtrace: script './writesbycmd.d' matched 1 probe ^C dtrace 1 cat 4 sed 9 head 9 grep 14 find 15 tail 25 mountd 28 expr 72 sh 291 tee 814 def.dir.flp 1996 make.bin 2010 # |
書き込みの情報として、実行可能ファイルの名前とファイル記述子の両方を出力することもできます。ファイル記述子は、write(2) の最初の引数です。次の例では、キーとして execname と arg0 の両方が指定されています。
syscall::write:entry
{
@counts[execname, arg0] = count();
}
このコマンドを実行すると、実行可能ファイルの名前とファイル記述子を含む、次の例のような表が出力されます。
# dtrace -s writesbycmdfd.d dtrace: script './writesbycmdfd.d' matched 1 probe ^C cat 1 58 sed 1 60 grep 1 89 tee 1 156 tee 3 156 make.bin 5 164 acomp 1 263 macrogen 4 286 cg 1 397 acomp 3 736 make.bin 1 880 iropt 4 1731 # |
次の例では、write システムコールにかかった時間の平均が、プロセス名ごとに出力されます。この例では、平均を求める式を引数にとる集積関数 avg() が使用されています。したがって、システムコールにかかった時計時間の平均が求められます。
syscall::write:entry
{
self->ts = timestamp;
}
syscall::write:return
/self->ts/
{
@time[execname] = avg(timestamp - self->ts);
self->ts = 0;
}
このコマンドを実行し、しばらく待ってから Control-C キーを押すと、次のような結果が得られます。
# dtrace -s writetime.d dtrace: script './writetime.d' matched 2 probes ^C iropt 31315 acomp 37037 make.bin 63736 tee 68702 date 84020 sh 91632 dtrace 159200 ctfmerge 321560 install 343300 mcs 394400 get 413695 ctfconvert 594400 bringover 1332465 tail 1335260 # |
平均値はさまざまな場面で利用できる情報ですが、通常、この情報だけでは、データポイントの分布まではわかりません。データ分布の詳細を確認したい場合は、次の例のように、集積関数 quantize() を使用します。
syscall::write:entry
{
self->ts = timestamp;
}
syscall::write:return
/self->ts/
{
@time[execname] = quantize(timestamp - self->ts);
self->ts = 0;
}
このスクリプトの出力は、先ほどの例の出力よりも長くなります。これは、先ほどの例で 1 行に出力されていた内容が、度数分布表として出力されるからです。以下は、出力例の抜粋です。
lint
value ------------- Distribution ------------- count
8192 | 0
16384 | 2
32768 | 0
65536 |@@@@@@@@@@@@@@@@@@@ 74
131072 |@@@@@@@@@@@@@@@ 59
262144 |@@@ 14
524288 | 0
acomp
value ------------- Distribution ------------- count
4096 | 0
8192 |@@@@@@@@@@@@ 840
16384 |@@@@@@@@@@@ 750
32768 |@@ 165
65536 |@@@@@@ 460
131072 |@@@@@@ 446
262144 | 16
524288 | 0
1048576 | 1
2097152 | 0
iropt
value ------------- Distribution ------------- count
4096 | 0
8192 |@@@@@@@@@@@@@@@@@@@@@@@ 4149
16384 |@@@@@@@@@@ 1798
32768 |@ 332
65536 |@ 325
131072 |@@ 431
262144 | 3
524288 | 2
1048576 | 1
2097152 | 0
|
度数分布の行は必ず 2 のべき乗の値になります。各行の右側に表示されているカウントは、その行の左側に表示されている値以上、次の行の左側に表示されている値未満に対応する要素数です。たとえば、上の出力例からは、iropt が、8,192 ナノ秒から 16,383 ナノ秒の間に 4,149 回の書き込みを行なっていることがわかります。
quantize() は、データの内容を短時間で把握するには便利ですが、線形値の分布を調べたい場合もあります。線形値の分布を表示するには、集積関数 lquantize() を使用します。lquantize() 関数を使用するときは、D 式と 3 つの引数 (下限値、上限値、ステップ値) を指定します。たとえば、ファイル記述子別に書き込みの分布を調べたい場合、2 のべき乗の量子化では効率がよくありません。そこで、次のように、狭い範囲で線形量子化を行います。
syscall::write:entry
{
@fds[execname] = lquantize(arg0, 0, 100, 1);
}
このスクリプトは、数秒実行しただけで大量の情報を出力します。以下は、一般的な出力例の抜粋です。
mountd
value ------------- Distribution ------------- count
11 | 0
12 |@ 4
13 | 0
14 |@@@@@@@@@@@@@@@@@@@@@@@@@ 70
15 | 0
16 |@@@@@@@@@@@@ 34
17 | 0
xemacs-20.4
value ------------- Distribution ------------- count
6 | 0
7 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 521
8 | 0
9 | 1
10 | 0
make.bin
value ------------- Distribution ------------- count
0 | 0
1 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 3596
2 | 0
3 | 0
4 | 42
5 | 50
6 | 0
acomp
value ------------- Distribution ------------- count
0 | 0
1 |@@@@@ 1156
2 | 0
3 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 6635
4 |@ 297
5 | 0
iropt
value ------------- Distribution ------------- count
2 | 0
3 | 299
4 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 20144
5 | 0
|
集積関数 lquantize() では、過去のある時点からのデータを集積することもできます。このテクニックを使って、時間の経過とともに変化する動作を監視できます。以下の例では、date(1) コマンドを実行中のプロセスにおける、システムコールの動作の変化を確認できます。
syscall::exec:return,
syscall::exece:return
/execname == "date"/
{
self->start = vtimestamp;
}
syscall:::entry
/self->start/
{
/*
* We linearly quantize on the current virtual time minus our
* process's start time. We divide by 1000 to yield microseconds
* rather than nanoseconds. The range runs from 0 to 10 milliseconds
* in steps of 100 microseconds; we expect that no date(1) process
* will take longer than 10 milliseconds to complete.
*/
@a["system calls over time"] =
lquantize((vtimestamp - self->start) / 1000, 0, 10000, 100);
}
syscall::rexit:entry
/self->start/
{
self->start = 0;
}
このスクリプトでは、複数の date(1) プロセスを実行しているときのシステムコールの動作を詳しく調べることができます。結果を表示するには、D スクリプトの実行中に別のウィンドウで sh -c 'while true; do date >/dev/null; done' を実行します。すると、date(1) コマンドのシステムコールの動作の概要が出力されます。
# dtrace -s dateprof.d
dtrace: script './dateprof.d' matched 218 probes
^C
system calls over time
value ------------- Distribution ------------- count
< 0 | 0
0 |@@ 20530
100 |@@@@@@ 48814
200 |@@@ 28119
300 |@ 14646
400 |@@@@@ 41237
500 | 1259
600 | 218
700 | 116
800 |@ 12783
900 |@@@ 28133
1000 | 7897
1100 |@ 14065
1200 |@@@ 27549
1300 |@@@ 25715
1400 |@@@@ 35011
1500 |@@ 16734
1600 | 498
1700 | 256
1800 | 369
1900 | 404
2000 | 320
2100 | 555
2200 | 54
2300 | 17
2400 | 5
2500 | 1
2600 | 7
2700 | 0
|
この出力から、カーネルを必要とするサービスについて、date(1) コマンドのさまざまなフェーズの概要を確認できます。これらのフェーズの詳細を把握するには、いつ、どのシステムコールが呼び出されたかを確認します。この場合は、定数文字列ではなく変数 probefunc について集積するように、D スクリプトを変更します。
集積体の出力
デフォルトの設定では、複数の集積体が、D プログラムに記述された順番で表示されます。この設定を変更するには、集積体を出力する printa() 関数を使用します。第 12 章出力書式でも説明しますが、printa() 関数は、集積体データの書式を書式文字列を使って正確に設定したい場合にも使用します。
D プログラム内の printa() 文で集積体の書式が設定されていない場合、dtrace コマンドを実行すると、集積体データのスナップショットが生成され、その結果はトレースの完了後に 1 回だけ、デフォルトの集積体の書式で出力されます。printa() 文で集積体の書式が設定されている場合、デフォルトの動作は無効になります。プログラムの dtrace:::END プローブ節に printa(@aggregation-name) という文を追加しても、同じ結果が得られます。集積関数 avg()、count()、min()、max()、およびsum() のデフォルトの出力書式では、各組の集積値に対応する 10 進整数値が出力されます。集積関数 lquantize() と quantize() のデフォルトの出力形式では、結果の ASCII テーブルが出力されます。集積体の組の出力は、個々の組要素に trace() を適用した場合と同じになります。
データの正規化
一定期間のデータを集積する際、定数係数を使用してデータを正規化できます。このテクニックを使用すると、互いに素のデータを簡単に比較できます。たとえば、システムコールを集積するとき、システムコールを経過時間の絶対値としてではなく、秒当たりのレートで出力できます。DTrace の normalize() アクションでは、この方法でデータを正規化できます。normalize() のパラメータとしては、集積体と正規化係数を指定します。集積体の結果としては、個々の値を正規化係数で割った値が出力されます。
以下の例では、データをシステムコールごとに集積する方法を示します。
#pragma D option quiet
BEGIN
{
/*
* Get the start time, in nanoseconds.
*/
start = timestamp;
}
syscall:::entry
{
@func[execname] = count();
}
END
{
/*
* Normalize the aggregation based on the number of seconds we have
* been running. (There are 1,000,000,000 nanoseconds in one second.)
*/
normalize(@func, (timestamp - start) / 1000000000);
}
このスクリプトをしばらく実行すると、デスクトップマシンに次のような結果が出力されます。
# dtrace -s ./normalize.d ^C syslogd 0 rpc.rusersd 0 utmpd 0 xbiff 0 in.routed 1 sendmail 2 echo 2 FvwmAuto 2 stty 2 cut 2 init 2 pt_chmod 3 picld 3 utmp_update 3 httpd 4 xclock 5 basename 6 tput 6 sh 7 tr 7 arch 9 expr 10 uname 11 mibiisa 15 dirname 18 dtrace 40 ksh 48 java 58 xterm 100 nscd 120 fvwm2 154 prstat 180 perfbar 188 Xsun 1309 .netscape.bin 3005 |
normalize() は、指定された集積体に正規化係数を設定しますが、このアクションによって配下のデータが変更されることはありません。denormalize() は、集積体だけをとります。上記の例に非正規化アクションを追加すると、生のシステムコールカウントと秒当たりのレートの両方が出力されます。
#pragma D option quiet
BEGIN
{
start = timestamp;
}
syscall:::entry
{
@func[execname] = count();
}
END
{
this->seconds = (timestamp - start) / 1000000000;
printf("Ran for %d seconds.\n", this->seconds);
printf("Per-second rate:\n");
normalize(@func, this->seconds);
printa(@func);
printf("\nRaw counts:\n");
denormalize(@func);
printa(@func);
}
上のスクリプトをしばらく実行すると、次の例のような出力が得られます。
# dtrace -s ./denorm.d ^C Ran for 14 seconds. Per-second rate: syslogd 0 in.routed 0 xbiff 1 sendmail 2 elm 2 picld 3 httpd 4 xclock 6 FvwmAuto 7 mibiisa 22 dtrace 42 java 55 xterm 75 adeptedit 118 nscd 127 prstat 179 perfbar 184 fvwm2 296 Xsun 829 Raw counts: syslogd 1 in.routed 4 xbiff 21 sendmail 30 elm 36 picld 43 httpd 56 xclock 91 FvwmAuto 104 mibiisa 314 dtrace 592 java 774 xterm 1062 adeptedit 1665 nscd 1781 prstat 2506 perfbar 2581 fvwm2 4156 Xsun 11616 |
集積体は、再正規化も可能です。同じ集積体に対して複数回 normalize() を呼び出した場合、直前の呼び出しで指定された係数が正規化係数になります。以下の例では、時間の経過とともに秒当たりのレートが出力されます。
例 9–1 renormalize.d: 集積体の再正規化
#pragma D option quiet
BEGIN
{
start = timestamp;
}
syscall:::entry
{
@func[execname] = count();
}
tick-10sec
{
normalize(@func, (timestamp - start) / 1000000000);
printa(@func);
}
集積体の消去
DTrace で単純な監視スクリプトを作成しているとき、clear() 関数を使って、集積体内の値を定期的に消去できます。この関数には、パラメータを 1 つだけ指定できます。パラメータとして指定できるのは、集積体だけです。clear() 関数で消去されるのは、集積体の値だけです。集積体のキーは保持されます。したがって、集積体内に値ゼロのキーがある場合は、「このキーの値はかつてはゼロではなかったが、clear によってゼロが設定された」と解釈できます。()集積体の値とキーの両方を破棄するときは、trunc() を使用します。詳細については、「集積体の切り捨て」を参照してください。
以下は、例 9–1 に clear() を追加した例です。
#pragma D option quiet
BEGIN
{
last = timestamp;
}
syscall:::entry
{
@func[execname] = count();
}
tick-10sec
{
normalize(@func, (timestamp - last) / 1000000000);
printa(@func);
clear(@func);
last = timestamp;
}
例 9–1 では dtrace の呼び出し開始から終了までのシステムコールレートが出力されましたが、上記の例では、過去 10 秒間のシステムコールレートだけが出力されます。
集積体の切り捨て
集積体の結果を調べるときは、通常、上位結果の数行だけに注目します。上位の値以外に関連付けられたキーや値は、あまり重要ではありません。また、キーと値の両方を削除して、集積体の結果全体を破棄したい場合もあります。DTrace の trunc() 関数は、こうした状況で使用します。
trunc() のパラメータとして指定できるのは、集積体と切り捨て値 (オプション) です。trunc() で切り捨て値を省略すると、集積体全体で集積体値と集積体キーとの両方が破棄されます。trunc() で切り捨て値 n を指定した場合は、上位 n 個の値に関連付けられている集積体値と集積体キー以外の値とキーを破棄します。つまり、trunc(@foo) では集積体全体が破棄されるのに対し、trunc(@foo, 10) では、foo という名前の集積体値の上位 10 個が保持され、それ以外の値が切り捨てられることになります。切り捨て値として 0 を指定した場合も、集積体全体が破棄されます。
上位 n 個の値ではなく下位 n 個の値を参照したい場合は、trunc() に負の切り捨て値を指定します。たとえば、trunc(@foo, -10) では、foo という名前の集積体値の下位 10 個が保持され、それ以外の値が切り捨てられます。
以下の例は、10 秒間での上位 10 個のシステム呼び出しアプリケーションについて秒当たりのシステムコールレートが出力だけされるように、先ほどのシステムコールの例を拡張したものです。
#pragma D option quiet
BEGIN
{
last = timestamp;
}
syscall:::entry
{
@func[execname] = count();
}
tick-10sec
{
trunc(@func, 10);
normalize(@func, (timestamp - last) / 1000000000);
printa(@func);
clear(@func);
last = timestamp;
}
以下は、負荷の少ないラップトップでこのスクリプトを実行したときの出力例です。
FvwmAuto 7 telnet 13 ping 14 dtrace 27 xclock 34 MozillaFirebird- 63 xterm 133 fvwm2 146 acroread 168 Xsun 616 telnet 4 FvwmAuto 5 ping 14 dtrace 27 xclock 35 fvwm2 69 xterm 70 acroread 164 MozillaFirebird- 491 Xsun 1287 |
欠落の最小化
DTrace は、カーネルに集積体データの一部を格納します。このため、集積体に新しいキーを追加したとき、容量が不足することがあります。この場合、カウンタの値は大きくなりますが、データは落とされ、dtrace から集積体欠落を示すメッセージが表示されます。DTrace は、容量が動的に増加する場合のユーザーレベルで長時間実行状態 (集積体キーと中間結果で構成される) を保存します。このため、集積体欠落はめったに発生しません。それでも集積体欠落が発生しそうなときは、aggsize オプションを指定して集積体バッファーサイズを大きくすることにより、欠落が発生する確率を低減できます。このオプションは、DTrace のメモリーフットプリントを最小化するときにも使用します。aggsize は、ほかのサイズオプションと同じく、任意のサイズの接尾辞とともに指定できます。投機バッファーのサイズ変更ポリシーは、bufresize オプションで指定します。バッファリングの詳細については、第 11 章バッファーとバッファリングを参照してください。オプションの詳細については、第 16 章オプションとチューニング可能パラメータを参照してください。
ユーザーレベルで集積体データが消費されるレートを増やすことによっても、集積体欠落の発生を抑えることができます。デフォルトでは、このレートは毎秒 1 回ですが、この値は、aggrate オプションを指定して明示的にチューニングできます。aggrate は、その他のレートオプションと同じく、任意の時間接尾辞とともに指定できます。ただし、デフォルトでは、秒当たりのレートが設定されています。aggsize オプションの詳細については、第 16 章オプションとチューニング可能パラメータを参照してください。
- © 2010, Oracle Corporation and/or its affiliates