test

プログラミングユーティリティ

カーネルのトレース

Solaris 2.5 リリースから、SunOS のカーネルには TNF プローブがいくつか組み込まれています。このプローブは、システムコール、スレッド状態の移り変わり、ページフォルト、スワッピング、入出力などのカーネルイベントを記録します。ユーザーは、これらのプローブを使用して、アプリケーション処理実行中におけるカーネルの活動状況を詳細にトレースできます。無効になっているプローブは、実行中のカーネルのパフォーマンスにはほとんど影響を与えません。

カーネルをトレースする方法は、いくつか相違点はあるものの、ユーザーレベルのプロセスをトレースする方法と似ています。以降の説明を理解するためには、あらかじめ 「prex の実行」と 「トレースファイルの読み取り」をお読みください。カーネルをトレースするにはスーパーユーザーの特権が必要です。

カーネルのプローブは、prex ユーティリティを使用して制御します。ユーザーは、カーネルのトレースの設定と管理を行うコマンドに加え、プローブの表示と操作を行う標準の prex コマンドも使用することができます。

カーネルのプローブは、トレース記録をカーネルトレースバッファーに書き込みます。このトレース記録を後で処理するためには、tnfxtract ユーティリティを使用してそのバッファーを TNF ファイルにコピーする必要があります。

カーネルトレースファイルを検証するには、tnfdump ユーティリティを使用して行います。これは、ユーザーレベルのトレースファイルを検証する場合とまったく同じ方法です。

カーネルのトレースを行う場合の標準的な手順を以下に示します。

  1. スーパーユーザーになります (su)。

  2. 必要なサイズのカーネルトレースバッファーを割り当てます (prex)。

  3. トレースするプローブを選択して、そのプローブを有効にします (prex)。

  4. カーネルのトレースをオンにします (prex)。

  5. アプリケーションを起動します。

  6. カーネルのトレースをオフにします (prex)。

  7. カーネルトレースバッファーからデータを抽出します (tnfxtract)。

  8. すべてのプローブを無効にします (prex)。

  9. カーネルトレースバッファーの割り当てを解除します (prex)。

  10. トレースファイルを検証します (tnfdump)。

    これらの手順は、2 つのシェルウィンドウを使用すると簡単に実行できます。一方のウィンドウで対話型の prex セッションを実行して、もう一方のウィンドウでアプリケーションと tnfxtract を実行します。「カーネルをトレースするためのシェルスクリプト」に示した ktrace シェルスクリプトを使用すると、上記の作業をさらに簡単にすることができます。

カーネルのトレース制御 (prex)

-k フラグを付けてカーネルに対して、prex を起動します (必ず root として実行してください)。prex が正常にカーネルに接続されると、prex のコマンドプロンプトが表示されます。

# prex -k
prex>
注 -

カーネルには、一度に 1 つの prex セッションしか接続できません。

バッファーの割り当て

カーネルのトレースを行うための最初の手順は、カーネルトレースバッファーの割り当てです。トレースバッファーが一杯になると、古いデータの上に新しいデータが書き込まれます。

バッファーのデフォルトサイズは 384 KB ですが、バッファーを割り当てるときにこのサイズを変更することができます。このバッファーは物理メモリーとカーネルの仮想メモリーの両方を使用するため、バッファーサイズを決める際には、トレース対象のシステムにその影響が及ぶことを考慮してください。RAM の容量が大きいほど、トレース対象の処理に対する影響は少なくなり、より大きな容量のバッファーを割り当てることができます。

prex で buffer コマンドを使用して、バッファーを割り当てます。たとえば、512 KB のバッファーを割り当てる場合は、以下のように行います。

prex> buffer         #バッファーが割り当てられているか?
No trace buffer allocated  
prex> buffer alloc 512k# 512 KB のバッファーを割り当てる
Buffer of size 524288 bytes allocated  
prex>
注 -

バッファーの最小サイズは 128 KB です。128 KB よりも小さいバッファーを割り当てようとした場合には、prex によって 128 KB のバッファーが割り当てられます。

プローブの選択と有効化

カーネルのプローブとその属性は、prex の標準リストコマンドを使用して一覧表示します。たとえば、pagein という名前のプローブの name 属性と keys 属性を表示するには、以下のコマンドを実行します。

prex> list name=pagein keys
name=pagein keys=vm pageio io

io グループに含まれるすべてのプローブの name 属性と keys 属性を表示するには、以下のコマンドを実行します。

