ヘッダーをスキップ
Oracle TimesTen In-Memory Databaseトラブルシューティング・プロシージャ・ガイド
リリース7.0
E05173-01
  目次へ
目次
索引へ
索引

前へ
前へ
次へ
次へ
 

ttTraceMonユーティリティの使用

ttTraceMonユーティリティを使用すると、多数のTimesTenコンポーネントについて様々なトレース情報を記録できます。各TimesTenコンポーネントは、様々な詳細レベルでトレースできます。ttTraceMonをshowサブコマンド付きで指定すると、トレース可能なすべてのTimesTenコンポーネントとそれらの現在のトレース・レベルを表示できます(レベル0はOFFを意味します)。ttTraceMonのオプションの完全なリストについては、『Oracle TimesTen In-Memory Database APIリファレンス・ガイド』を参照してください。

例1.8

この例は、demoデータ・ストアに対するほぼすべてのトレース・コンポーネントがレベル0(OFF)に設定されていることを示しています。(ERRトレースのデフォルトはレベル1です。)

% ttTraceMon demo

LATCH        ... 0

LOCK         ... 0

LOG          ... 0

TRACE        ... 0

API          ... 0

HEAP         ... 0

SM           ... 0

OP           ... 0

EE           ... 0

CG           ... 0

SQL          ... 0

TEST         ... 0

FLOW         ... 0

PT           ... 0

ERR          ... 1

REPL         ... 0

OPT          ... 0

CKPT         ... 0

XA           ... 0

ORACON       ... 0

ほとんどのTimesTenコンポーネントの出力は、テクニカル・サポートでのみ使用されます。ただし、SQL、API、LOCKおよびERRコンポーネントの出力は、アプリケーションの問題のトラブルシューティングで役立つ場合があります。


注意: TimesTenのトレース処理は、アプリケーションのパフォーマンスに大きく影響し、大量のディスク領域を消費します。ttTraceMonユーティリティは、問題を診断するときにのみ使用してください。診断が終了したら、トレースを前述のデフォルト値にリセットしてください。

トレースの開始とトレース・バッファの参照

新しいトレースは、ttTraceMon DSN=datastoreを指定して開始できます。たとえば、demoデータ・ストアに対してトレースを開始するには、次のように入力します。

%  ttTraceMon demo

Trace monitor; empty line to exit

Trace >

Traceプロンプトで、トレース・タイプとそのレベルを指定できます。たとえば、レベル3でSQLコンポーネントのトレースを開始するには、次のように入力します。

Trace > level sql 3

この時点で、アプリケーションを実行でき、TimesTenのトレース情報がトレース・バッファに出力されます。トレース・バッファの内容を読み取るには、次の2つの方法があります。

トレース・バッファから出力される各行の書式は次のとおりです。

timestamp    sequence    component    level    connection    operation

ここで、

たとえば、レベル3のSQLトレース後のトレース・バッファの行は、次のようになります。

16:32:06.328    5281 SQL   2L  3C select cust_num, region, name, address from xyz.customer


注意: トレースを有効(ON)にすると、データベースは非常に遅くなります。あるコンポーネントのトレースが終了したら、トレースをOFF(level component 0)にする必要があります。

この後の項では、次の各タイプのトレースの実行方法を説明します。

SQLトレース

ttTraceMonをSQLコンポーネントで使用すると、TimesTenエンジンによって準備または実行されているSQLに関する情報が提供されます。次に、SQLトレースの出力レベルを、冗長度が最も低いレベルから順に示します。

SQLトレース・レベル
出力
2
準備されているSQLコマンド。
3
+ 実行されているSQLコマンド。
4
+ コマンドをプールする効果(準備されたコマンドはすでにプールに存在するため、準備は行われない)、再準備の必要性(索引が作成されたためなど)、および破棄されるコマンド。
このレベルでは、ttTraceMonによって問合せコマンドのオープン、フェッチおよびクローズのタイミングも示されます。
5
+ コマンド番号などの内部データ(通常、ユーザー・レベルでのデバッグには役立ちません)。


