第 1 章 TNF ユーティリティによるプログラム実行のトレース

この章では、TNF (Trace Normal Form) ユーティリティを使用してプログラムからデータを収集する方法について説明します。

TNF ユーティリティは、TNF バイナリファイルの作成、処理、読み取りを行う、ライブラリおよびプログラム群で構成されています。この TNF ユーティリティを使用して、以下の作業を行うことができます。

• C または C++ プログラムの実行をトレースする

• C または C++ プログラムをデバッグする

• C または C++ プログラムのパフォーマンスデータを収集する

• アプリケーション実行中のカーネルの活動状況をトレースする

TNF ユーティリティは、初級プログラマが実行中のプログラムのイベントをトレースする場合にも、上級プログラマがマルチスレッド化されたプログラムにおける複数のスレッドとカーネルとの間の相互作用をトレースする場合にも、便利なユーティリティです。

• 「ユーザーの分類」

• 「TNF ユーティリティの使い方」

• 「カーネルのトレース」

• 「上級者向きのトピック」

この章の始めの部分では、TNF ユーティリティの概要について説明しています。その後に、詳細な情報が記述されています。初級プログラマの方は、目的の作業を行うのに必要な部分だけを読んでください。上級プログラマの方は、この章をすべて一読することをお勧めします。

ユーザーの分類

初級プログラマと上級プログラマの区別とは別に、TNF ユーティリティの用途によってユーザーを以下のように分類できます。

既存のプローブポイントを使用

プログラムまたはライブラリに付属しているプローブポイントを使用する場合は、prex および tnfdump に関する節をお読みください。プローブの挿入方法についての説明はとばしても構いません。

プログラムをデバッグ

プログラムをデバッグについては、この章の必要な部分を読んでください。実行するトレースの複雑さによって、必要な箇所は異なります。

ライブラリへプローブポイントを挿入

作成中のライブラリにプローブポイントを挿入する場合は、この章全体をお読みください。また、ライブラリのユーザー用に、プローブポイントに関する情報を必ず提供してください。

カーネル実行をトレース

カーネル内のいくつかの TNF プローブは、システムコール、スレッドの状態の移り変わり、ページフォルト、スワッピング、および入出力を記録します。カーネルをトレースする方法の大部分は、ユーザーレベルのプロセスをトレースする場合と同じです。

TNF ユーティリティの使い方

TNF ユーティリティは、libtnfprobe ライブラリ、prex(1) コマンド、および tnfdump(1) コマンドで構成されています。

• libtnfprobe - プログラムにリンクされているライブラリで、トレース記録をバイナリの TNF トレースファイルに生成します。

• prex - プローブポイントと、プローブポイントによって収集された各種データを操作するユーティリティです。

• tnfdump - バイナリの TNF トレースファイルを ASCII ファイルに変換するユーティリティです。

コード内のデータを収集する箇所 (プローブポイント) に、コマンドを挿入することができます。prex を使用して実行可能オブジェクトを実行すると、プローブポイントの操作が可能になります。収集された情報は、Trace Normal Form (TNF) と呼ばれる形式のトレースファイルに書き込まれます。tnfdump は、そのバイナリの TNF トレースファイルを ASCII ファイルに変換します。

プローブポイントは、.init() セクション、.fini() セクション、マルチスレッド化されたコード、共有オブジェクト、dlopen(3X) によってオープンされた共有オブジェクトなど、C または C++ コードの任意の場所に挿入できます。

また、プローブ関数と呼ばれる関数をこれらのプローブポイントに接続できます。プローブ関数は、収集された情報に基づいてアクションを実行します (現在使用できるプローブ関数は、出力を stderr に書き込むデバッグ関数だけです) 。

通常の TNF セッションでは、以下の操作を行います。

1. プローブポイントをプログラムに挿入します。ソースコードには、プローブポイントがすでに組み込まれている場合もあります。

2. prex を使用して、プログラムを起動します。libtnfprobe は自動的に prex によって起動前にロード (プリロード) されます。プログラムを起動するときに、そのプログラムを libtnfprobe にリンクすることもできます。その場合は、実行中のプログラムに prex を接続できます。「実行中のプロセスへの prex の接続」を参照してください。

3. prex でプローブポイントを操作して、必要な情報をプログラムから収集します。

4. tnfdump を使用して、ターゲットプログラムから生成されたバイナリの TNF 情報トレースファイルを ASCII ファイルに変換します。「読み取り可能な形式へのバイナリファイルの変換」を参照してください。

5. ASCII ファイル中の情報を確認します。

プローブポイントの挿入

プローブポイントの挿入についての詳細は、「上級者向きのトピック」で説明しています。

「C プログラムのサンプル」では、プローブポイントの設計と配置について説明しています。「prex セッションのサンプル」と 「トレースファイルの読み取り」では、プローブポイントの操作方法と、それぞれのプローブポイントでどのような情報が収集されるかについて説明しています。

prex の起動

ユーザーは、prex を使用してプログラムをロードするか、もしくは実行中のプロセスに prex を接続することができます。以下の 2 つの節で、その手順を説明します。

prex によるプログラムの起動

prex を使用してプログラムを起動すると、ターゲットのプログラムに libtnfprove ライブラリがプリロードされます。したがって、プログラムを明示的に libtnfprobe にリンクする必要はありません。

prex は、プログラムを起動し、コードが実行される前にそのプログラムを停止します。.init() セクションが実行される前であってもプログラムの実行は停止されるため、プローブポイントを .init() セクションに配置して初期化コードをトレースすることができます。

プローブポイントが含まれていて、引数を受け取らない a.out という単純な実行可能プログラムの場合には、以下のコマンドを使用できます。

$ prex a.out

(prex は、環境変数 $PATH を使用して実行可能プログラムを検索します。)

オプションを指定するには、以下の書式で指定します。

prex [-o outfilename] [-s kbytes_size]
     [-l sharedobjs] cmd [cmdargs...]