prex> list name keys probes io 
name=biodone keys=io blockio
name=physio_start keys=io rawio
name=pagein keys=vm pageio io
name=pageout keys=vm pageio io
name=physio_end keys=io rawio
name=strategy keys=io blockio
prex>

次に、必要なプローブをトレースして、そのプローブを有効にします。たとえば、thread、vm、io を指定するキーを持ったプローブをすべて選択して、そのプローブをトレースできるようにするには、以下のコマンドを実行します。

prex> trace thread vm io     #トレース関数をプローブに接続します。  
prex> enable thread vm io    #プローブを有効にします。
prex>
注 -

ユーザーレベルのプローブとは違って、カーネルのプローブは、prex をカーネルに接続しても自動的にはトレースされません。上記のように、明示的に trace コマンドと enable コマンドを実行する必要があります。

これで、関連するプローブはトレースできる状態になりますが、カーネルのトレースは広域的には許可されていないので、トレース記録は書き込まれません。

プロセスのフィルタリング

システムの動作をすべてトレースする場合 (たとえば、ビジーサーバー上など) には、「トレースの有効と無効」に進んでください。これは、カーネルトレースの最も一般的な使い方であり、また、通常は最も有用な使い方です。

ただし、選択したプロセスに関するトレースデータの生成を制限するオプションも用意されています。このオプションを使用すると、収集して分析しなければならないデータの量を減らすことができます。

prex では、2 つの抽出条件によって、プロセスのフィルタリングを実現しています。

プロセスのフィルタリングを制御するには、prex pfilter コマンドを使用します。

prex> pfilter                # フィルタリングは行われているか？
Process filtering is off  
Process filter set is empty.  
prex> pfilter add 408       # PID 408 をフィルタセットに追加  
prex> pfilter  
Process filtering is off  
Process filter set is {408}  
prex> pfilter on            # プロセスのフィルタリングを有効にする  
prex>
注 -

システムスレッド (割り込みスレッドなど) は、プロセス 0 に属するスレッドとして扱われます。

トレースの有効と無効

トレースを開始するために行う最後の手順は、広域的にカーネルのトレースを有効にすることです。この手順を実行すると、有効にしたプローブが検出されるたびに、そのプローブはカーネルトレースバッファーに記録を書き込みます。

prex> ktrace           # トレースの状態を検査 
Tracing is off  
prex> ktrace on        # カーネルのトレースを有効にする  
prex>

アプリケーションのカーネル動作をトレース (同時に、ユーザーレベルのトレースも開始) するには、この時点でそのアプリケーションを起動します。アプリケーションが終了したとき、またはアプリケーションの動作をサンプリングできるだけの十分なトレースデータを得たときには、広域的にカーネルのトレースを無効にします。

prex> ktrace off       # カーネルのトレースを無効にする  
prex>

トレースバッファーは、カーネル内にそのまま残っています。tnfxtract を使用して、そのトレースバッファーを TNF ファイルにコピーしてください。この操作の手順については、「カーネルトレースデータの抽出 (tnfxtract)」を参照してください。

カーネルのトレースのリセット

トレースバッファーを TNF ファイルにコピーしたら、すべてのプローブを無効にして、バッファーの割り当てを解除することによって、カーネルのトレースをリセットします。リセットすることによって、カーネルのパフォーマンスはトレースを開始する前の状態に戻るため、この操作は重要です。

次のように標準の prex コマンドを使用して、すべてのプローブを無効にし、そのトレースも解除します。

prex> disable $all      # すべてのプローブを無効にする  
prex> untrace $all      # すべてのプローブのトレースを解除  
prex>

最後に、prex buffer コマンドを使用して、トレースバッファーの割り当てを解除します。

注意 - 注意 -

トレースバッファーをトレースファイルにすべてコピーしてから、トレースバッファーの割り当てを解除してください。コピーを行う前にトレースバッファーの割り当てを解除すると、検証用に収集したトレースデータがすべて失われてしまいます。

prex> buffer dealloc    # バッファーの割り当てを解除  

buffer deallocated
prex>

バッファーの割り当てを解除したら、prex を終了して、収集したトレースデータを検証できます。

prex> quit  
#

カーネルトレースデータの抽出 (tnfxtract)

tnfxtract ユーティリティを使用して、アクティブなカーネルトレースバッファーのコピーを外部の TNF トレースファイルに作成します。トレースと並行して tnfxtract ユーティリティを実行することもできますが、通常はトレースを無効にしてから実行します。このユーティリティでは、整合性のある TNF データについてのみ、読み取りおよび書き込みを行うことができます。

