カーネル挙動を追尾する「DTrace」の実力：OS選択の新常識（5/8 ページ）

[大澤文孝，ITmedia]

#!/usr/sbin/dtrace -s
#pragma D option quiet
syscall::read:entry
{
        self->time = timestamp;
}
syscall::read:return
{
        @time[execname] = sum(timestamp - self->time);
}
dtrace:::END
{
        printa(@bytes);
}

リスト2　ファイルの読み込みに要した時間計測（filereadtime.d

　リスト2では、readシステムコールのentryプローブとreturnプローブを処理している。

　entryプローブでは、timestamp変数を使って現在のタイムスタンプを取得するビルドイン変数であり、ナノ秒単位での値を保持している。entryプローブの処理では、次のように「self->time」という書式を指定している点に注目しよう。

self->time = timestamp;

　「self->」という書式は、「スレッドローカルな変数」を示すものだ。プローブは異なるスレッドで同時に呼び出される可能性があるが、「self->変数名」という書式を使うと（ここでは変数名としてtimeという名前を用いたが、これは任意名でよい）、スレッドごとに別々の変数が用意されるため、値が混じらなくなる。

　なお、Dスクリプトでは、「self->変数名」と似た書式として「this->変数名」という書式も用意されている。「this->変数名」はブロック内でのみ有効な一時的な変数（C言語で言うところの自動変数。Perlで言えば、My）だ。

　さて、returnプローブでは、次のように現在のタイムスタンプ値から、先にentryプローブで保存しておいたタイムスタンプ値を引いたものの総和を採っている。

@time[execname] = sum(timestamp - self->time);

　これにより、entryからreturnまでの所要時間――readシステムコールが呼び出し終わるまで――の合計を求められるという仕組みだ。

　実際に実行すると、次のように、コマンドごとにファイルの読み込みに要した時間総計がナノ秒単位で表示される（表示される内容は環境によって異なる）。

# dtrace -s filereadtime.d
^C
  cat                                       36265
  ttymon                                    40936
  dtscreen                                 173114
  dtwm                                     217419
  utmpd                                    354749
  sac                                      847370
  sdtperfmeter                            1419325
  java                                    4769073
  Xorg                                    6133046
  more                                  973867805
  tcsh                                16200305646
  dtfile                              30029429139
  sh                              659094214480122