-o、-s、-l オプションについては、「prex のコマンド行オプション」で説明しています。

実行中のプロセスへの prex の接続

a.out という名前のプログラムを実行中に、その a.out のプロセス ID (PID) が 2374 である (ps(1) コマンドを使用して確認できます) が示した場合には、以下のコマンドによって prex を a.out に接続できます。

$ prex -p 2374

実行中のプログラムに prex を接続する場合には、先に libtnfprobe をそのプログラムにリンクする必要があります。libtnfprobe にリンクしていないと、libtnfprobe がプログラムにリンクされていないというエラーメッセージが表示され、prex が終了します。

libtnfprobe とのリンク

libtnfprobe ライブラリにリンクすると、割り当てられたトレースファイルのサイズ (prex のコマンド行オプションで制御可能) に約 33 KB (25 KB は共有可能) を加えた分だけプログラムのサイズが、増加します。prex を使用して実行中のプログラムに接続しない場合は、libtnfprobe にリンクしないでください。

ただし、再起動が容易ではなく、長時間連続して実行するプログラムの場合で、将来そのプログラムに関する情報を収集する可能性がある場合には、libtnfprobe をプログラムにリンクしてください。ウィンドウサーバーなどが、その例です。このような停止や再起動を頻繁に行わない種類のプログラムの場合には、プログラムの実行を開始する前に libtnfprobe にリンクする必要があります。

以下のいずれかの方法で libtnfprobe に、リンクすることができます。

これからプログラムのコンパイルを行う場合には、cc 行に -ltnfprobe を追加します (-lthread を使用している場合には、必ず -lthread の前に -ltnfprobe を入力してください)。

$ cc -ltnfprobe -lthread -o cookie cookie.c

プログラムがコンパイル済みの場合、または libtnfprobe に明示的に依存するプログラムを作成しない場合には、以下のコマンドを使用します。

$ LD_PRELOAD=libtnfprobe.so.1 executable_object_name

LD_PRELOAD については、『リンカーとライブラリ』を参照してください。

prex の停止と再開

prex を使用してプログラムをロードするか、または実行中のプログラムに prex を接続したら、Control-c キーを押してプログラムを停止し、制御を prex に渡します。

prex が実行されて、プログラムが停止すると、prex のプロンプトが表示されます。

prex>

このプロンプトに prex コマンドを入力して、プローブポイントを制御します。たとえば、プローブポイントの一覧表示や、トレースの開始、プログラムのデバッグを行うことができます。

プログラムの実行を再開するには、continue コマンドを入力します。

prex> continue

プログラムを停止して prex に戻るには、Control-c キーを押します。

$ ^c
prex>

prex の標準のコマンド行オプションを表 1-1 に示します。

prex のコマンド行オプション

prex の実行

prex をプログラムに接続後、prex コマンドを使用して、収集するデータのパラメータを変更できます。prex list コマンドを使用して、プログラム内のプローブをすべて表示できます。プログラムの実行中にプローブポイントが実行されると、その実行ごとに情報がトレースファイルに記録されます。収集された情報は、tnfdump() を使用して表示します。tnfdump() については、「tnfdump ファイルの読み取り」を参照してください。

ユーザーは、プログラムに対する prex の接続と切り離しを繰り返し行なって、複数のセッションを作成できます。たとえば、最初のセッションでは、prex を使用してターゲットプログラムを起動し、プローブを設定してから prex コマンドの quit resume を実行することができます。

この操作は、prex の起動、収集する情報の定義、prex の終了を行い、最後にプログラムの実行を再開することによって情報の収集を開始します。これらの処理を行うコマンドを表 1-2 に示します。

2 回目のセッションでは、prex を同じプログラムに接続して、プローブを再設定してから、再度 prex コマンドの continue を実行することができます。この操作は繰り返し何度でも行うことができます。

すべてのトレース結果は、最初のセッションで名前を指定したトレースファイルに書き込まれます。このトレースファイル名を変更することはできません。

prex コマンドの構成要素

プローブポイントをソースコードに挿入するときに、さまざまな属性や (必要に応じて) 値を各プローブポイントに割り当てることができます。たとえば、任意の名前を "name" 属性の値に割り当てることができます。

定義済みの属性とその値の意味を表 1-3 に示します。prex コマンドを使用して、プローブポイントの属性または値に一致する複数のプローブポイントをグループとして選択できます。また、選択したプローブポイントのトレースやデバッグを行うこともできます。

prex コマンドとそのアクションは、表 1-5 を参照してください。

例 1-1 では、TNF_PROBE マクロによって work_start という名前のプローブポイントが定義されています。このプローブポイントには、state と message という 2 つの引数があります。work_start という名前のプローブが検出されるたびに、変数 state と message のタイムスタンプと値がトレースファイルに記録されます。

例 1-1 prex の属性と値

 #include <tnf/probe.h>
 
 int
 work(int state, char *message)
 {
    TNF_PROBE_2(work_start, "work_module work"
               "sunw%debug in function work",
               tnf_long, int_input, state,
               tnf_string, string_input, message);
   ...
   ...
 }

TNF_PROBE マクロとこのコード例についての詳細は、「TNF_PROBE マクロの使い方」を参照してください。

属性

属性は、コード内のプローブポイントを識別するための特性です。定義済みの属性を表 1-3 に示します。ユーザーは、TNF_PROBE を使用して別の属性を追加定義することができます。「TNF_PROBE マクロの使い方」を参照してください。

プローブの照合構文

プローブの属性と値に基づいてプローブを選択します。 selector_list に選択条件を指定します。それぞれの属性または値は、以下のいずれかで表現できます。

• 識別子−英字、数字、_ ¥ . % (下線、バックスラッシュ、ピリオド、パーセント記号) を使用した文字列。識別子の最初の文字を数字にすることはできません。

