トレースの例
デフォルトでは、すべてのコンポーネントでトレースが無効になっています。したがって、ランタイム システムのトレースを有効化にするためには、少なくとも構成ファイルの中でmftrace.levelまたはmftrace.level.mf.rtsエントリを指定する必要があります。たとえば、MFTRACE_CONFIG環境変数を次のように設定し、
export MFTRACE_CONFIG=/home/mydir/ctf.cfg
さらに/home/mydir/ctf.cfgに次のエントリのみが入っている場合、
mftrace.level=error
ランタイム システム エラーを生成したプロセスによって、イベントID 255に対応するエントリを含むトレース ファイルが作成されます。このイベントをエミットするためにmf.rtsコンポーネントに対して何らかのプロパティを指定する必要はまったくありません。トレース レベルを「エラー」に設定するだけで十分です。
次の例では、アプリケーションmymainを使用しています。このアプリケーションは、以下に示すコードを含むmymain.cblとmysub.cblという2つのプログラムで構成されています。
mymain.cbl:
identification division.
program-id. mymain.
environment division.
data division.
working-storage section.
01 my-var pic 9(9) external.
procedure division.
move 1 to my-var
perform 5 times
call 'mysub'
add 1 to my-var
end-perform
cancel 'mysub'
call 'myprog'
goback.mysub.cbl:
identification division.
program-id. mysub.
environment division.
data division.
working-storage section.
01 my-var pic 9(9) external.
procedure division.
display my-var
goback.
mymainを実行すると、myprogが呼び出されるため、ランタイム システム エラー173（「呼び出されたプログラム ファイルがドライブ／ディレクトリ内にない」）が発生します。上の構成を使用して生成されるトレース ファイルは、次のようになります。
1> # -MFTRACE Text Emitter- 2> # CommandLine = mymain 3> # ProcessId = 2404 4> # Date = 2004/12/14 5> # Time = 11:54:42.875 6> # Operating System = Windows XP Service Pack 1 (Build 2600) 7> # Computer Name = PC-NAME 8> # Format = $(TIME) $(COMPONENT) $(EVENT) $(LEVEL)$(DATA) 9> 11:54:42.875 MF.RTS 255 3 173 1 "myprog"
1>から8>というマークが付いたエントリは、TEXTFILEエミッターによって出力されるヘッダー レコードで、トレース中のアプリケーションに関する情報を提供します。8>は、以下のトレース エントリのフォーマット（この例では、デフォルトのトレース エントリ フォーマットを使用）を表しています。したがって、9>のフィールドは次のように解釈できます。
| トレース ファイル内の情報 | 擬似変数 | 説明 | ||||||||||
|---|---|---|---|---|---|---|---|---|---|---|---|---|
| 11:54:42.875 | $(TIME) | トレース エントリが出力された時刻。 | ||||||||||
| MF.RTS | $(COMPONENT) | トレースエントリを出力したコンポーネントの名前。MF.RTSは、ランタイム システムを示します。 | ||||||||||
| 255 | $(EVENT) | イベント識別子。mf.rtsコンポーネントのイベント識別子255は、ランタイム システム エラーを示します。 | ||||||||||
| 3 | $(LEVEL) | エラーのレベル。以下の値をとります。
|
||||||||||
| 173 1 "myprog" | $(DATA) | イベント固有のデータ。 |
次のようにして構成ファイルで文を変更してINFOのトレースレベルを指定した後に、mymainを再実行すると、
mftrace.level=info
作成されるトレース ファイルには、ランタイム システムのエラー イベントに加え、ランタイム システムの初期化および初期化解除イベントに関するエントリが含まれています。トレース ファイルは次のようになります。
# -MFTRACE Text Emitter-
# CommandLine = mymain
# ProcessId = 2820
# Date = 2004/12/14
# Time = 12:27:04.317
# Operating System = Windows XP Service Pack 1 (Build 2600)
# Computer Name = PC-NAME
# Format = $(TIME) $(COMPONENT) $(EVENT) $(LEVEL)$(DATA)
12:27:04.317 MF.RTS 128 1
12:27:04.327 MF.RTS 129 1
12:27:04.337 MF.RTS 255 3 173 1 "myprog"
12:27:04.367 MF.RTS 130 1
12:27:04.367 MF.RTS 131 1
ランタイム システム エラーが起こる前にアプリケーションがどのプログラムを呼び出したかを調べるには、PGMプロパティを設定する必要があります。プログラムのロード元は何か、そしていつキャンセルされたかを知りたい場合、次のようにPGMLOADプロパティも設定する必要があります。
mftrace.level=info mftrace.comp.mf.rts#pgm=true mftrace.comp.mf.rts#pgmload=true
mymainを再実行すると、生成されるトレース ファイルには、プログラムのロード、入口、出口、キャンセル イベントに関する追加エントリが含まれます。トレース ファイルは、次のようになります。
# -MFTRACE Text Emitter-
# CommandLine = mymain
# ProcessId = 4092
# Date = 2004/12/14
# Time = 13:44:30.868
# Operating System = Windows XP Service Pack 1 (Build 2600)
# Computer Name = PC-NAME
# Format = $(TIME) $(COMPONENT) $(EVENT) $(LEVEL)$(DATA)
13:44:30.868 MF.RTS 128 1
13:44:30.888 MF.RTS 129 1
13:44:30.888 MF.RTS 19 1 0 0 "mymain" "" ""
13:44:30.888 MF.RTS 6 1 17 0 "mymain"
13:44:31.008 MF.RTS 19 1 0 0 "mysub" "gnt" "E:\myprogs"
13:44:31.008 MF.RTS 6 1 1 0 "MYSUB"
13:44:31.008 MF.RTS 7 1
13:44:31.008 MF.RTS 6 1 1 0 "MYSUB"
13:44:31.008 MF.RTS 7 1
13:44:31.008 MF.RTS 6 1 1 0 "MYSUB"
13:44:31.008 MF.RTS 7 1
13:44:31.008 MF.RTS 6 1 1 0 "MYSUB"
13:44:31.008 MF.RTS 7 1
13:44:31.008 MF.RTS 6 1 1 0 "MYSUB"
13:44:31.008 MF.RTS 7 1
13:44:31.008 MF.RTS 20 1 0 0 "mysub"
1> 13:44:31.008 MF.RTS 6 1 1 0 "MYSUB"
13:44:31.008 MF.RTS 7 1
13:44:31.139 MF.RTS 255 3 173 1 "myprog"
13:44:31.199 MF.RTS 130 1
13:44:31.199 MF.RTS 20 1 0 0 "mymain"
2> 13:44:31.199 MF.RTS 6 1 17 0 "mymain"
13:44:31.199 MF.RTS 7 1
13:44:31.199 MF.RTS 131 1
1>および2>というマークが付いたエントリは、当該プログラムのイベント タイプ20エントリ（論理キャンセル）の直後に、同じプログラムにイベント タイプ6および7のエントリ（プログラムの入口と出口）があることを示します。これは、プログラムによって開かれたファイルを閉じるために、コンパイラがすべてのプログラムにキャンセル ルーチンを埋め込んでいるためです。これらのキャンセル ルーチンは、論理キャンセル動作の一部として、ランタイム システムによって暗示的に呼び出されます。
メモリ管理を除く、すべてのランタイム システム イベントのトレースをイネーブルにするには、次の構成ファイル エントリを使用します。
mftrace.level = info mftrace.comp.mf.rts#all=true mftrace.comp.mf.rts#memory=false
mymainを再実行すると、生成されるトレース ファイルには、外部データ項目に関する追加エントリが含まれます。プログラムをAMODE指示付きでコンパイルした場合、個々のMainframe Pointer Managerイベントごとのエントリも含まれます。トレースファイルは、次のようになります。
# -MFTRACE Text Emitter-
# CommandLine = mymain
# ProcessId = 2716
# Date = 2004/12/14
# Time = 14:33:22.704
# Operating System = Windows XP Service Pack 1 (Build 2600)
# Computer Name = PC-NAME
# Format = $(TIME) $(COMPONENT) $(EVENT) $(LEVEL)$(DATA)
14:33:22.704 MF.RTS 128 1
14:33:22.714 MF.RTS 129 1
14:33:22.714 MF.RTS 19 1 0 0 "mymain" "" ""
14:33:22.714 MF.RTS 6 1 17 0 "mymain"
1> 14:33:22.714 MF.RTS 26 1 "MY_VAR" 9
14:33:22.714 MF.RTS 19 1 0 0 "mysub" "gnt" "E:\myprogs"
14:33:22.724 MF.RTS 6 1 1 0 "MYSUB"
14:33:22.724 MF.RTS 7 1
14:33:22.724 MF.RTS 6 1 1 0 "MYSUB"
14:33:22.724 MF.RTS 7 1
14:33:22.724 MF.RTS 6 1 1 0 "MYSUB"
14:33:22.724 MF.RTS 7 1
14:33:22.724 MF.RTS 6 1 1 0 "MYSUB"
14:33:22.724 MF.RTS 7 1
14:33:22.724 MF.RTS 6 1 1 0 "MYSUB"
14:33:22.724 MF.RTS 7 1
14:33:22.724 MF.RTS 20 1 0 0 "mysub"
14:33:22.724 MF.RTS 6 1 1 0 "MYSUB"
14:33:22.724 MF.RTS 7 1
14:33:22.724 MF.RTS 255 3 173 1 "myprog"
14:33:22.764 MF.RTS 130 1
14:33:22.764 MF.RTS 20 1 0 0 "mymain"
14:33:22.764 MF.RTS 6 1 17 0 "mymain"
14:33:22.764 MF.RTS 7 1
2> 14:33:22.764 MF.RTS 27 1 "MY_VAR"
14:33:22.764 MF.RTS 131 1
1>および2>というマークが付いたエントリは、外部データ項目に関する追加エントリを示します。
関連項目