注意: SQLのトレースは、レベル3または4で実行することをお薦めします。SQLトレースでは、オプティマイザに関する情報は表示されません。オプティマイザのトレースは、レベル4で別のコンポーネント(OPT)によって管理され、ユーザーが使用するようには設計されていません。

例1.9

この例では、demoデータ・ストアに対してSQLトレースをレベル4で実行するためにttTraceMonを実行します。SQLトレースの出力は、SQLtrace.txtファイルに書き込みます。

%  ttTraceMon demo

Trace monitor; empty line to exit

Trace > outfile SQLtrace.txt

Trace > level sql 4

ここでアプリケーションを実行します。トレース情報はSQLtrace.txtファイルに出力されます。アプリケーションが完了したら、SQLトレースを無効にし、ttTraceMonを終了します。

Trace > level sql 0

Trace > {press ENTER - blank line}

SQLtrace.txtの内容は、次のとおりです。

16:32:06.317    5269 SQL   2L  3C Preparing:

16:32:06.317    5270 SQL   2L  3C insert into xyz.customer values (?,?,?,?)

16:32:06.317    5271 SQL   4L  3C sbSqlCmdCompile(E): cmdType:100, cmdNum:1001130.

16:32:06.328    5272 SQL   3L  3C Executing: insert into xyz.customer values (?,?,?,?);

16:32:06.328    5273 SQL   3L  3C Executing: insert into xyz.customer values (?,?,?,?);

16:32:06.328    5274 SQL   3L  3C Executing: insert into xyz.customer values (?,?,?,?);

16:32:06.328    5275 SQL   3L  3C Executing: insert into xyz.customer values (?,?,?,?);

16:32:06.328    5276 SQL   2L  3C Preparing:

16:32:06.328    5277 SQL   2L  3C {CALL ttOptUpdateStats('xyz.customer',1)}

16:32:06.328    5278 SQL   4L  3C sbSqlCmdCompile(E): (Found already compiled version: refCount:01, bucket:05) cmdType:100, cmdNum:1000932.

16:32:06.328    5279 SQL   3L  3C Executing: {CALL ttOptUpdateStats('xyz.customer',1)};

16:32:06.328    5280 SQL   2L  3C Preparing:

16:32:06.328    5281 SQL   2L  3C select cust_num, region, name, address from xyz.customer

16:32:06.328    5282 SQL   4L  3C sbSqlCmdCompile(E): cmdType:100, cmdNum:1001131.

16:32:06.328    5283 SQL   4L  3C Opening: select cust_num, region, name, address from xyz.customer;

16:32:06.328    5284 SQL   4L  3C Fetching: select cust_num, region, name, address from xyz.customer;

....

16:32:06.328    5292 SQL   4L  3C Fetching: select cust_num, region, name, address from xyz.customer;

16:32:06.328    5293 SQL   4L  3C Closing: select cust_num, region, name, address from xyz.customer;

APIトレース

トランザクションのコミットなど、SQLを使用せずに実行するコマンドも多数あるため、APIトレースの生成が役立つ場合もあります。次に、APIトレースの出力レベルを、冗長度が最も低いものから順に示します。

APIトレース・レベル
出力
1
サブデーモンが実行したロールバックのすべての試行。アプリケーションが異常終了し、サブデーモンがその接続をリカバリする場合に実行されます。
2
+ ある程度の領域不足の状態。
3
+ データ・ストアに対する作成、接続、切断、チェックポイント、バックアップおよび圧縮の各操作と、各接続のコミットおよびロールバック、その他のいくつかの操作。
4
+ TimesTenの内部APIレベルで処理されるその他のほぼすべての操作。ストレージ・マネージャおよび索引に対して実行され、APIの内部で実行される多数の操作は表示されません。


注意: レベル3でのトレースをお薦めします。

例1.10

