Solaris 動的トレースガイド

`tick`

Solaris では、CPU アカウンティングがクロック刻みで行われます。このような CPU アカウンティングでは、決まった時間間隔でシステムクロック割り込みが発生し、そのとき実行中のスレッドとプロセスが CPU を使用しているものと見なされます。以下は、tick プローブを使ってこのアカウンティングの様子を調べる例です。

# dtrace -n sched:::tick'{@[stringof(args[1]->pr_fname)] = count()}'
^C
  arch                                                              1
  sh                                                                1
  sed                                                               1
  echo                                                              1
  ls                                                                1
  FvwmAuto                                                          1
  pwd                                                               1
  awk                                                               2
  basename                                                          2
  expr                                                              2
  resize                                                            2
  tput                                                              2
  uname                                                             2
  fsflush                                                           2
  dirname                                                           4
  vim                                                               9
  fvwm2                                                            10
  ksh                                                              19
  xterm                                                            21
  Xsun                                                             93
  MozillaFirebird                                                 260

システムクロック周波数は、オペレーティングシステムによって異なりますが、通常は 25 - 1024 ヘルツです。Solaris のシステムクロック周波数は調整できます。デフォルトでは 100 ヘルツです。

tick プローブは、システムクロックが実行可能なスレッドを検出したときにだけ起動します。tick プローブを使ってシステムクロック周波数を監視するには、常時実行可能なスレッドが必要です。まず、次の例のようなループしたシェルを作成します。

$ while true ; do let i=0 ; done

先ほどとは別のウィンドウで、次のスクリプトを実行します。

uint64_t last[int];

sched:::tick
/last[cpu]/
{
	@[cpu] = min(timestamp - last[cpu]);
}

sched:::tick
{
	last[cpu] = timestamp;
}

# dtrace -s ./ticktime.d
dtrace: script './ticktime.d' matched 2 probes
^C

  0          9883789

最小の間隔は 9.8 ミリ秒です。つまり、デフォルトのクロック周波数は 10 ミリ秒 (100 ヘルツ) になります。上の例で検出された最小値が 10 ミリ秒未満なのは、ジッターが発生しているせいです。

クロック刻みのアカウンティングには、欠点もあります。それは、アカウンティングを行うシステムクロックによって、時間に関するスケジューリングアクティビティがディスパッチされる場合があるということです。その結果、クロック刻みと同間隔で (つまり 10 ミリ秒に 1 回) スレッドが何らかの作業を行う場合に、正しいアカウンティングができません。時間に関するスケジューリングアクティビティのディスパッチの前後どちらでアカウンティングが行われるかによって、結果が実際よりも上下します。Solaris では、時間に関するディスパッチの前にアカウンティングが行われます。その結果、一定間隔で実行されるスレッドについてのアカウンティングが実際より低く報告されます。このようなスレッドは、実行期間をクロック刻みより短くすることによってクロック刻みの背後に「隠す」ことができます。以下は、システムにこのようなスレッドがどのくらいあるかを表示する例です。

sched:::tick,
sched:::enqueue
{
	@[probename] = lquantize((timestamp / 1000000) % 10, 0, 10);
}

このスクリプトを実行し、出力結果を確認すると、10 ミリ秒間にミリ秒のオフセットが 2 つ存在することがわかります。1 つは tick プローブのオフセット、もう 1 つは enqueue のオフセットです。

# dtrace -s ./tick.d
dtrace: script './tick.d' matched 4 probes
^C
  tick                                              
           value  -------------- Distribution ------------ count    
               6 |                                         0        
               7 |@                                        3        
               8 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@   79       
               9 |                                         0        

  enqueue                                           
           value  -------------- Distribution ------------ count    
             < 0 |                                         0        
               0 |@@                                       267      
               1 |@@                                       300      
               2 |@@                                       259      
               3 |@@                                       291      
               4 |@@@                                      360      
               5 |@@                                       305      
               6 |@@                                       295      
               7 |@@@@                                     522      
               8 |@@@@@@@@@@@@                             1315     
               9 |@@@                                      337

ヒストグラム tick からは、クロック刻みが 8 ミリ秒のオフセットで起動していることがわかります。スケジューリングがクロック刻みと無関係に行われていれば、enqueue の出力結果は 10 ミリ秒間の中で均一に分布するはずです。しかし、実際には 8 ミリ秒のオフセットで値が大きく変化しています。したがって、このシステムには、時間ベースでスケジューリングされるスレッドも多少存在していることになります。