抽出したカーネルトレースデータを保持するために tnfxtract が使用するファイルの名前を指定してください。このファイルは、上書きされ、カーネルトレースバッファーと同じサイズに縮小されます。たとえば、カーネルトレースバッファーを ktrace.tnf という名前の一時ファイルに抽出するには、以下のコマンドを実行します。

# tnfxtract /tmp/ktrace.tnf  
# ls -l /tmp/ktrace.tnf  
-rw------- 1 root other 524288 Aug 15 16:00 /tmp/ktrace.tnf  
#

トレースファイルのアクセス権を変更して、すべてのユーザーが読み取れるようにしておくと、スーパーユーザー以外のユーザーでもそのファイルに対して解析ツールを実行できるようになります。

注 -

カーネルクラッシュダンプに対して tnfxtract を使用することもできます。詳細は、tnfxtract(1) を参照してください。

カーネルトレースデータの検証 (tnfdump)

tnfdump を使用して、カーネル trace-file の時刻順の ASCII ダンプを stdout に出力します (この操作は、ユーザーレベルのトレースの場合とまったく同じです)。トレース出力のサイズは非常に大きくなる場合もあるので、通常はページングユーティリティ (more など) を使用して tnfdump を実行するか、または出力ファイルにリダイレクトします。

# tnfdump /tmp/ktrace.tnf | more
注 -

tnfdump には、複数の TNF ファイルを入力として指定できます。複数の TNF ファイルを入力に指定すると、指定した入力ファイル内のイベント記録がすべて時刻順にソートされて出力されます。このため、カーネルトレースファイルと複数のユーザーレベルのトレースファイルを入力として指定することによって、それらのファイルを 1 つに結合することができます。

使用可能なカーネルプローブ (tnf_probes)

SunOS のカーネルプローブは、vmstat、iostat、sar などの主に統計を行う Solaris パフォーマンス監視ツールとほぼ同程度の情報を提供します。ただし、プローブの方が上記の監視ツールよりも詳しい情報を提供します。各プローブは、高精度のタイムスタンプ、スレッド (LWP (軽量プロセス)、スレッド、プロセス識別子)、CPU を記録し、イベントに関連したシステムリソース (ディスク、ファイル、CPU など) の識別もします。

ユーザーは、カーネルのトレースとユーザーレベルのトレースを併用して、アプリケーションまたはライブラリのプローブによって記録されたイベントと、カーネルのプローブによって記録されたイベントを相互に関連付けることができます。これにより、コードがカーネルのサービスをどのように使用しているか、また、システムリソースに対してアプリケーションが行う要求と他のクライアントによって行われる要求がどのように相互に作用しているかを詳しく知ることができます。

以下の節では、SunOS のカーネルプローブについて簡単に説明します。イベント記録フィールドについての詳細は、tnf_probes(4) を参照してください。

スレッドプローブ

thread_create プローブは、カーネルスレッドの作成をトレースします。このプローブは、プロセス識別子、カーネルスレッド識別子、新しいスレッドの開始ルーチンのカーネルアドレスを記録します。

thread_exit プローブは、現在のスレッドの終了を記録します。

スレッド状態の移り変わりをトレースするプローブは、マイクロステートプローブと呼ばれます。このプローブは、スレッド状態とスレッド識別子 (オプション) を記録します。スレッド識別子が指定されている場合は、状態変化はそのスレッドに適用されます。スレッド識別子が指定されていない場合は、状態変化は書き込みスレッドに適用されます。

スレッド状態の値には、<sys/msacct.h> で定義されたマイクロステート定数が使用されます。記録されるスレッド状態を表 1-7 に示します。

表 1-7 スレッドマイクロステート定数

状態 

説明 

user

ユーザーモードで実行中 

system

システムモードで実行中 

tfault

ユーザーテキスト障害の初期状態 

dfault

ユーザーデータ障害の初期状態 

trap

その他のトラップの初期状態 

user_lock

ユーザーモードのロックを待つための休眠 

sleep

その他の理由による休眠 

wait_cpu

CPU 待ち (実行可能)  

stopped

停止 (/proc、jobcontrol、lwp_stop)

注 -

トレース量を減らすため、カーネルは、システムコールによって暗黙に示されているシステム状態とユーザー状態との間の遷移はトレースしません。この情報を得るには、システムコールプローブを有効にする必要があります。thread キーを使用してプローブを有効にすると、システムコールプローブは自動的に有効になります。