この例では、demoデータ・ストアに対してAPIトレースをレベル3で実行するためにttTraceMonを実行します。APIトレースの出力は、APItrace.txtファイルに送信されます。

% ttTraceMon demo

Trace monitor; empty line to exit

Trace> outfile APItrace.txt

Trace> level api 3

ここでアプリケーションを実行します。トレース情報はAPItrace.txtファイルに出力されます。アプリケーションが完了したら、APIトレースを無効にし、ttTraceMonを終了します。

Trace > level api 0

Trace > {press ENTER - blank line}

通常のアプリケーションの実行では、APItrace.txtの内容は次のようになります。APIトレースの各行の書式は、例1.9に示したSQLの書式に類似しています。

15:56:50.165    5031 API      3L    3C sb_dbConnect()(X)

15:56:50.165    5032 API      3L    3C sb_dbConnSetIsoLevel()(E)

15:56:50.175    5033 API      3L    3C sb_xactCommitQ()(E)

15:56:50.175    5034 API      3L    3C sb_xactCommitQ()(E)

15:56:50.175    5035 API      3L    3C sb_xactCommitQ()(E)

15:56:50.175    5036 API      3L    3C sb_xactCommitQ()(E)

15:56:50.175    5037 API      3L    3C sb_xactCommitQ()(E)

15:56:50.175    5038 API      3L    3C sb_xactCommitQ()(E)

15:56:50.175    5039 API      3L    3C sb_xactCommitQ()(E)

15:56:50.175    5040 API      3L    3C sb_dbDisconnect()(E)

LOCKトレース

LOCKコンポーネントを使用すると、アプリケーションのロック動作をトレースして、デッドロックまたはロックの待機による問題を検出できます。LOCKトレースは大量の情報を生成するので、適切なトレース・レベルを選択することが重要です。たとえば、レベル3では、ごく一般的なイベントについてもトレースが作成されるため、大量のトレースが発生します。さらに、トレース自体が読みにくくなることもあります。必要な情報が見つからない場合は、テクニカル・サポートに連絡してください。

LOCKトレース・レベル
出力
1
検出されたデッドロック・サイクル。
2
+ なんらかの理由によるロック付与の失敗。
3
+ ロックの待機(付与の有無に依存しない)。
4
+ すべてのロックの付与/解除、ルーチンのコール、デッドロック検出のメカニズム。
6

+ サイクルにおける各ステップ。

例1.11

この例では、demoデータ・ストアに対してLOCKトレースをレベル4で実行するためにttTraceMonを実行し、トレース・バッファから直接結果を参照します。LOCKトレースをバッファに保存する前に、flushコマンドを使用してバッファを空にします。

% ttTraceMon demo

Trace monitor; empty line to exit

Trace> level lock 4

Trace> flush

ここでアプリケーションを実行します。トレース情報はトレース・バッファに出力されます。トレース・バッファの内容は、dumpコマンドを使用すると画面に表示されます。

Trace> dump

16:16:42.336 13593 LOCK 4L 3C ENQ: xcb:00003 <DB 0x1312d00,0x0> 0+IX=>

GR activity 0 IX cnt=1

16:16:42.336 13594 LOCK 4L 3C ENQ: xcb:00003 <Cmd 0x155a718,0x0> 0+S=>G

R activity 0 S cnt=1

16:16:42.336 13595 LOCK 4L 3C ENQ: xcb:00003 <Tbl 0x5ff68,0x0> 0+IRC=>G

R activity 0 IRC cnt=1

16:16:42.336 13596 LOCK 4L 3C DEQ: xcb:00003 <Tbl 0x5ff68,0x0> All:N, m

ode=IRC, cnt=1

16:16:42.346 13597 LOCK 4L 3C DEQ: xcb:00003 <Cmd 0x155a718,0x0> All:N,

mode=S, cnt=1

16:16:42.346 13598 LOCK 4L 3C ENQ: xcb:00003 <Cmd 0x1565964,0x0> 0+S=>G