• 引用符付き文字列−単一引用符で囲んだ文字列。この文字列は文字どおりに解釈される直定数とみなされます。照合する文字列が予約語の場合に便利な表現です。予約語の一覧については、表 1-4 を参照してください。

• 正規表現−スラッシュ (/) で囲んだ文字列。ed(1) の規則に従って照合用に拡張されています。正規表現においてパス名などを表すためにスラッシュを使用する場合は、/¥/tmp¥/filename のように、バックスラッシュでそのスラッシュをエスケープしてください。

selector_list は、1 つ以上の selector= という形式の選択条件で構成されています。最初の selector= が指定されていない場合は、keys= がデフォルトになります。たとえば、enable コマンドは以下の書式で指定します。

enable selector_list

たとえば、以下のように指定します。

enable name=/first/ file='sampleZ.c'

このコマンドは、値 first が含まれている name 属性 (正規表現による一致) をもつプローブポイント、または値が sampleZ.c である file 属性を持つプローブポイントをすべて有効にします。なお、トレースは、論理積ではなく論理和であることに注意してください。

選択条件 selector_list の簡略名として、$set_name のように変数を設定することができます。以下の例では、myprobes がその set_name に当たります。

create $myprobes name=/first/ file='sampleZ.c'
enable $myprobes

これは、前述の例と同じ処理を行います。set_name は、識別子の命名規則に従っています。デフォルト設定の $all は、プログラムのプローブをすべて選択します。

予約語

予約語を表 1-4 に示します。これらの予約語を使用して属性または値を選択する場合は、その予約語を単一引用符で囲んでください。

たとえば、以下のコマンドは、trace 属性の値が ON のプローブをすべて有効にします。trace と on はどちらも予約語なので、単一引用符で囲む必要があります。

enable 'trace'='on'

list name file probes $all

トレース、プローブポイント、デバッグ関数の設定状態

プローブポイントをトレースするには、プローブポイントのトレースをオンにして、プローブポイントを有効にする必要があります。プローブポイントでデバッグするには、プローブポイントをデバッグ関数に接続して、そのプローブポイントを有効にする必要があります。

トレース、プローブポイント、デバッグ関数の設定状態の組み合わせと、その結果を表 1-6 に示します。

スクリプトによる prex の制御

prex へのコマンドは、prex コマンド行から、または prex コマンドが含まれているファイルから入力します。

prex を起動すると、prex は .prexrc という名前のファイルをまず $HOME/ ディレクトリ内で探し、その次に、prex を起動したディレクトリ内で探します。コマンドは、検索されたすべてのファイルから読み取られます。したがって、ホームディレクトリの .prexrc ファイルで設定されたデフォルト値が、現在のディレクトリの .prexrc ファイルによって上書きされる可能性もあります。

検索された .prexrc ファイルを読み取った後は、prex コマンド行から入力されたコマンドが実行されます。.prexrc ファイルを使用して作業のすべてを設定する場合は、.prexrc ファイル中の最後の文を quit resume にします。quit resume は、prex を終了してプログラムを再実行します。

また、prex の実行中には、source filename コマンドを使用して、prex が読み取るコマンドが記述されているファイル filename を指定できます。このファイルは、どのような名前でも構いません。

スクリプト内のコマンドは、prex コマンド行から入力するコマンドと同様に、すべて ASCII 形式にしてください。スクリプトには以下の規則が適用されます。

• 各コマンドの最後には、改行文字を入力します。

• 次の行までコマンドが続く場合は、1 行目の終わりにバックスラッシュ (¥) を入力します。

• トークンは、空白 (1 つ以上の空白文字またはタブ) で区切ります。

