Solaris 動的トレースガイド

以下は、vmstat(1M) の出力例です。


kthr      memory            page            disk          faults      cpu
 r b w   swap  free  re  mf pi po fr de sr cd s0 — —   in   sy   cs us sy id
 0 1 0 1341844 836720 26 311 1644 0 0 0  0 216 0  0  0  797  817  697  9 10 81
 0 1 0 1341344 835300 238 934 1576 0 0 0 0 194 0  0  0  750 2795  791  7 14 79
 0 1 0 1340764 833668 24 165 1149 0 0 0  0 133 0  0  0  637  813  547  5  4 91
 0 1 0 1340420 833024 24 394 1002 0 0 0  0 130 0  0  0  621 2284  653 14  7 79
 0 1 0 1340068 831520 14 202 380 0 0  0  0 59  0  0  0  482 5688 1434 25  7 68

pi 列には、ページインされたページ数が出力されています。vminfo プロバイダを使用すると、これらのページインのソースの詳細情報を得ることができます。次の例を参照してください。


dtrace -n pgin'{@[execname] = count()}'
dtrace: description 'pgin' matched 1 probe
^C
  xterm                                                             1
  ksh                                                               1
  ls                                                                2
  lpstat                                                            7
  sh                                                               17
  soffice                                                          39
  javaldx                                                         103
  soffice.bin                                                    3065

この出力からわかるように、ほとんどのページインは、StarSuiteTM ソフトウェア (soffice.bin) 関連の単一のプロセスによって行われています。soffice.bin の仮想メモリーの動作の様子を詳しく調べたいときは、すべての vminfo プローブを有効にします。以下は、StarSuite ソフトウェアの起動中に dtrace(1M) を実行する例です。


dtrace -P vminfo'/execname == "soffice.bin"/{@[probename] = count()}'
dtrace: description 'vminfo' matched 42 probes
^C

  kernel_asflt                                                      1
  fspgin                                                           10
  pgout                                                            16
  execfree                                                         16
  execpgout                                                        16
  fsfree                                                           16
  fspgout                                                          16
  anonfree                                                         16
  anonpgout                                                        16
  pgpgout                                                          16
  dfree                                                            16
  execpgin                                                         80
  prot_fault                                                       85
  maj_fault                                                        88
  pgin                                                             90
  pgpgin                                                           90
  cow_fault                                                       859
  zfod                                                           1619
  pgfrec                                                         8811
  pgrec                                                          8827
  as_fault                                                       9495

以下のスクリプト例では、StarSuite ソフトウェア 起動時の仮想メモリーの動作を詳しく調べることができます。

vminfo:::maj_fault,
vminfo:::zfod,
vminfo:::as_fault
/execname == "soffice.bin" && start == 0/
{
	/*
	 * This is the first time that a vminfo probe has been hit; record
	 * our initial timestamp.
	 */
	start = timestamp;
}

vminfo:::maj_fault,
vminfo:::zfod,
vminfo:::as_fault
/execname == "soffice.bin"/
{
	/*
	 * Aggregate on the probename, and lquantize() the number of seconds
	 * since our initial timestamp.  (There are 1,000,000,000 nanoseconds
	 * in a second.)  We assume that the script will be terminated before
	 * 60 seconds elapses.
	 */
	@[probename] =
	    lquantize((timestamp - start) / 1000000000, 0, 60);
}

今回も、StarSuite ソフトウェアの起動中にスクリプトを実行します。次に、新しい図形描画と新しいプレゼンテーションを作成し、すべてのファイルを閉じてアプリケーションを終了します。D スクリプトを実行しているシェルウィンドウ内で、Control-C キーを押します。結果として、時間の経過とともに変化する仮想メモリーの様子が出力されます。


# dtrace -s ./soffice.d
dtrace: script './soffice.d' matched 10 probes
^C

 maj_fault                                         
           value  ------------- Distribution ------------- count    
               7 |                                         0        
               8 |@@@@@@@@@                                88       
               9 |@@@@@@@@@@@@@@@@@@@@                     194      
              10 |@                                        18       
              11 |                                         0        
              12 |                                         0        
              13 |                                         2        
              14 |                                         0        
              15 |                                         1        
              16 |@@@@@@@@                                 82       
              17 |                                         0        
              18 |                                         0        
              19 |                                         2        
              20 |                                         0        

  zfod                                              
           value  ------------- Distribution ------------- count    
             < 0 |                                         0        
               0 |@@@@@@@                                  525      
               1 |@@@@@@@@                                 605      
               2 |@@                                       208      
               3 |@@@                                      280      
               4 |                                         4        
               5 |                                         0        
               6 |                                         0        
               7 |                                         0        
               8 |                                         44       
               9 |@@                                       161      
              10 |                                         2        
              11 |                                         0        
              12 |                                         0        
              13 |                                         4        
              14 |                                         0        
              15 |                                         29       
              16 |@@@@@@@@@@@@@@                           1048     
              17 |                                         24       
              18 |                                         0        
              19 |                                         0        
              20 |                                         1        
              21 |                                         0        
              22 |                                         3        
              23 |                                         0        

  as_fault                                          
           value  ------------- Distribution ------------- count    
             < 0 |                                         0        
               0 |@@@@@@@@@@@@@                            4139     
               1 |@@@@@@@                                  2249     
               2 |@@@@@@@                                  2402     
               3 |@                                        594      
               4 |                                         56       
               5 |                                         0        
               6 |                                         0        
               7 |                                         0        
               8 |                                         189      
               9 |@@                                       929      
              10 |                                         39       
              11 |                                         0        
              12 |                                         0        
              13 |                                         6        
              14 |                                         0        
              15 |                                         297      
              16 |@@@@                                     1349     
              17 |                                         24       
              18 |                                         0        
              19 |                                         21       
              20 |                                         1        
              21 |                                         0        
              22 |                                         92       
              23 |                                         0

仮想メモリーシステム関連の StarSuite の動作が出力されています。たとえば、maj_fault プローブは、アプリケーションを新しく起動するまで起動していません。期待したとおり、StarSuite のウォームスタートを行なっても、重大なフォルトは発生していません。as_fault の出力からは、アクティビティの最初のバーストから最後のバーストまでの様子がわかります。最初のバーストのあと、ユーザーがメニューを使って新しい図面を作成するまで遅延が発生します。その後、アイドル状態を経て、ユーザーが新しいプレゼンテーションをクリックした時点で最後のバーストが起こります。zfod の出力からは、新しいプレゼンテーションの作成により、わずかな時間ですが、ゼロで初期化されたページにかなりの負荷がかかっていることがわかります。

以降の DTrace の調査は、調べる内容に応じて異なります。ゼロで初期化されたページの要求元について知りたい場合は、zfod の有効化の際に ustack() を集積できます。ゼロで初期化されたページのしきい値を設定し、しきい値を超えた場合に、stop() 破壊アクションを使って、悪影響を及ぼすプロセスを終了することもできます。この方法では、truss(1)mdb(1) のような従来のデバッグツールも使用できます。vminfo プロバイダでは、vmstat(1M) などの従来のツールで出力された統計情報と、システム全体に影響を及ぼすような動作を引き起こすアプリケーションを関連付けることができます。