R activity 0 S cnt=1

16:16:42.346 13599 LOCK 4L 3C ENQ: xcb:00003 <Tbl 0x5ff68,0x0> 0+IRC=>G

R activity 0 IRC cnt=1

16:16:42.346 13600 LOCK 4L 3C DEQ: xcb:00003 <Tbl 0x5ff68,0x0> All:N, m

ode=IRC, cnt=1

16:16:42.346 13601 LOCK 4L 3C DEQ: xcb:00003 <Cmd 0x1565964,0x0> All:N,

mode=S, cnt=1

16:16:42.346 13602 LOCK 4L 3C ENQ: xcb:00003 <Cmd 0x156a92c,0x0> 0+S=>G

R activity 0 S cnt=1

16:16:42.346 13603 LOCK 4L 3C ENQ: xcb:00003 <Tbl 0x5ff68,0x0> 0+IRC=>G

R activity 0 IRC cnt=1

16:16:42.346 13604 LOCK 4L 3C DEQ: xcb:00003 <Tbl 0x5ff68,0x0> All:N, m

ode=IRC, cnt=1

16:16:42.346 13605 LOCK 4L 3C DEQ: xcb:00003 <Cmd 0x156a92c,0x0> All:N,

mode=S, cnt=1

16:16:42.346 13606 LOCK 4L 3C DEQ: xcb:00003 <DB 0x1312d00,0x0> All:Y,

mode=IX, cnt=1

16:16:42.346 13607 LOCK 4L 3C ENQ: xcb:00003 <DB 0x1312d00,0x0> 0+IX=>

GR activity 0 IX cnt=1

16:16:42.346 13608 LOCK 4L 3C DEQ: xcb:00003 <DB 0x1312d00,0x0> All:Y,

mode=IX, cnt=1

16 records dumped

トレースが終了したら、LOCKトレースをデフォルトの設定(0)に戻し、ttTraceMonを終了します。

Trace > level lock 1

Trace > {press ENTER - blank line}

ERRトレース

ERRコンポーネントのトレースが役立つ場合もあります。たとえば、レベル4のERRトレースでは、TimesTenダイレクト・ドライバにプッシュされるすべてのエラー・メッセージが表示されます(内部的に処理されるため、すべてのエラーがユーザーに出力されるわけではありません)。デフォルトは、レベル1のERRトレースです。レベル2および3のERRトレースでは、出力は作成されません。

ERRトレース・レベル
出力
1(デフォルトの設定)
致命的エラー。
4
+ 他のすべてのエラー・メッセージ。ほとんどがTimesTenで内部的に処理されます。

例1.12

この例では、demoデータ・ストアに対してERRトレースをレベル4で実行するためにttTraceMonを実行します。前述の例とは異なり、この例ではトレースをファイルに出力するのではなく、トレース・バッファからその内容を直接参照します。ERRトレースをバッファに保存する前に、flushコマンドを使用してバッファを空にします。

% ttTraceMon demo

Trace monitor; empty line to exit

Trace> level err 4

Trace> flush

ここでアプリケーションを実行します。トレース情報はトレース・バッファに出力されます。トレース・バッファの内容は、dumpコマンドを使用すると画面に表示されます。

Trace> dump

10:02:30.146    5553 ERR      4L    3C TT3204: Sequence PRODUCTID is not found -

- file "saCanon.c", lineno 4373, procedure "ppDrSequence"

10:02:30.146    5554 ERR      4L    3C TT3204: Sequence ORDERID is not found --

file "saCanon.c", lineno 4373, procedure "ppDrSequence"

10:02:30.146    5555 ERR      4L    3C TT3204: Sequence CUSTID is not found -- f

ile "saCanon.c", lineno 4373, procedure "ppDrSequence"

10:02:30.146    5556 ERR      4L    3C TT3120: View ORDER_SUMMARY does not exist

