Solaris 動的トレースガイド

第 20 章 `fbt` プロバイダ

この章では、関数境界トレース (Function Boundary Tracing、FBT) プロバイダについて説明します。このプロバイダは、Solaris カーネルのほとんどの関数の開始 (entry) と終了 (return) に関連したプローブを提供します。関数は、プログラムテキストの基本単位です。上手に設計されたシステムでは、各関数が、指定された 1 つのオブジェクトまたは類似した複数のオブジェクトに対して、明確に定義された操作を個別に実行します。このため、どんなに小規模な Solaris システムであっても、FBT は、20,000 個程度のプローブを提供します。

ほかの DTrace プロバイダ同様、FBT でも、明示的に有効にしない限り、プローブの及ぼす影響は皆無です。FBT プローブを有効にすると、それに関連付けられた関数だけがプローブの影響を受けます。FBT 実装は、命令セットアーキテクチャに固有のものですが、FBT は、SPARC と x86 の両方のプラットフォームに実装されています。命令セットごとに、少数ですが、FBT では計測できない関数があります。この関数は、「リーフ関数」と呼ばれています。リーフ関数はコンパイラによって高度に最適化されており、別の関数を呼び出しません。リーフ関数のプローブは、DTrace 内には存在しません。

FBT プローブを効果的に利用するためには、オペレーティングシステム実装に関する知識が必要です。したがって、FBT は、カーネルソフトウェアの開発時や、ほかのプロバイダでは十分でない場合にのみ使用することをお勧めします。syscall、sched、proc、io などのその他の DTrace プロバイダは、オペレーティングシステム実装の知識がなくても使用できます。これらのプロバイダを使って、システム分析に関するほとんどの問題の答えを引き出すことができます。

プローブ

FBT は、カーネル内のほとんどの関数の「境界」でプローブを提供します。関数の境界を越えるのは、関数に入るときと関数から抜けるときです。FBT は、カーネル内の各関数に、関数に入るときと関数から抜けるときに 1 つずつ、合計 2 つの関数を提供しています。これらのプローブにはそれぞれ、entry、return という名前が付けられています。関数名とモジュール名は、プローブの一部として指定されます。すべての FBT プローブは、関数名とモジュール名を指定します。

プローブ引数

`entry` プローブ

entry プローブの引数は、対応するオペレーティングシステムカーネル関数の引数と同じです。これらの引数にアクセスするときは、args[] 配列を使って、引数の型を想定してアクセスします。これらの引数は、次の変数を使うことで、int64_t 型としてアクセスできます。arg0 .. argn の変数です。

`return` プローブ

エントリポイント 1 つに対して、呼び出し元へ戻るポイントを複数持っている関数もあります。通常、ユーザーにとって重要なのは、関数から返される値か、関数が終了したという事実かであって、具体的なリターンパスではありません。このため、FBT は、関数の復帰 (複数存在) を単一の return プローブで収集します。正確なリターンパスが必要な場合は、return プローブの args[0] の値を確認します。この値は、関数テキスト内の復帰命令のオフセット (バイト単位) を表しています。

関数に戻り値がある場合、この戻り値は args[1] に格納されます。関数に戻り値がない場合、args[1] は定義されません。

例

FBT を使用すると、カーネルの実装を簡単に調べることができます。以下に、xclock プロセスの最初の ioctl(2) を記録し、カーネル経由で続きのコードパスをたどるスクリプトの例を示します。

/*
 * To make the output more readable, we want to indent every function entry
 * (and unindent every function return).  This is done by setting the
 * "flowindent" option.
 */
#pragma D option flowindent

syscall::ioctl:entry
/execname == "xclock" && guard++ == 0/
{
	self->traceme = 1;
	printf("fd: %d", arg0);
}

fbt:::
/self->traceme/
{}

syscall::ioctl:return
/self->traceme/
{
	self->traceme = 0;
	exit(0);
}

このスクリプトを実行すると、次のような出力が得られます。