• コメントの先頭には、ハッシュ記号 (#) を入力します。

  コマンド行から入力する prex コマンドとスクリプトのコマンドとでコマンド言語は同じですが、スクリプトでは出力が stdout に送られるため、出力を返すコマンド (たとえば、list probes...) をスクリプトで使用してもあまり意味がありません。

C プログラムのサンプル

このプログラム cookie.c は　give me a COOKIE! というメッセージを表示します。それに対する応答は、大文字で入力する必要があります。小文字の場合は誤りとみなされます。また、数値の素因数を計算することもできます。これら 2 つの処理過程を通して、トレース機能がどのように動作しているかを見てみましょう。

このプログラムをコンパイルして cookie() という実行可能プログラムを作成するには、以下のコマンドを実行します。

$ cc -o cookie cookie.c 

このプログラムでは、5 つのプローブポイントが定義 (大文字で表記) されています。各プローブポイントの名前は、start (17 行目)、inloop (33 行目)、factor_start (60 行目)、found_a_factor (65 行目)、factor_end (72 行目)となっています。これらのプローブポイントについての詳細は、「prex セッションのサンプル」で説明しています。

例 1-2 cookie.c のコード

#include <sys/types.h>
#include <stdio.h>
#include <string.h>
#include <tnf/probe.h>

#define MAX_RESPONSE_SIZE 256

static void find_factor(int n);

int
main(int argc, char **argv)
{
    boolean_t shouldexit = B_FALSE;
    int       sum = 0, max_loop = 5;
    int       i;

    TNF_PROBE_0(start, "cookie main", 
         "sunw%debug starting main");

    while (!shouldexit) {
       char response[MAX_RESPONSE_SIZE];
       int factor_input;

       (void) printf("give me a COOKIE! ");
       (void) scanf("%s", response);

       if (!strcmp(response, "COOKIE")) {
            (void) printf("thanks!¥n");
            shouldexit = B_TRUE;
       }

       else if (!strcmp(response, "loop")) {
            for (i = 0; i < max_loop; i++) {
               TNF_PROBE_2(inloop, "cookie main
                           loop","sunw%debug in the loop",
                           tnf_long, loop_count,  i,
                           tnf_long, total_iterations,  sum);
               sum++;
            }
            max_loop += 2 ;
       }

      else if (!strcmp(response, "factor")) {
            (void) printf("number you want factored? ");
            (void) scanf("%d", &factor_input);
            find_factor(factor_input);
      }

      else {
            (void) printf("not a %s, ", response);
      }
    }
    return 0;

}   /* end main */
static void
find_factor(int n)
{
    int i;

    (void) printf("¥tfactors of %d = ", n);
    TNF_PROBE_1(factor_start, "factor", "",
                tnf_long, input_number, n);

    for (i=2; i <= n; i++) {
        while (n % i == 0) {
           TNF_PROBE_2(found_a_factor, "cookie find_factor",
                       "", tnf_long, searching_for, n,
                       tnf_long, factor, i);
           (void) printf("%d ", i);
           n /= i;
        }
    }
    TNF_PROBE_0(factor_end, "factor", "");
    (void) printf("¥n");
}

prex セッションのサンプル

この prex セッションのサンプルは、prex のさまざまな機能を紹介できるように作られています。cookie を実行するときに収集されるデータは、「tnfdump ファイルの読み取り」に示しています。

% prex cookie     /* prex によって、実行可能プログラム cookie がロードされます。*/
Target process stopped
Type "continue" to resume the target, "help" for help ...
prex> list sets
$all      'keys'=/.*/    /* エイリアス $all が 1 つ定義されています 
                                  --- (すべてのプローブです)。*/
prex> list fcns
&debug    tnf_probe_debug      /* デバッグ関数は、使用可能な唯一の関数です。*/
prex> list probes $all
name=inloop enable=off trace=on file=cookie.c line=35 funcs=<no value>
name=factor_end enable=off trace=on file=cookie.c line=72 funcs=<no value>
name=factor_start enable=off trace=on file=cookie.c line=61 funcs=<no value>
name=found_a_factor enable=off trace=on file=cookie.c line=67 funcs=<no value>
name=start enable=off trace=on file=cookie.c line=17 funcs=<no value>
prex>/* 行番号は、5 つのプローブのそれぞれの最終行を示しています。*/
prex> create $factor /factor/   /* "keys" 属性に文字列 "factor" が含まれている
                          プローブと一致する新しいセットを作成します。*/
prex>      
prex> list sets
$all      'keys'=/.*/
$factor   'keys'=/factor/        
/* "factor" という名前の新しいセットが作成されて、そのセットが表示されています。*/
prex>                              
  /* セットの一覧 */
prex> list probes $factor            
/* この行によって、どのプローブがそのセットと一致しているかがわかります。*/
name=factor_end enable=off trace=on file=cookie.c line=72 funcs=<no value>
name=factor_start enable=off trace=on file=cookie.c line=61 funcs=<no value>
name=found_a_factor enable=off trace=on file=cookie.c line=67 funcs=<no value>
prex> list probes $all    /* 有効なプローブがあるかどうか検査します。*/
name=inloop enable=off trace=on file=cookie.c line=35 funcs=<no value>
name=factor_end enable=off trace=on file=cookie.c line=72 funcs=<no value>
name=factor_start enable=off trace=on file=cookie.c line=61 funcs=<no value>
name=found_a_factor enable=off trace=on file=cookie.c line=67 funcs=<no value>
name=start enable=off trace=on file=cookie.c line=17 funcs=<no value>
prex>              /* 有効なプローブはありませんが、
                                   どのプローブもトレースはオンになっています。*/

prex> enable $all             /* すべてのプローブを有効にします。*/
prex> list probes $all        /* 有効なプローブがあるかどうか、再度検査します。*/  
name=inloop enable=on trace=on file=cookie.c line=35 funcs=<no value>
name=factor_end enable=on trace=on file=cookie.c line=72 funcs=<no value>
name=factor_start enable=on trace=on file=cookie.c line=61 funcs=<no value>
name=found_a_factor enable=on trace=on file=cookie.c line=67 funcs=<no value>
name=start enable=on trace=on file=cookie.c line=17 funcs=<no value
prex> list values name              /* プローブの名前を調べます。*/
name =                              
    factor_end                   
    factor_start
    found_a_factor
    inloop
    start
prex> list values /.*/          /* 定義済みの属性とその値をすべて表示します。*/
enable =              /* 固有の属性だけを表示します。*/
    on 
file =
    cookie.c
funcs =
   
keys =
    cookie
    factor
    find_factor
    loop
    main
line =
    17
    35
    61
    67
    72
name =
    factor_end
    factor_start
    found_a_factor
    inloop
    start
object =
    cookie
slots =
    factor
    input_number
    loop_count
    searching_for
    total_iterations
sunw%debug =           /* ユーザー定義のマクロ sunw%debug も表示されています。*/
    in     /* このマクロは、cookie.c の 17 行目で定義されています。*/
    loop
    main
    starting
    the
trace =
    on
prex> list values object
object =
    cookie
prex> connect &debug name=inloop
prex> list /.*/ probes $all         /* すべてのプローブの情報をすべて表示します。*/
enable=on trace=on object=cookie funcs=<no value> name=inloop slots=loop_count
total_iterations keys=cookie main loop file=cookie.c line=35 sunw%debug=in the loop 
enable=on trace=on object=cookie funcs=<no value> name=factor_end slots=<no value>
keys=factor file=cookie.c line=72
enable=on trace=on object=cookie funcs=<no value> name=factor_start slots=input_number
keys=factor file=cookie.c line=61 
enable=on trace=on object=cookie funcs=<no value> name=found_a_factor slots=searching_for
factor keys=cookie find_factor file=cookie.c line=67 
enable=on trace=on object=cookie funcs=<no value> name=start slots=<no value> 
keys=cookie
main file=cookie.c line=17 sunw%debug=starting main 
prex> continue
give me a COOKIE! loop       
 /* ループカウントの例 */
probe inloop; sunw%debug "in the loop"; loop_count=0; total_iterations=0;
probe inloop; sunw%debug "in the loop"; loop_count=1; total_iterations=1;
probe inloop; sunw%debug "in the loop"; loop_count=2; total_iterations=2;
probe inloop; sunw%debug "in the loop"; loop_count=3; total_iterations=3;
probe inloop; sunw%debug "in the loop"; loop_count=4; total_iterations=4;
give me a COOKIE! factor 
number you want factored? 25
 factors of 25 = 5 5
give me a COOKIE! factor
number you want factored? 43645729
 factors of 43645729 = 43645729
give me a COOKIE! ^C Target process stopped
Type "continue" to resume the target, "help" for help...
prex> continue
give me a COOKIE! biscuit
not a biscuit, give me a COOKIE!  cookie
not a cookie, give me a COOKIE! COOKIE
thanks!
prex: target process finished

トレースファイルの読み取り

prex で作成したバイナリのトレースファイルには、ユーザーが選択した prex コマンドによって判定された情報が含まれています (「prex の実行」を参照)。

デフォルトでは、トレースファイルは /$TMPDIR/trace-pid に作成されます。この pid は、ターゲットのプログラムのプロセス ID です。$TMPDIR が設定されていない場合は、/tmp/trace-pid にファイルが作成されます。トレースファイルの場所は、prex コマンドに -o オプションを付けて変更できます (詳細については、「prex のコマンド行オプション」を参照してください)。

トレースファイルが一杯になると、新しいイベントによって古いイベントが上書きされます。トレースファイルのデフォルトサイズは、4 MB です。このサイズは、prex の -s オプションで変更することができます。

プログラムのトレース結果がファイルに書き込まれた後で、そのプログラムが存在する間にはそのトレースファイルを削除したり、トレースファイルの名前を変更することはできません。トレースファイルをターゲットプログラムから切り離し、別の名前に変更したトレースファイルを再接続しても、新しい名前は無視されます。

読み取り可能な形式へのバイナリファイルの変換

バイナリのトレースファイルを ASCII ファイルに変換するには、tnfdump コマンドとバイナリのトレースファイルの名前を使用します。デフォルトで tnfdump の出力は stdout に送られるため、その出力をファイルにリダイレクトする必要があります。

$ tnfdump filename > newfile

tnfdump に -r オプションを付けると、詳細な (生の) TNF 出力が得られます。この詳細な TNF 出力を解釈するには、この章の説明範囲を超えた TNF の知識が必要となります。

tnfdump ファイルの読み取り

「prex セッションのサンプル」で説明した prex cookie コマンドの出力を以下に示します。tnfdump ファイルの出力は非常に幅が広いので、出力を表示する場合は幅の広いウィンドウを開いてください。

probe  tnf_name: "start" tnf_string: "keys cookie main;file cookie.c;line 17;sunw%debug
starting main"
probe  tnf_name: "factor_start" tnf_string: "keys factor;file cookie.c;line 61;"
probe  tnf_name: "found_a_factor" tnf_string: "keys cookie find_factor;file cookie.c;line
67;"
probe  tnf_name: "factor_end" tnf_string: "keys factor;file cookie.c;line 72;"
---------------- ---------------- ----- ----- ---------- --- -------------------------
------------------------
    Elapsed (ms)  Delta (ms)     PID  LWPID  TID  CPU Probe Name        Data / Description . . .
---------------- ---------------- ----- ----- ---------- --- -------------------------
------------------------
  0.000000 0.000000 5354 1 0 - start 
 4551.625000 4551.625000 5354 1 0 - factor_start input_number: 25
 4571.278000 19.653000 5354 1 0 - found_a_factor searching_for: 25 factor: 5
 4571.543000 0.265000 5354 1 0 - found_a_factor searching_for: 5 factor: 5
 4571.732000 0.189000 5354 1 0 - factor_end 
  23151.434000 18579.702000 5354 1 0 - factor_start input_number: 101247
  23151.509000 0.075000 5354 1 0 - found_a_factor searching_for: 101247 factor: 3
  23228.090000 76.581000 5354 1 0 - found_a_factor searching_for: 33749 factor: 33749
  23228.250000 0.160000 5354 1 0 - factor_end 
  89041.868000 65813.618000 5354 1 0 - factor_start input_number: -1690908149
  89041.920000 0.052000 5354 1 0 - factor_end 
 108271.852000 19229.932000 5354 1 0 - factor_start input_number: 43645729
 208857.756000  100585.904000 5354 1 0 - found_a_factor searching_for: 43645729 factor:
43645729
 208857.960000 0.204000 5354 1 0 - factor_end 
 334511.548000  125653.588000 5354 1 0 - factor_start input_number: 12
 334511.618000 0.070000 5354 1 0 - found_a_factor searching_for: 12 factor: 2
 334511.689000 0.071000 5354 1 0 - found_a_factor searching_for: 6 factor: 2
 334511.750000 0.061000 5354 1 0 - found_a_factor searching_for: 3 factor: 3
 334511.808000 0.058000 5354 1 0 - factor_end 

tnfdump の表示を見て、factor_end の時間から factor_start の時間を引くと、因数を見つけるまでに要した時間がわかります。43645729 の因数分解には、208857.960000 - 108271.852000 (つまり、100586.11) ミリ秒間かかっています。12 の因数分解には、334511.808000 - 334511.548000 (つまり、0.260000) ミリ秒間かかっています。

どのハードウェアプラットフォームでも、結果はナノ秒の精度で報告されます。ただし、結果の正確度は、使用しているハードウェアプラットフォームによって異なります。

カーネルのトレース

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 つの抽出条件によって、プロセスのフィルタリングを実現しています。

• プロセスのフィルタセットは、トレースを有効にするプロセスのプロセス識別子 (PID) のリストです。このフィルタセットに含まれていないプロセス (に属するスレッド) は、トレースデータの書き込みを行いません。デフォルトのフィルタセットは空です。

• プロセスのフィルタモードは、カーネルにおけるプロセスのフィルタリングの有効/無効を選択するための広域フラグです。デフォルトでは、プロセスのフィルタリングは無効にされています。つまり、すべてのプロセス (とスレッド) がトレース記録を書き込みます。フィルタリングを有効にすると、フィルタセット内のプロセス (に属するスレッド) だけがトレース記録を書き込みます。

プロセスのフィルタリングを制御するには、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 に示します。

トレース量を減らすため、カーネルは、システムコールによって暗黙に示されているシステム状態とユーザー状態との間の遷移はトレースしません。この情報を得るには、システムコールプローブを有効にする必要があります。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 つのプローブによって、スワッパーの活動状況がトレースされます。

• swapout_process プローブは、プロセスアドレス空間のスワップアウトをトレースして、プロセス識別子と、開放されたページまたは出力用にキューに入れられたページの総数を記録します。

• swapout_lwp プローブは、LWP のスタックページのスワップアウトをトレースして、LWP の識別情報と出力用にキューに入れられたページ数を記録します。

• swapin_lwp プローブは、LWP のスタックページのスワップインをトレースして、LWP の識別情報と取り込まれたスタックページ数を記録します。

ローカル入出力プローブ

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

上級者向きのトピック

プローブポイントの挿入

以下のような場合に、プローブポイントをコードに挿入します。

• プログラムの変数値をトレースする。

• エクスポートされたインタフェースからは得ることができない内部状態の情報を提供する。これは、デバッグやパフォーマンス分析を行う場合に役立ちます。

  たとえば、プローブポイントを使用して、C++ の private クラスに隠されているパフォーマンス関連の情報を表示したり、ハッシュテーブル内の衝突率などの処理データを表示できます。ハッシュテーブルのコード中にプローブポイントを配置しておくと、衝突が検出されるたびにそのプローブポイントはトレースファイルに書き込みを行うことができます。

  プローブを挿入するためのインタフェースは、TNF_PROBE_0 から TNF_PROBE_5 までの TNF_PROBE マクロによって定義されます。0 〜 5 の数字は、マクロによってトレースされる変数の数です。

  これらのマクロを使用して、コードの任意の場所にプローブポイントを挿入することによって、変数の値を取得したり、プログラムの実行をトレースすることができます。libtnfprobe ライブラリでは標準のスカラー型 (int、long、float など) が定義されていますが、TNF_DECLARE_RECORD マクロと TNF_DEFINE_RECORD マクロを使用すると、さらに複雑な構造を定義することもできます。「プローブポイントのユーザー定義型」を参照してください。

TNF_PROBE マクロの使い方

単純な例として、TNF_PROBE_0 を以下に示します。このマクロには、引数の型は指定しません。

TNF_PROBE_0 (name, keys, detail);

各変数について説明します。

• name - プローブの名前。この名前は、ANSI C の識別子の構文規則にすべて従います。name は、使用したときに宣言されるので、あらかじめ別に宣言する必要はありません。この宣言はブロックスコープ宣言なので、プログラムの名前空間には影響を与えません。

• keys - プローブが属するグループのリスト。このリスト中には複数のキーワードが含まれており、各キーワードは空白文字で区切られています。このリストの中では、セミコロン (;)、等号 (=)、単一引用符 (') は使用できません。いずれかのグループが有効になると、そのプローブポイントも有効になります。keys を変数にすることはできません。keys はインライン文字列にしてください。

• detail - 独自の属性と値を定義する手段を提供します。detail 文字列には、複数の組の属性と値が含まれており、各組はセミコロンで区切られています。ただし、この値は省略可能です。最初のワード (空白文字まで) は属性、残りの文字列 (セミコロンまで) は値とみなされます。区切り文字のセミコロンの前後には、スペースを入れることができます。detail 文中では単一引用符と等号は使用できません。

  属性名の前にベンダー固有の記号と % 記号を付けて、名前の衝突を避けてください。以下の例では、 sunw%debug、comX%exception、comY%func_entry、comY%color という 4 つの属性が定義されています。prex は空白文字の値をトークン化するので、複数の語から成る値の場合はいずれかの語で照合できますが、文字列全体で照合することはできません。たとえば、以下のような例が考えられます。

  sunw%debug entering function A; 
  comX%exception no file;  
  comY%func_entry;  
  comY%color red blue

上記のコマンドで照合される値を表 1-8 に示します。

libtnfprobe は、ベンダー記号が前に付いていない属性名をすべて予約します (つまり、名前に % 記号が含まれていない属性をすべて予約します)。「C プログラムのサンプル」の cookie.c では、以下の TNF_PROBE_0 を使用しています。

TNF_PROBE_0(start, "cookie main", "sunw%debug starting main");

プリプロセッサオプションの -DNPROBE (cc(1) のマニュアルページを参照) を使用してコンパイルする場合、またはプリプロセッサ制御文 #include <tnf/probe.h> の前に #define NPROBE を置いてコンパイルする場合には、プローブポイントと TNF の型拡張コードがプログラムにコンパイルされないようにしてください。

TNF_PROBE_1 〜 TNF_PROBE_5

引数の名前に含まれている数字 1 〜 5 は、プローブポイントに指定する変数の数を表します。たとえば、TNF_PROBE_1 の構文は次のようになっています。

TNF_PROBE_1(name, keys, detail,
arg_type_1, arg_name_1, arg_value_1);

また、TNF_PROBE_5 の構文は次のようになっています。

TNF_PROBE_5(name, keys, detail,
arg_type_1, arg_name_1, arg_value_1
arg_type_2, arg_name_2, arg_value_2
arg_type_3, arg_name_3, arg_value_3
arg_type_4, arg_name_4, arg_value_4
arg_type_5, arg_name_5, arg_value_5);

以下、各引数について説明します。

• arg_type_n − n 番目の引数の型です。n には 1 〜 5 の数字が入ります。定義済みの型を表 1-9 に示します。ユーザー独自の型の定義については、「プローブポイントのユーザー定義型」 を参照してください。

• arg_name_n − n 番目の引数に与える名前です。 ANSI C の識別子に関する規則に従ってください。また、引数の名前は、引用符で囲まないでください。(「属性」で取り上げた slots 属性には、この名前の文字列の場合が含まれています。)

• arg_value_n − トレースファイルに含まれている値に対して評価される式です。value_n に含まれている任意の変数に対して読み取り (アクセス) を行うことができます。マルチスレッドのプログラムで、読み取りを禁止する必要があるデータが value_n に含まれている場合には、マクロ TNF_PROBE_n の前後にロックを配置してください。

たとえば、「C プログラムのサンプル」の cookie.c では、以下のように TNF_PROBE_2 を使用しています。

TNF_PROBE_2(inloop, "cookie main loop","sunw%debug in the loop",
            tnf_long, loop_count,   i,
            tnf_long, total_iterations,  sum);

cookie.c のマクロ定義の一部について、表 1-10 で説明します。

例 − 関数の所要時間の測定

例 1-4 では、関数の入口と出口にプローブポイントを配置して、関数内で費やされる時間を測定しています。関数の入口に配置されたプローブは、その関数への引数も記録します。

prex は、トレースが許可されているプローブポイントをプログラム実行時に検出すると、トレースファイルに記録を書き込みます。各プローブポイントは、検出された時刻を記録し、ファイル名、行番号、name、keys などのプローブポイントの詳細情報が含まれたタグ記録を参照します。これらのタグの記録は、トレースファイルに 1 度だけ書き込まれ、上書きされることはありません。

以下のコード例において、最初のプローブポイント work_args は、そのプローブポイントの 2 つの変数値 (state と message) も記録します。

例 1-4 関数の入口と出口に配置されたプローブポイント

#include <tnf/probe.h>

int
work(int state, char *message)
{
    TNF_PROBE_2(work_start, "work_module work"
               "sunw%debug in function work",
               tnf_long, int_input, state,
               tnf_string, string_input, message);
   ...
    TNF_PROBE_0(work_end, "work_module work", "");
}

プローブポイントのユーザー定義型

プログラムの構造体をトレースするには、TNF_DECLARE_RECORD マクロと TNF_DEFINE_RECORD_n マクロを使用して新しい型を定義します。これらのマクロは、プローブポイントに渡される型を拡張するためのコンパイル時インタフェースの一部です。

TNF_DECLARE_RECORD(c_type, tnf_type);

TNF_DEFINE_RECORD_1(c_type, tnf_type, 
                    tnf_member_type_1, 
                    tnf_member_name_1)
TNF_DEFINE_RECORD_2(c_type, tnf_type,  
                    tnf_member_type_1, 
                    tnf_member_name_1, 
                    tnf_member_type_2, 
                    tnf_member_name_2)
TNF_DEFINE_RECORD_3(c_type, tnf_type, 
                    tnf_member_type_1, 
                    tnf_member_name_1,
                    tnf_member_type_2, 
                    tnf_member_name_2, 
                    tnf_member_type_3, 
                    tnf_member_name_3)
TNF_DEFINE_RECORD_4(c_type, tnf_type, 
                    tnf_member_type_1, 
                    tnf_member_name_1,
                    tnf_member_type_2, 
                    tnf_member_name_2,
                    tnf_member_type_3, 
                    tnf_member_name_3,  
                    tnf_member_type_4, 
                    tnf_member_name_4) 
TNF_DEFINE_RECORD_5(c_type, tnf_type, 
                    tnf_member_type_1, 
                    tnf_member_name_1,
                    tnf_member_type_2, 
                    tnf_member_name_2,
                    tnf_member_type_3, 
                    tnf_member_name_3,
                    tnf_member_type_4,  
                    tnf_member_name_4,
                    tnf_member_type_5,  
                    tnf_member_name_5)

TNF_DECLARE_RECORD と TNF_DEFINE_RECORD は、新しく定義する型ごとに 1 つだけ作成してください。TNF_DECLARE_RECORD は、TNF_DEFINE_RECORD よりも前に置く必要があります。定義されている tnf_type を複数のソースファイルで使用する必要がある場合は、その複数のファイルで共有するヘッダーファイル中に TNF_DECLARE_RECORD を宣言することができます。TNF_DEFINE_RECORD は、いずれか 1 つのソースファイルだけに作成する必要があります。

TNF_DEFINE_RECORD マクロインタフェースは、1 つの関数といくつかのデータ構造体を定義します。したがってこのインタフェースは、関数の内部ではなく、ソースファイル (.c ファイルまたは .cc ファイル) のファイルスコープ (有効範囲) 内で使用してください。

TNF_DEFINE_RECORD 文の後にセミコロンを置かないでください。セミコロンを置くと、コンパイル時に警告が出力されます。

以下、各変数について説明します。

• c_type − 新しい tnf_type を作成するためのテンプレートです。C 構造体のすべての要素を、定義する TNF 型で使用する必要はありません。c_type は、C の構造体型にしてください。

• tnf_type − 新しく作成した型に与えられる名前です。このインタフェースは、tnf_type を接頭辞とした名前空間を使用します。したがって、ライブラリが xxx_type という新しい型を定義した場合には、そのライブラリは、xxx_type を接頭辞に使用して別のシンボルを定義することはできません。

  型の名前空間の管理方法は、ライブラリ内のその他の名前空間の管理方法と同じです。つまり、ライブラリ内の型以外のシンボルが使用している固有の接頭辞を新しい TNF 型の名前の接頭辞としてください。これによって、新しい TNF 型が定義されている複数のライブラリをリンクしても、名前空間が衝突することはなくなります。

  たとえば、libpalloc.so というライブラリが名前の接頭辞として pal を使用してシンボルを定義している場合には、この libpalloc.so は、新しく定義する TNF 型の名前にも pal を接頭辞として使用する必要があります。

• tnf_member_type_n − C 構造体の n 番目のメンバーの TNF 型です。

• tnf_member_name_n − C 構造体の n 番目のメンバーの名前です。

例 − TNF 型の定義

新しい TNF 型の定義方法と、プローブ内でのその TNF 型の使い方を例 1-5 に示します。

この例 1-5 は、すべてのシンボルの接頭辞に pal を使用している架空のライブラリ libpalloc.so の一部であると仮定しています。

例 1-5 新しい TNF 型の定義

#include <tnf/probe.h>

typedef struct pal_header {
        long    size;
        char * descriptor;
        struct pal_header *next;
} pal_header_t;

TNF_DECLARE_RECORD(pal_header_t, pal_tnf_header);
TNF_DEFINE_RECORD_2(pal_header_t, pal_tnf_header,
                        tnf_long,   size,
                        tnf_string, descriptor)

/* 
 * 注 : 接頭辞 pal_tnf_header が付いている名前空間は、
 *     このクライアントではもう使用できない。
 */

void 
pal_free(pal_header_t *header_p)
{
        int state;

        TNF_PROBE_2(pal_free_start, "palloc pal_free",
                "sunw%debug entering pal_free",
                tnf_long,       state_var, state,
                pal_tnf_header, header_var, header_p);
        . . .
}

next フィールドを使用して自分自身を指し示す構造体 (リンクされたリスト) 中などで、tnf_type を再帰的または相互再帰的に定義することができます。

このような構造体が TNF_PROBE に渡されると、リンクされたリストの全体がトレースファイルに記録されます (next フィールドが NULL になるまで続きます)。ただし、そのリストが循環リストの場合には、処理が無限ループに入ります。この無限ループを中断するには、tnf_type から next フィールドを削除するか、または next メンバーの型を tnf_opaque として定義します。

パフォーマンスについて

頻繁に使用される mutex ロックのような、頻繁に通過するコード内のセクションには、プローブポイントを配置しないでください。

SPARCStation10 の場合、各プローブが使用するワーキングセットメモリーは約 30 ワード (データが 10 ワード、テキストが 20 ワード)、無効な各プローブで費やされる時間は約 200 ns (ナノ秒) です。アプリケーションのパフォーマンスは、配置するプローブの数を調整することによって改善できます。

プローブポイントを配置したライブラリを出荷する場合は、ベンチマークを実行して、パフォーマンスが著しく低下していないことを確認してください。パフォーマンスを改善するにはプローブの数を減らすか、プローブの配置を変更してください。

/proc

dbx、truss、および prex は、/proc を使用してターゲットプロセスを制御します。/proc では、1 つのクライアントだけが安全にターゲットプロセスを制御できます。このため、dbx や prex のようなユーティリティを同じターゲットプログラム上で同時に実行することはできません。dbx または truss が実行されているターゲットプログラム上で prex を実行しようとすると、prex は「cannot attach to target (ターゲットに接続できません)」というメッセージを表示します。

ただし、以下の手順によって prex と dbx を交互に実行できます。

1. prex を起動します。

2. プローブポイントの状態を設定します。

3. quit suspend コマンドを実行します。

4. dbx を起動します。

5. 中断されているプログラムに接続します。

   ターゲットは、prex と dbx 以外のコードは実行しません。

   ターゲットに SIGSTOP シグナルを送ってそのターゲットを一時停止させてから、"quit resume" を prex に入力することもできます。これを行なった場合には、停止されたプロセス上で dbx を呼び出してから、SIGCONT シグナルを送る必要があります (そうしない場合、dbx がハングします)。

dlopen()、dlclose()、履歴

dlopen(3X) によって取り込まれた共有オブジェクト内のプローブは、prex のコマンド履歴に従って自動的に設定されます。dlclose(3X) によって共有オブジェクトが削除されると、prex はターゲットプログラム内のプローブの情報をリフレッシュします。これは、dlopen と dlclose に必要な作業がほかにもあるということを意味しています。したがって、dlopen と dlclose の所要時間は多少長くなります。

この機能を必要とせず、また dlopen と dlclose の処理に影響を与えたくない場合は、ターゲットから prex を分離してください。

シグナル

prex は、ターゲットプログラムに直接送られるシグナルを妨げません。ただし、prex は Control-c (SIGINT) や Control-z (SIGSTOP) などの端末から生成されたシグナルをすべて受信しますが、それをターゲットプログラムには転送しません。

ターゲットプログラムにシグナルを送るには、シェルから kill(1) コマンドを実行してください。

イベント書き込み操作の障害

トレースファイルにイベントを書き込む際には、システムコール障害などの障害がいくつか発生する可能性があります。これらの障害が発生すると、ターゲットプロセス内で障害コードが設定されます。ターゲットプロセスは正常に実行を継続しますが、トレース記録は書き込まれません。

Control-c を prex に入力して prex プロンプトを表示させると、prex はターゲット内の障害コードを検査して、トレース障害が発生したかどうかを通知します。

ターゲットによる fork() または exec() の実行

プログラムが fork() を実行した場合には、子プロセスが検出したプローブはすべて同じトレースファイルに記録されます。イベントにはプロセス ID 付きで記録されるので、そのイベントがどのプロセスから発生したのかを判定できます。

マルチスレッドのプログラムで、あるスレッドが fork を行なったときに他のスレッドが実行されていると、競合状態が発生することがあります。トレースファイルが破損しないようにするには、fork を実行するときに他のスレッドが停止しているようにするか、または fork1(2) を使用してください。

ターゲットプログラム自身 (ターゲットプログラムがフォークした子プロセスではない) が exec(2) を実行した場合には、prex がターゲットから分離して終了します。ユーザーは、以下のコマンドを使用して、prex を再接続することができます。

$ prex -p pid