システムコールプローブ

システムコールの入口および出口のプローブは、ユーザーコードによって明示的に要求されたシステム操作を識別します。

syscall_start プローブは、システムコールの開始とそのシステムコール番号を記録します。システムコールの引数を捕捉するのはかなり大きな負荷がかかるので、このプローブはシステムコールの引数は捕捉しません (ユーザーレベルで C ライブラリのエントリポイントにプローブを挿入すると、システムコールの引数についての情報の一部を捕捉できます)。また、この syscall_start プローブは、system 状態に入ったときに現在のスレッドを暗黙的に記録します。

syscall_end プローブは、システムコールの終了、そのシステムコールの 2 つの戻り値、および errno 値を記録します。また、この syscall_end プローブは、user 状態に入ったときに現在のスレッドを暗黙に記録します。

注 -

このレベルでのシステムコールの実装は、Solaris のリリースによって異なります。各システムコールに対応する番号がどのリリースでも同じとは考えないでください。

VM プローブ

仮想メモリーサブシステム (VM) プローブは、ページフォルト、ページ入出力、ページデーモン、スワッパーに関する情報を提供します。

ページフォルト

ページフォルトプローブは、仮想アドレスを障害の種類とファイル (vnodes) に関係付けます。

address_fault プローブは、アドレス空間障害をトレースして、障害が発生した仮想アドレス、障害の種類、要求されたアクセス権を記録します。

障害の種類およびアクセス権の種類を表す値には、<vm/seg_enum.h> で定義された定数が使用されます。障害の種類には、無効なページ (軽い障害)、アクセス権障害、物理的な入出力用のページのロック/ロック解除を行うソフトウェア要求 (softlock と softunlock) があります。アクセス権の種類には、読み取り、書き込み、実行、作成があります。

major_fault プローブは、深刻なページフォルトをトレースします。このプローブは、障害を解決する際に必要となる vnode とオフセットを記録します。この 2 つの組み合わせによって、ファイルシステムのページが識別されます。このデータを現在のスレッドの直前の address_fault イベントに相互に関連付けて、障害が発生した仮想アドレスを知ることができます。

anon_private プローブは、コピー時の書き込み障害をトレースします。

anon_zero プローブは、zero-fill 障害をトレースします。

page_unmap プローブは、物理ページとファイルシステムページとの間の分離を記録します (たとえば、ページの名前が変更されたときや、ページが削除されたときなど)。

ページ入出力

pagein プローブは、ページイン要求の開始をトレースして、vnode、オフセット、ページインのサイズを記録します。

pageout プローブは、ページアウト要求の完了をトレースして、ページアウトされたページ数、開放されたページ数、ページアウト後に再要求されたページ数を記録します。

ページデーモン

ページデーモン (ページスティーラ) は、2 つのプローブ pageout_scan_start と pageout_scan_end によってトレースされます。これらのプローブは、検査前に必要な空きページ数、検査されたページ数、検査前と検査後の空きページ数を報告します。検査によってキューに入れられた pageout 要求がすべて完了すれば、さらに多くのページが開放される可能性があります。

スワッパー

以下の 3 つのプローブによって、スワッパーの活動状況がトレースされます。

ローカル入出力プローブ

strategy プローブは、カーネルによるローカルブロックデバイス入出力の開始をトレースして、転送に関係するデバイス番号、論理ブロック番号、サイズ、バッファーポインタ、バッファーフラグを記録します。このフラグ値は、<sys/buf.h> で定義されているバッファー状態フラグです。

biodone プローブは、バッファー付き入出力転送の完了、つまりカーネルの biodone(9f) ルーチンの呼び出しをトレースします。このプローブは、転送に関係するデバイス番号、論理ブロック番号、バッファーポインタを記録します。

物理 (生の) 入出力は、physio(9f) の 2 つのプローブ physio_start と physio_end によってトレースされます。これらのプローブは、デバイス番号、オフセット、サイズ、入出力転送の方向を記録します。

その他のプローブ

thread_queue プローブは、スレッドのスケジューリングをトレースします。スケジューリングされているスレッドのスレッド識別子、スレッドが配置されているディスパッチキューに関連付けられている CPU、スレッドのディスパッチ優先順位、ディスパッチキュー上にある実行可能スレッドの現在の数を記録します。

カーネルをトレースするためのシェルスクリプト

例 1-3 ktrace スクリプト