# dtrace -s ./xioctl.d
dtrace: script './xioctl.d' matched 26254 probes
CPU FUNCTION                                 
  0  => ioctl                                 fd: 3
  0    -> ioctl                               
  0      -> getf                              
  0        -> set_active_fd                   
  0        <- set_active_fd                   
  0      <- getf                              
  0      -> fop_ioctl                         
  0        -> sock_ioctl                      
  0          -> strioctl                      
  0            -> job_control_type            
  0            <- job_control_type            
  0            -> strcopyout                  
  0              -> copyout                   
  0              <- copyout                   
  0            <- strcopyout                  
  0          <- strioctl                      
  0        <- sock_ioctl                      
  0      <- fop_ioctl                         
  0      -> releasef                          
  0        -> clear_active_fd                 
  0        <- clear_active_fd                 
  0        -> cv_broadcast                    
  0        <- cv_broadcast                    
  0      <- releasef                          
  0    <- ioctl                               
  0  <= ioctl

上記の出力では、xclock プロセスが、ソケットと関連付けられているように見えるファイル記述子で ioctl() を呼び出しています。

FBT で、カーネルドライバに関する情報を得ることもできます。たとえば、ssd(7D) ドライバには、EIO を返すコードパスが多数あります。FBT を使用すると、エラーを出した正確なコードパスを簡単に突き止めることができます。次の例を参照してください。

fbt:ssd::return
/arg1 == EIO/
{
	printf("%s+%x returned EIO.", probefunc, arg0);
}

EIO の詳細情報を得たい場合は、すべての fbt プローブを投機的にトレースし、関数の戻り値に基づいて commit() (または discard()) を実行します。投機トレースについては、第 13 章投機トレースを参照してください。

FBT を使って、指定のモジュール内で呼び出された関数の情報を得ることもできます。以下は、UFS で呼び出されたすべての関数を一覧表示する例です。

# dtrace -n fbt:ufs::entry'{@a[probefunc] = count()}'
dtrace: description 'fbt:ufs::entry' matched 353 probes
^C
  ufs_ioctl                                                         1
  ufs_statvfs                                                       1
  ufs_readlink                                                      1
  ufs_trans_touch                                                   1
  wrip                                                              1
  ufs_dirlook                                                       1
  bmap_write                                                        1
  ufs_fsync                                                         1
  ufs_iget                                                          1
  ufs_trans_push_inode                                              1
  ufs_putpages                                                      1
  ufs_putpage                                                       1
  ufs_syncip                                                        1
  ufs_write                                                         1
  ufs_trans_write_resv                                              1
  ufs_log_amt                                                       1
  ufs_getpage_miss                                                  1
  ufs_trans_syncip                                                  1
  getinoquota                                                       1
  ufs_inode_cache_constructor                                       1
  ufs_alloc_inode                                                   1
  ufs_iget_alloced                                                  1
  ufs_iget_internal                                                 2
  ufs_reset_vnode                                                   2
  ufs_notclean                                                      2
  ufs_iupdat                                                        2
  blkatoff                                                          3
  ufs_close                                                         5
  ufs_open                                                          5
  ufs_access                                                        6
  ufs_map                                                           8
  ufs_seek                                                         11
  ufs_addmap                                                       15
  rdip                                                             15
  ufs_read                                                         15
  ufs_rwunlock                                                     16
  ufs_rwlock                                                       16
  ufs_delmap                                                       18
  ufs_getattr                                                      19
  ufs_getpage_ra                                                   24
  bmap_read                                                        25
  findextent                                                       25
  ufs_lockfs_begin                                                 27
  ufs_lookup                                                       46
  ufs_iaccess                                                      51
  ufs_imark                                                        92
  ufs_lockfs_begin_getpage                                        102
  bmap_has_holes                                                  102
  ufs_getpage                                                     102
  ufs_itimes_nolock                                               107
  ufs_lockfs_end                                                  125
  dirmangled                                                      498
  dirbadname                                                      498

