付録L.3 性能検証用トレース情報の解析例
(1) 性能検証用トレースの編集コマンド
性能検証用トレースを編集するにはprfedコマンド，またはdcalzprfコマンドを使用します。それぞれのコマンドの利用方法，出力内容については，「13. 運用コマンドの詳細」の「prfed」または「dcalzprf」を参照してください。
性能検証用トレースを編集する際，コマンドにトレース情報を絞り込むための引数を渡せます。性能検証用トレースは，トレース情報を絞り込まないで編集すると，多大な情報が出力され，コマンド処理に時間が掛かる場合があります。そのため，解析作業をスムーズに行えるよう，あらかじめわかっている情報から，トレース情報を極力絞り込むことをお勧めします。特に，トレースが取得された時間帯やプロセスIDで絞り込めると，編集出力される情報量を抑えることができます。
prfedコマンドは，時刻を軸とした一次元での編集結果を出力します。一方，dcalzprfコマンドは出力形式がcsvとなっており，時刻とプロセスを軸とした二次元での編集結果を出力します。また，prfedコマンドに比べてトレース情報の選択オプションが豊富であり，効率の良い絞り込みができます。これらの特長によって，prfedコマンドに比べて，dcalzprfコマンドは容易に性能検証用トレースを解析できます。
(2) トレース情報の見方
性能検証用トレースを編集出力すると，さまざまな情報が表示されます。各項目の意味を次の表に示します。
|
項目 |
説明 |
|---|---|
|
ノードID |
トレース情報を取得したプロセスが所属していたOpenTP1システムのノードIDです。複数ノードの性能検証用トレースをまとめて編集した際に，どのノードに所属していたプロセスかを判別するために使用します。 |
|
ランID |
トレース情報を取得したプロセスが所属していたOpenTP1システムのランIDです。複数回のオンラインの性能検証用トレースをまとめて編集した際に，いつのオンラインの時に取得されたトレース情報なのかを判別するために使用します。 |
|
トレース通番 |
トレース情報を取得したプロセスが取得していた性能検証用トレース情報の通番です。1〜65535まで1ずつ，トレース情報を取得するたびに増加します。65535の次は1に戻ります。 同一プロセスのトレースについて，連続性を確認するために使用します。 |
|
イベントID |
各トレース情報の識別子です。トレースの取得個所ごとに決められており，どこの処理で取得されたトレース情報なのかを判別するために使用します。 |
|
サーバ名 |
トレース情報を取得したプロセスのサーバ名です。 |
|
リターンコード |
OpenTP1提供関数のリターンコードです。処理の成功・失敗などを判別するために使用します。 |
|
クライアントOpenTP1識別子 |
ノード間の通信でのクライアント側のOpenTP1識別子（ノードID）です。 |
|
クライアント通信番号 |
他ノードや他プロセスに通信するときに，OpenTP1システム が付加する番号です。同一のOpenTP1システムで一意になります。 クライアントOpenTP1識別子とクライアント通信番号をセットにして検索することで，通信の流れを追跡できます。 |
|
サーバOpenTP1識別子 |
ノード間の通信でのサーバ側のOpenTP1識別子（ノードID）です。 |
|
ルートOpenTP1識別子 |
通信が複数のノードにまたがっている場合，その通信のルートとなるノードのOpenTP1識別子（ノードID）です。 ノードを何度またがっても，同じ識別子が使用されます。 |
|
ルート通信番号 |
他ノードや，他プロセスに通信するときにOpenTP1システム が付加する番号です。同一のOpenTP1システムで一意になります。 ノードを何度またがっても，同じ識別子が使用されます。 ルートOpenTP1識別子とルート通信番号をセットにして検索することで，一連の通信の流れを追跡できます。 |
|
サービスグループ名 |
RPC要求先のサービスグループ名です。 |
|
サービス名 |
RPC要求先のサービス名です。 |
|
グローバルトランザクションID |
グローバルトランザクションを識別するためのIDです。グローバルトランザクションIDをキーに検索することで，一連のトランザクションの流れを追跡できます。 |
|
イベント種別 |
トランザクションサービスが取得しているトレース情報に付加されている情報です。XA関数の出入り口情報や，トランザクションサービスに関係するイベント情報が出力されます。 出力されているイベントによって処理の進行状況がわかり，ボトルネックの調査などに利用できます。 |
(3) 性能検証用トレースの利用例
性能検証用トレースには，ノード間の通信の際にクライアント・サーバ同士を関連づけるためのキーとして，クライアント通信番号やルート通信番号などが含まれています。ノードをまたがってOpenTP1の処理を追いかける場合，このキーを基に，クライアント・サーバそれぞれで取得したトレースを関連づけることができます。
クライアント・サーバそれぞれのノードで取得されるトレースの内容について次に示します。
![[図データ]](GRAPHICS/ZU0F0300.GIF)
![[図データ]](GRAPHICS/ZU0F0301.GIF)
なお，OpenTP1識別子と通信番号はセットで比較してください。OpenTP1識別子だけの場合，ノードは特定できますが，どの通信なのかを特定するのは困難です。また，通信番号だけの場合は，ノードの特定が困難です。
(4) dcalzprfコマンドでの性能検証用トレース解析
dcalzprfコマンドには，性能検証用トレースを編集・解析するためのさまざまな機能があります。
dcalzprfコマンドで出力されたCSVファイルは，表計算ソフトを使用して参照・編集すると，時間とプロセスを軸とした二次元的な情報表示ができます。これによって，トレースデータの流れがわかりやすくなります。また，表計算ソフトのフィルタリング機能を使用すれば，dcalzprfコマンドで絞り込めなかったデータを直接，絞り込めます。
ここでは，dcalzprfコマンドでのトレース解析方法を紹介します。
(a) イベント間の時刻差算出（-Cオプション，および-Fオプション）
dcalzprfコマンドでは，出力される各イベントとイベントの間の時刻差を，編集出力時に算出できます。時刻差の算出には，-Cオプションおよび-Fオプションを使用します。-Cオプションに時刻差を計算する始点となるイベントIDを指定し，-Fオプションに終点となるイベントIDを指定します。
例えば，「-C 0x4005 -F 0x4006」と指定して編集出力をすると，始点を0x4005（コミット電文の受信イベント）から0x4006（コミット完了電文の送信イベント）までの時刻差，つまりコミット処理に掛かった時間を算出できます。そのほか，「-C 0x4100 -F 0x4150」と指定すると，トランザクション開始から終了までの時間を，「-C 0x1000 -F 0x1004」と指定すると，RPCでサービスの呼び出しに掛かった時間をそれぞれ算出できます。
ただし，時刻差を算出できるのは，同一プロセス上のイベント同士だけです。別プロセス上のレコードに出力されるイベント同士は，-Cオプションおよび-Fオプションでは時刻差を算出できません。
|
|
![[図データ]](GRAPHICS/ZU0F0400.GIF)
一部のprfトレースの情報に抜けが発生した場合，抜けたトレースのイベントIDを-Cオプションまたは-Fオプションに指定しても，時刻差を算出できません。
|
|
![[図データ]](GRAPHICS/ZU0F0500.GIF)
-Cオプションおよび-Fオプションの両方で指定したイベントIDのトレースに連続で抜けが発生した場合，本来よりも長い時刻差で算出されることがあります。
|
|
![[図データ]](GRAPHICS/ZU0F0600.GIF)
また，始点と終点を-Cオプションおよび-Fオプションにそれぞれ複数指定すれば，複数種類のイベントIDの時刻差を取得できます。しかし，トレースが「始点-始点-終点-終点」の順序になっている場合は，仮にトレースに抜けがないときでも，意図したイベントの時刻差とは異なる時刻差が算出されることがあります。この場合，-Cオプションおよび-Fオプションを一つずつ指定すると，正しい時刻差が算出されます。
|
|
![[図データ]](GRAPHICS/ZU0F0700.GIF)
(b) 別プロセス同士のイベント時刻差算出（-dオプション）
別プロセス同士のイベント時刻差を算出する場合は，-dオプションを使うと便利です。-dオプションは，指定された起点時刻から各レコードまでの時刻差を編集出力時に表示します。起点時刻との時刻差はマイクロ秒で表示されており，レコード同士の時刻を引き算することで，レコード間の時刻を容易に算出できます。
(c) -Cオプション，-Fオプション，および-dオプションで算出した時刻差の表示について
CSVファイルの参照・編集に表計算ソフトを使用している環境で，-Cオプションおよび-Fオプションで算出される時刻差や，-dオプションで算出される時刻差が大きい値の場合，指数表記で表示されるときがあります。また，けた落ちが発生することもあります。そのため，時刻差が大きくなり過ぎないよう，トレース情報を絞り込むことをお勧めします。-Cオプションおよび-FオプションにイベントIDを指定，また，-dオプションに起点時刻を指定して，トレース情報を絞り込むことで，時刻差の値を小さくできます。