#!/bin/sh
#
# ktrace
# カーネルのトレースをリセットし有効にする
# 指定されている場合はコマンドをバックグラウンドで実行する
# 指定されている場合は休眠 (スリープ) する
# コマンドの実行完了、タイムアウト、キーボードの割り込みを待機
# (注 : キーボード割り込みによってコマンドは終了する)
# カーネルのトレースを無効にする
# カーネルトレースバッファーを抽出する
# 指定されている場合はカーネルのトレースをリセットする
#
 
TMPDIR=${TMPDIR:-/tmp}
 
output_file=$TMPDIR/ktrace.tnf
buffer_size=512k
duration=
events=
command=
do_reset=y
child=
alarm=
 
# 使用法のメッセージ
usage() {
 echo ""
 echo $1
 echo "
Usage: ktrace [-o <output_file>] # デフォルトでは /tmp/ktrace.tnf
              [-s <buffer_size>] # デフォルトでは 512k
              -e <events>        # 有効にするカーネルプローブ (キー)
              [-r]                  # カーネルのトレースをリセットしない
                                    # デフォルトでは、コマンド実行後にリセットする
              <cmd> | -t <seconds>
 
Eg,
 # ktrace -e `thread vm io' -t 10
 # ktrace -e `thread' -s 256k myapp ...
"
 exit 1
}
# 失敗時のメッセージ
fail() {
 while [ $# -gt 0 ]
 do
  echo $1
  shift
 done
 echo "ktrace failed"
 exit 2
}
 
# カーネルのトレースをリセットする
ktrace_reset() {
 if [ $1 = "y" ]; then
  echo "Resetting kernel tracing"
  prex -k >/dev/null 2>&1 <<-EOF
   ktrace off
   untrace /.*/
   disable /.*/
   buffer dealloc
   EOF
  test $? -ne 0 && fail "Could not reset kernel tracing" ¥
   "`su root' and retry"
 fi
}
 
# カーネルのトレースを有効にする
ktrace_on() {
 echo "Enabling kernel tracing"
 prex -k >/dev/null 2>&1 <<-EOF
  buffer alloc $buffer_size
  trace $events
  enable $events
  ktrace on
  EOF
 test $? -ne 0 && fail "Could not enable kernel tracing" ¥
  "Check syntax of `-e' argument" ¥
  "Check buffer size is not too high"
}
 
# カーネルのトレースを無効にする
ktrace_off() {
 prex -k >/dev/null 2>&1 <<-EOF
  ktrace off
  EOF
 test $? -ne 0 && fail "Could not disable kernel tracing"
 echo "Kernel tracing disabled"
}
 
# カーネルトレースバッファーを抽出する
ktrace_xtract() {
 echo "Extracting kernel trace buffer"
 tnfxtract $output_file || fail "Could not extract kernel trace
 buffer"
 ls -l $output_file
}
 
# コマンドを実行、休眠、またはコマンド実行完了を待機する
run_command() {
 trap `interrupt' 0 1 2 3 15
 if [ "$command" ]; then
  $command &
  child=$!
  echo "`$command' pid is $child"
 fi
 
 if [ "$duration" ]; then
  sleep $duration &
  alarm=$!
  wait $alarm
  # XXX test -z "$child" || kill -15 $child
 else
  wait $child
 fi
 trap 0 1 2 3 15
}
 
# キーボード割り込み
interrupt() {
 test -z "$alarm" || kill -15 $alarm
 test -z "$child" || kill -15 $child
}
 
# オプションを読み取る
while getopts o:s:t:e:r opt
do
 case $opt in
  o) output_file="$OPTARG";;
  s) buffer_size="$OPTARG";;
  t) duration="$OPTARG";;
  e) events="$OPTARG";;
  r) do_reset="n";;
  ¥?) usage;;
 esac
done
 
shift `expr $OPTIND - 1`
 
# 実行するコマンドを取得する
test $# -gt 0 && command="$*"
 
# オプションを検査
test -z "$events" && usage "No kernel events specified"
test -z "$command" && test -z "$duration" && ¥
usage "No command or time duration specified"
 
# 検査を実行する
ktrace_reset y           # カーネルのトレースをリセット
ktrace_on                # カーネルのトレースを有効に
run_command              # コマンド実行、待機、または休眠
ktrace_off               # カーネルのトレースを無効に
ktrace_xtract            # バッファを抽出
ktrace_reset $do_reset   # カーネルのトレースを再度リセット
exit 0