カーネル関数の引数の目的を理解している場合は、FBT を使って、この関数を呼び出す理由やその方法を確認できます。たとえば、putnext(9F) の最初のメンバーは、queue(9S) 構造体のポインタになります。queue 構造体の q_qinfo メンバーは、qinit(9S) 構造体のポインタになります。qinit 構造体の qi_minfo メンバーは、module_info(9S) 構造体のポインタを持っています。module_info 構造体の mi_idname メンバーには、モジュール名が格納されます。以下の例では、putnext 内で FBT プローブを使用することによってこの情報をまとめ、モジュール名から putnext(9F) 呼び出しを追跡します。

fbt::putnext:entry
{
	@calls[stringof(args[0]->q_qinfo->qi_minfo->mi_idname)] = count();
}

このスクリプトを実行すると、次のような出力が得られます。

# dtrace -s ./putnext.d
^C

  iprb                                                              1
  rpcmod                                                            1
  pfmod                                                             1
  timod                                                             2
  vpnmod                                                            2
  pts                                                              40
  conskbd                                                          42
  kb8042                                                           42
  tl                                                               58
  arp                                                             108
  tcp                                                             126
  ptm                                                             249
  ip                                                              313
  ptem                                                            340
  vuid2ps2                                                        361
  ttcompat                                                        412
  ldterm                                                          413
  udp                                                             569
  strwhead                                                        624
  mouse8042                                                       726

FBT を使って、特定の関数で消費された時間を調べることもできます。以下の例では、DDI 遅延ルーチン drv_usecwait(9F) と delay(9F) の呼び出し元を特定する方法を示します。

fbt::delay:entry,
fbt::drv_usecwait:entry
{
	self->in = timestamp
}

fbt::delay:return,
fbt::drv_usecwait:return
/self->in/
{
	@snoozers[stack()] = quantize(timestamp - self->in);
	self->in = 0;
}

このスクリプトは、ブート中に実行されることに意味があります。システムブート中の匿名トレースの実行手順については、第 36 章匿名トレースで説明します。リブート時に、次のような出力が得られます。