-- file "eeDDL.c", lineno 3150, procedure "sbEeDrViewEval"

10:02:30.146    5557 ERR      4L    3C TT3204: Sequence ORDERID is not found --

file "saCanon.c", lineno 4373, procedure "ppDrSequence"

10:02:30.156    5558 ERR      4L    3C TT3204: Sequence PRODUCTID is not found -

- file "saCanon.c", lineno 4373, procedure "ppDrSequence"

10:02:30.156    5559 ERR      4L    3C TT3204: Sequence CUSTID is not found -- f

ile "saCanon.c", lineno 4373, procedure "ppDrSequence"

7 records dumped

ERRトレースをデフォルトの設定(1)に戻し、ttTraceMonを終了します。

Trace > level err 1

Trace > {press ENTER - blank line}

エージングの監視

ttTraceMonユーティリティは、次のことを確認する場合に使用できます。

次のような構文を使用します。

ttTraceMon(-e level aging n [outfile file]

     {-connStr connection_string | DSN});

nは、トレース・レベルを表します。nは、次の表のように設定します。

レベル
説明

1

エージング・スレッドがウェイクアップするタイミングを表示し、エージングの候補となる表を少なくとも1つ検索します。

2

  • エージング・スレッドが表に作用し始めるタイミングを表示します。
  • エージング・スレッドがその表に対する作用を完了したときに、表内で削除された行および残っている行の概要を表示します。

3

削除された行と残っている行など、各表についてのエージングの詳細を表示します。

4

エージング・スレッドがウェイクアップするタイミングを表示します。

トレース・レベルを高くすると、それより低いトレース・レベルのすべての情報が表示されます。

例1.13

% ttTraceMon -e level aging 4 myDSN

このコマンドを実行すると、次のような出力が表示されます。

13:33:49.390  322 AGING   4L 2044C    9183P sb_dbAging(E): curTime=156

13:33:50.400  323 AGING   4L 2044C    9183P sb_dbAging(E): curTime=156

13:33:51.410  324 AGING   4L 2044C    9183P sb_dbAging(E): curTime=156

13:33:52.420  325 AGING   4L 2044C    9183P sb_dbAging(E): curTime=156

13:33:52.420  326 AGING   1L 2044C    9183P Entering sbAgingTB(): curTime=157

13:33:52.420  27 AGING   2L 2044C    9183P Entering sbAgingOneTable(): curTime=1 57, ltblid= 638128

13:33:52.420  328 AGING   3L 2044C    9183P curTime=157, numDeleted=0, rows = 2796, tbl = PARENT1

13:33:52.461  329 AGING   3L 2044C    9183P curTime=157, numDeleted=100, rows = 2696, tbl = PARENT1

13:33:53.101  330 AGING   3L 2044C    9183P curTime=157, numDeleted=200, rows = 2597, tbl = PARENT1

13:33:53.161  331 AGING   3L 2044C    9183P curTime=157, numDeleted=300, rows = 2497, tbl = PARENT1

13:33:53.231  332 AGING   3L 2044C    9183P curTime=157, numDeleted=400, rows = 2397, tbl = PARENT1

13:33:53.280  333 AGING   3L 2044C    9183P curTime=157, numDeleted=500, rows = 2297, tbl = PARENT1

13:33:53.340  334 AGING   3L 2044C    9183P curTime=157, numDeleted=600, rows = 2197, tbl = PARENT1

13:33:53.380  335 AGING   3L 2044C    9183P curTime=157, numDeleted=700, rows = 2097, tbl = PARENT1

13:33:53.430  336 AGING   3L 2044C    9183P curTime=157, numDeleted=800, rows = 1998, tbl = PARENT1

13:33:53.481  337 AGING   3L 2044C    9183P curTime=157, numDeleted=900, rows = 1898, tbl = PARENT1

詳細は、『Oracle TimesTen In-Memory Databaseオペレーション・ガイド』の表へのエージングの実装に関する説明を参照してください。