# dtrace -ae

              ata`ata_wait+0x34
              ata`ata_id_common+0xf5
              ata`ata_disk_id+0x20
              ata`ata_drive_type+0x9a
              ata`ata_init_drive+0xa2
              ata`ata_attach+0x50
              genunix`devi_attach+0x75
              genunix`attach_node+0xb2
              genunix`i_ndi_config_node+0x97
              genunix`i_ddi_attachchild+0x4b
              genunix`devi_attach_node+0x3d
              genunix`devi_config_one+0x1d0
              genunix`ndi_devi_config_one+0xb0
              devfs`dv_find+0x125
              devfs`devfs_lookup+0x40
              genunix`fop_lookup+0x21
              genunix`lookuppnvp+0x236
              genunix`lookuppnat+0xe7
              genunix`lookupnameat+0x87
              genunix`cstatat_getvp+0x134

           value  ------------- Distribution ------------- count    
            2048 |                                         0        
            4096 |@@@@@@@@@@@@@@@@@@@@@                    4105     
            8192 |@@@@                                     783      
           16384 |@@@@@@@@@@@@@@                           2793     
           32768 |                                         16       
           65536 |                                         0


              kb8042`kb8042_wait_poweron+0x29
              kb8042`kb8042_init+0x22
              kb8042`kb8042_attach+0xd6
              genunix`devi_attach+0x75
              genunix`attach_node+0xb2
              genunix`i_ndi_config_node+0x97
              genunix`i_ddi_attachchild+0x4b
              genunix`devi_attach_node+0x3d
              genunix`devi_config_one+0x1d0
              genunix`ndi_devi_config_one+0xb0
              genunix`resolve_pathname+0xa5
              genunix`ddi_pathname_to_dev_t+0x16
              consconfig_dacf`consconfig_load_drivers+0x14
              consconfig_dacf`dynamic_console_config+0x6c
              consconfig`consconfig+0x8
              unix`stubs_common_code+0x3b

           value  ------------- Distribution ------------- count    
          262144 |                                         0        
          524288 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@      221      
         1048576 |@@@@                                     29       
         2097152 |                                         0        


              usba`hubd_enable_all_port_power+0xed
              usba`hubd_check_ports+0x8e
              usba`usba_hubdi_attach+0x275
              usba`usba_hubdi_bind_root_hub+0x168
              uhci`uhci_attach+0x191
              genunix`devi_attach+0x75
              genunix`attach_node+0xb2
              genunix`i_ndi_config_node+0x97
              genunix`i_ddi_attachchild+0x4b
              genunix`i_ddi_attach_node_hierarchy+0x49
              genunix`attach_driver_nodes+0x49
              genunix`ddi_hold_installed_driver+0xe3
              genunix`attach_drivers+0x28

           value  ------------- Distribution ------------- count    
        33554432 |                                         0        
        67108864 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 3        
       134217728 |                                         0

末尾呼び出しの最適化

ある関数が別の関数を呼び出して終了したとき、コンパイラは、「末尾呼び出しの最適化」を行うことができます。その結果、呼び出し元のスタックフレームを呼び出された関数で再利用できるようになります。この手続きは、SPARC アーキテクチャでよく行われます。SPARC アーキテクチャのコンパイラは、レジスタウィンドウの負荷を極力抑えるため、呼び出される側の関数で呼び出し元のレジスタウィンドウを再利用します。

この最適化により、呼び出し元関数の return プローブは、呼び出される側の entry プローブより先に起動するようになります。この順序は、かなり混乱を招きやすくなっています。たとえば、特定の関数から呼び出されたすべての関数と、この特定の関数が呼び出すすべての関数を記録する場合、次のようなスクリプトを使用します。

fbt::foo:entry
{
	self->traceme = 1;
}

fbt:::entry
/self->traceme/
{
	printf("called %s", probefunc);
}

fbt::foo:return
/self->traceme/
{
	self->traceme = 0;
}

しかし、foo() が最適化された末尾呼び出しで終わる場合、末尾で呼び出された関数と、この関数によって呼び出された関数は捕捉されません。動的にカーネルの最適化を解除することはできません。また、DTrace は、コードの構造を偽ることを望みません。このため、末尾呼び出しの最適化がいつ行われるかを意識する必要があります。

末尾呼び出しの最適化は、通常、次の例のようなソースコードで行われます。

	return (bar());

次のようなソースコードで行われる場合もあります。

	(void) bar();
	return;

逆に、次の例のような終わり方の関数ソースコードでは、bar() の呼び出しを最適化することができません。これは、bar() の呼び出しが末尾呼び出しではないためです。

	bar();
	return (rval);

末尾呼び出しの最適化が行われているかどうかは、次のようにして判断できます。

DTrace の実行中に、問題の return プローブの arg0 をトレースします。arg0 には、関数内の復帰命令のオフセットが格納されます。
DTrace の停止後、mdb(1) を使って関数を調べます。トレースされたオフセットに、この関数からの復帰命令ではなく、別の関数の呼び出しが含まれている場合、末尾呼び出しの最適化が行われています。

命令セットのアーキテクチャ上の理由から、末尾呼び出しの最適化は、x86 システムよりも SPARC システムでよく使用されます。以下は、mdb を使って、カーネルの dup() 関数内で末尾呼び出しの最適化を検出する例です。

# dtrace -q -n fbt::dup:return'{printf("%s+0x%x", probefunc, arg0);}'

このコマンドの実行中に、bash プロセスなど、dup(2) を実行するプログラムを実行します。このコマンドからは、次のような出力が得られます。

dup+0x10
^C

mdb を使って関数を調べましょう。

# echo "dup::dis" | mdb -k
dup:                            sra       %o0, 0, %o0
dup+4:                          mov       %o7, %g1
dup+8:                          clr       %o2
dup+0xc:                        clr       %o1
dup+0x10:                       call      -0x1278       <fcntl>
dup+0x14:                       mov       %g1, %o7

dup+0x10 が fcntl() 関数の呼び出しであり、ret 命令でないことが、この出力からわかります。したがって、fcntl() の呼び出しは、末尾呼び出しの最適化の一例になっています。

アセンブリ関数

関数に入るだけで抜けない場合や、関数に入らずに抜けるだけの場合が存在します。まれにあるこのような関数は、概して、ハンドコードされたアセンブリルーチンで、ほかのハンドコードされたアセンブリ関数の中へと分岐しています。これらの関数が、解析を妨げることがあってはなりません。分岐先の関数は、分岐元の関数の呼び出し元へ復帰する必要があります。つまり、すべての FBT プローブを有効にした場合、ある関数へ入る動作と別の関数から復帰する動作が同じスタック深度で行われるべきです。

命令セットの制限

一部の関数は、FBT で計測できません。計測不能な関数は、命令セットアーキテクチャに固有の関数です。

x86 の制限

x86 システム上でスタックフレームを作成しない関数は、FBT で計測できません。x86 のレジスタセットは非常に小さいので、ほとんどの関数は、データをスタックに格納するため、スタックフレームを作成します。しかし、一部の x86 関数はスタックフレームを作成しないため、計測できません。x86 プラットフォーム上で計測できない関数の数は決まっていませんが、通常は全体の 5 % 未満です。

SPARC の制限

アセンブリ言語で SPARC システムにハンドコードされたリーフルーチンは、FBT では計測できません。カーネルの大部分は C で書かれているので、C で書かれた関数はすべて FBT で計測できます。

ブレークポイントとの相互作用

FBT は、カーネルテキストを動的に変更することによって機能します。カーネルのブレークポイントも、カーネルテキストを変更することによって機能します。このため、カーネルのブレークポイントを DTrace のロード前の開始時 (entry) または終了時 (return) に配置した場合、FBT はこの関数にプローブを提供しなくなります。これは、その後カーネルのブレークポイントを削除したとしても変わりません。カーネルのブレークポイントを DTrace のロード後に配置した場合、カーネルのブレークポイントと DTrace プローブの両方が、テキスト内の同じポイントに対応するようになります。この場合、デバッガがカーネルを再開すると、まずブレークポイントがトリガーされ、次にプローブが起動します。カーネルのブレークポイントと DTrace は、なるべく併用しないでください。ブレークポイントが必要な場合は、DTrace の breakpoint () アクションを使用してください。

モジュールのロード

Solaris カーネルは、カーネルモジュールを動的にロードしたり、アンロードしたりできます。FBT がロードされ、モジュールが動的にロードされると、FBT により、新しいモジュールに関連付けられた新しいプローブが自動的に提供されます。ロードされたモジュールの FBT プローブが有効化されていない場合、このモジュールの読み込みは解除されます。さらに、このアンロードに伴って、対応するプローブが破棄されます。ロードされたモジュールの FBT プローブが有効である場合、モジュールはビジー状態と見なされるので、アンロードできません。

安定性

以下の表に、FBT プロバイダの安定性を DTrace の安定性機構に従って示します。安定性機構の詳細については、第 39 章安定性を参照してください。

要素	名前の安定性	データの安定性	依存クラス
プロバイダ	発展中	発展中	ISA
モジュール	非公開	非公開	不明
機能	非公開	非公開	不明
名前	発展中	発展中	ISA
引数	非公開	非公開	ISA

FBT はカーネルの実装を公開するので、「安定」に該当するものはありません。モジュールと関数では、名前の安定性およびデータの安定性が「非公開」です。プロバイダと名前のデータの安定性は「発展中」になっていますが、その他のすべてのデータの安定性は「非公開」になっています。これらは、現在の実装に影響を受けています。FBT の依存クラスは ISA です。FBT は現在の命令セットアーキテクチャ全部で使用できますが、将来の任意の命令セットアーキテクチャで FBT を使用できる保証はありません。

第 20 章 fbt プロバイダ