付録F.4 Exceptionトレースログ

Exceptionトレースログは,メソッド実行時に障害が発生した場合に障害要因を分析するためのトレース情報です。障害発生時の問題個所の切り分けをするときに有効です。メソッドの呼び出し情報,メソッドの戻り値の情報,および例外(Exception)の情報が,製品名称などが出力されたヘッダと合わせて出力されます。

Exceptionトレースログとして出力される情報を次に示します。

表F-9  Exceptionトレースログとして出力される情報

情報の種類内容
ヘッダ出力情報の通番
製品名称
メソッドの呼び出し情報ログの取得時間
スレッド識別情報
メソッドの呼び出し識別情報
クラス名,オブジェクトID,メソッド名
コネクションハンドル
セクションID(カーソルIDと同じことを表現しています)
メソッドの引数
メソッドの戻り情報ログの取得時間
スレッド識別情報
メソッドの戻り識別情報
クラス名,オブジェクトID,メソッド名
コネクションハンドル
セクションID(カーソルIDと同じことを表現しています)
メソッドの引数
Exceptionの情報ログの取得時間
スレッド識別情報
Exceptionのスタックトレース

Exceptionトレースログは,SQLException,BatchUpdateException,またはXAExceptionが発生したときに,環境変数に設定した設定情報を基に,Exceptionがthrowされる前にファイルに出力されます。Exceptionトレースを出力するメソッドと,ログ出力に関連する環境変数については,「付録E.1 Cosminexus DABroker Libraryで取得できるログの種類と出力先」を参照してください。

<この項の構成>
(1) 出力形式と出力項目
(2) 解析方法
(3) トレース取得レベルごとの出力例

(1) 出力形式と出力項目

Exceptionトレースログの出力形式を,トレース取得レベル5の場合の出力例を基に説明します。

[図データ]

[図データ]

[図データ]

出力される内容について次の表で示します。項番は出力例中の番号と対応しています。

表F-10  Exceptionトレースログの出力項目

項番区分表示意味
1ヘッダ[XXXX]出力情報の通番を示します。
2Cosminexus DABroker for Java , DABroker for Java Version 2 XX-XX-XXCosminexus DABroker Libraryのログであることを示します。
3共通XXXX/XX/XX XX:XX:XX.XXXログの取得時間を示します。
4Thread[XXXX,XXXXX,XXXX]@XXXXスレッド識別情報を示します。
5[JdbcDbpsvXXXX@XXXX.XXXX]クラス名,オブジェクトID,メソッド名を示します。
6HANDLE(XXXX)ConnectionHandleを示します。
7SID(XXX)セクションID(カーソルIDと同じことを表現しています)を示します。
8メソッドの呼び出し情報[E]メソッドの呼び出し識別情報を示します。
9XXXX=XXXXメソッドの引数を示します。
10メソッドの戻り情報[R]メソッドからの戻り識別情報を示します。
11Return=XXXXメソッドの戻り値を示します。
12Exception情報JP.co.Hitachi.soft.DBPSV_Driver.XXXXException:XXXXExceptionのスタックトレースを表示します。

(2) 解析方法

ここでは,(1)で示した出力例を使用して,Exceptionトレースログの解析方法について説明します。

Exceptionトレースログは,次の手順で解析します。

  1. 解析するログの通番から,ログ情報を抜き出します。
  2. ログ情報を,Thread識別情報で分類して,ログごとに分割します。
  3. ログの取得時間によって,ログ情報を時系列に並べます。
    手順1.~3.を実施すると,次のような表を作成できます。
    時間スレッド1スレッド2スレッド3スレッド4
    Thread[main,5,main]
    @1259414
    Thread[Thread-0,5,main]
    @30090737
    Thread[Thread-1,5,main]
    @5462872
    Thread[Thread-2,5,main]
    @25253977
    2004/07/06 23:07:09.129JdbcDbpsvConnection
    @82c01f.createStatement(1)
    2004/07/06 23:07:09.160JdbcDbpsvStatement
    @1e4cbc4.execute
    2004/07/06 23:07:14.285JdbcDbpsvConnection
    @82c01f.commit
    2004/07/06 23:07:14.301JdbcDbpsvConnection
    @82c01f.prepareStatement(1)
    2004/07/06 23:07:26.567JdbcDbpsvConnection
    @82c01f.commit
    2004/07/06 23:07:26.567JdbcDbpsvStatement
    @1e4cbc4.executeQuery
    2004/07/06 23:07:26.567JdbcDbpsvStatement
    @1e4cbc4.execute
    2004/07/06 23:07:28.332JdbcDbpsvResultSet
    @3eca90.close
    JdbcDbpsvConnection
    @82c01f.prepareStatement(1)
    2004/07/06 23:07:28.332JdbcDbpsvConnection
    @82c01f.commit
    2004/07/06 23:07:28.348JdbcDbpsvConnection
    @82c01f.prepareStatement(1)
    2004/07/06 23:07:30.332JdbcDbpsvConnection
    @82c01f.rollback
    2004/07/06 23:07:42.098JdbcDbpsvConnection
    @82c01f.close
    2004/07/06 23:07:42.535SQLException発生
    KFDJ00002-E Statement or Connection is closed.
    (凡例)
    -:該当しない

  4. Exceptionエラーの内容を確認します。
    2004/07/06 23:07:42.535のスレッド3でSQLExceptionが発生しています。メッセージの内容から,この時点でStatementオブジェクト,またはConnectionオブジェクトがすでにクローズされていることによるエラーだとわかります。
  5. 時系列にオブジェクトの流れを確認します。
    2004/07/06 23:07:09.129のスレッド1,2004/07/06 23:07:28.332のスレッド2,2004/07/06 23:07:28.348のスレッド3,2004/07/06 23:07:30.332のスレッド4のConnectionオブジェクトのオブジェクトIDが同じであることから,四つのスレッドが同一コネクションで処理されていることがわかります。
  6. エラーの原因となっている個所を探します。
    四つのスレッドが同一コネクションであることがわかったため,Statement.closeメソッド,またはConnection.closeメソッドを実行している個所を探します。この例の場合は,スレッド4が2004/07/06 23:07:42.098でConnection.closeメソッドを実行しています。
    このことから,2004/07/06 23:07:42.535のスレッド3で発生したSQLExceptionの原因は,スレッド4が2004/07/06 23:07:42.098でConnection.closeメソッドを実行していたためであることが,わかります。

(3) トレース取得レベルごとの出力例

トレース取得レベルごとの出力例を次に示します。

トレース取得レベル1の場合の出力例

[1] Cosminexus DABroker for Java , DABroker for Java Version 2 02-11-/D
2004/07/21 17:59:41.001 Thread[main,5,main]@2113601537 [E][JdbcDbpsvXADataSource@59920001.getXAConnection(1)]
                       HANDLE(0) : SID(0)
2004/07/21 17:59:41.020 Thread[main,5,main]@2113601537 [E][JdbcDbpsvXAConnection@8bf8002.getXAResource]
                       HANDLE(0) : SID(0)
2004/07/21 17:59:41.554 Thread[main,5,main]@2113601537 [R][JdbcDbpsvXAConnection@8bf8002.getXAResource]
                       HANDLE(0) : SID(0)
                       Return=JP.co.Hitachi.soft.DBPSV_Driver.JdbcDbpsvXAResource@33690002
2004/07/21 17:59:41.554 Thread[main,5,main]@2113601537
[R][JdbcDbpsvXADataSource@59920001.getXAConnection(1)]
                       HANDLE(0) : SID(0)
                       Return=JP.co.Hitachi.soft.DBPSV_Driver.JdbcDbpsvXAConnection@8bf8002
2004/07/21 17:59:41.557 Thread[main,5,main]@2113601537 [E][JdbcDbpsvXAConnection@8bf8002.getXAResource]
                       HANDLE(0) : SID(0)
2004/07/21 17:59:41.557 Thread[main,5,main]@2113601537 [R][JdbcDbpsvXAConnection@8bf8002.getXAResource]
                       HANDLE(0) : SID(0)
                       Return=JP.co.Hitachi.soft.DBPSV_Driver.JdbcDbpsvXAResource@33690002
2004/07/21 17:59:41.561 Thread[main,5,main]@2113601537 [E][JdbcDbpsvXAConnection@8bf8002.getConnection]
                       HANDLE(0) : SID(0)
2004/07/21 17:59:41.649 Thread[main,5,main]@2113601537 [R][JdbcDbpsvXAConnection@8bf8002.getConnection]
                       HANDLE(883163352) : SID(0)
                       Return=JP.co.Hitachi.soft.DBPSV_Driver.JdbcDbpsvConnection@78688002
2004/07/21 17:59:41.649 Thread[main,5,main]@2113601537 [E][JdbcDbpsvConnection@78688002.prepareStatement(1)]
                       HANDLE(883163352) : SID(0)
                       sql=INSERT INTO TRC_ex VALUES(?)
2004/07/21 17:59:41.819 Thread[main,5,main]@2113601537 [R][JdbcDbpsvConnection@78688002.prepareStatement(1)]
                       HANDLE(883163352) : SID(1)
                       Return=JP.co.Hitachi.soft.DBPSV_Driver.JdbcDbpsvPreparedStatement@d334002
2004/07/21 17:59:41.977 Thread[main,5,main]@2113601537 [E][JdbcDbpsvConnection@78688002.close]
                       HANDLE(883163352) : SID(0)
2004/07/21 17:59:42.886 Thread[main,5,main]@2113601537 [R][JdbcDbpsvConnection@78688002.close]
                       HANDLE(883163352) : SID(0)
2004/07/21 17:59:42.945 Thread[main,5,main]@2113601537 [E][JdbcDbpsvConnection@78688002.createStatement(1)]
                       HANDLE(883163352) : SID(0)
2004/07/21 17:59:42.946 Thread[main,5,main]@2113601537:JP.co.Hitachi.soft.DBPSV_Driver.SQLException:
KFDJ00006-E Connection is closed.[JdbcDbpsvConnection.createStatement(1)]
       at JP.co.Hitachi.soft.DBPSV_Driver.JdbcDbpsvConnection.createStatement(JdbcDbpsvConnection.java:529)
       at TRC_ex.main(TRC_ex.java:81)

トレース取得レベル2の場合の出力例

[1] Cosminexus DABroker for Java , DABroker for Java Version 2 02-11-/D
2004/07/21 19:00:56.992 Thread[main,5,main]@2113866091 [E][JdbcDbpsvXADataSource@5996096b.getXAConnection(1)]
                       HANDLE(0) : SID(0)
2004/07/21 19:00:57.012 Thread[main,5,main]@2113866091 [E][JdbcDbpsvXAConnection@8bb8968.getXAResource]
                       HANDLE(0) : SID(0)
2004/07/21 19:00:57.561 Thread[main,5,main]@2113866091 [R][JdbcDbpsvXAConnection@8bb8968.getXAResource]
                       HANDLE(0) : SID(0)
                       Return=JP.co.Hitachi.soft.DBPSV_Driver.JdbcDbpsvXAResource@336d0968
2004/07/21 19:00:57.561 Thread[main,5,main]@2113866091 [R][JdbcDbpsvXADataSource@5996096b.getXAConnection(1)]
                       HANDLE(0) : SID(0)
                       Return=JP.co.Hitachi.soft.DBPSV_Driver.JdbcDbpsvXAConnection@8bb8968
2004/07/21 19:00:57.565 Thread[main,5,main]@2113866091 [E][JdbcDbpsvXAConnection@8bb8968.getXAResource]
                       HANDLE(0) : SID(0)
2004/07/21 19:00:57.565 Thread[main,5,main]@2113866091 [R][JdbcDbpsvXAConnection@8bb8968.getXAResource]
                       HANDLE(0) : SID(0)
                       Return=JP.co.Hitachi.soft.DBPSV_Driver.JdbcDbpsvXAResource@336d0968
2004/07/21 19:00:57.569 Thread[main,5,main]@2113866091 [E][JdbcDbpsvXAConnection@8bb8968.getConnection]
                       HANDLE(0) : SID(0)
2004/07/21 19:00:57.660 Thread[main,5,main]@2113866091 [R][JdbcDbpsvXAConnection@8bb8968.getConnection]
                       HANDLE(883163368) : SID(0)
                       Return=JP.co.Hitachi.soft.DBPSV_Driver.JdbcDbpsvConnection@7862c968
2004/07/21 19:00:57.660 Thread[main,5,main]@2113866091 [E][JdbcDbpsvConnection@7862c968.prepareStatement(1)]
                       HANDLE(883163368) : SID(0)
                       sql=INSERT INTO TRC_ex VALUES(?)
2004/07/21 19:00:57.779 Thread[main,5,main]@2113866091 [R][JdbcDbpsvConnection@7862c968.prepareStatement(1)]
                       HANDLE(883163368) : SID(1)
                       Return=JP.co.Hitachi.soft.DBPSV_Driver.JdbcDbpsvPreparedStatement@d4dc968
2004/07/21 19:00:57.840 Thread[main,5,main]@2113866091 [E][JdbcDbpsvPreparedStatement@d4dc968.executeUpdate(1)]
                       HANDLE(883163368) : SID(1)
                       sql=INSERT INTO TRC_ex VALUES(?)
2004/07/21 19:00:57.854 Thread[main,5,main]@2113866091 [R][JdbcDbpsvPreparedStatement@d4dc968.executeUpdate(1)]
                       HANDLE(883163368) : SID(1)
                       Return=1
2004/07/21 19:00:57.854 Thread[main,5,main]@2113866091 [E][JdbcDbpsvConnection@7862c968.close]
                       HANDLE(883163368) : SID(0)
2004/07/21 19:00:57.886 Thread[main,5,main]@2113866091 [R][JdbcDbpsvConnection@7862c968.close]
                       HANDLE(883163368) : SID(0)
2004/07/21 19:00:57.916 Thread[main,5,main]@2113866091 [E][JdbcDbpsvConnection@7862c968.createStatement(1)]
                       HANDLE(883163368) : SID(0)
2004/07/21 19:00:57.917 Thread[main,5,main]@2113866091:JP.co.Hitachi.soft.DBPSV_Driver.SQLException: KFDJ00006-E Connection is closed.[JdbcDbpsvConnection.createStatement(1)]
       at JP.co.Hitachi.soft.DBPSV_Driver.JdbcDbpsvConnection.createStatement(JdbcDbpsvConnection.java:529)
       at TRC_ex.main(TRC_ex.java:81)

(凡例)
下線は,トレース取得レベル1ではトレースが出力されないメソッドの情報です。

トレースレベル3の場合の出力例

[1] Cosminexus DABroker for Java , DABroker for Java Version 2 02-11-/D
2004/07/21 19:01:28.755 Thread[main,5,main]@2113866075 [E][JdbcDbpsvXADataSource@5996095b.getXAConnection(1)]
                       HANDLE(0) : SID(0)
2004/07/21 19:01:28.774 Thread[main,5,main]@2113866075 [E][JdbcDbpsvXAConnection@8bb8958.getXAResource]
                       HANDLE(0) : SID(0)
2004/07/21 19:01:29.329 Thread[main,5,main]@2113866075 [R][JdbcDbpsvXAConnection@8bb8958.getXAResource]
                       HANDLE(0) : SID(0)
                       Return=JP.co.Hitachi.soft.DBPSV_Driver.JdbcDbpsvXAResource@336d0958
2004/07/21 19:01:29.329 Thread[main,5,main]@2113866075 [R][JdbcDbpsvXADataSource@5996095b.getXAConnection(1)]
                       HANDLE(0) : SID(0)
                       Return=JP.co.Hitachi.soft.DBPSV_Driver.JdbcDbpsvXAConnection@8bb8958
2004/07/21 19:01:29.332 Thread[main,5,main]@2113866075 [E][JdbcDbpsvXAConnection@8bb8958.getXAResource]
                       HANDLE(0) : SID(0)
2004/07/21 19:01:29.332 Thread[main,5,main]@2113866075 [R][JdbcDbpsvXAConnection@8bb8958.getXAResource]
                       HANDLE(0) : SID(0)
                       Return=JP.co.Hitachi.soft.DBPSV_Driver.JdbcDbpsvXAResource@336d0958
2004/07/21 19:01:29.333 Thread[main,5,main]@2113866075 [E][JdbcDbpsvXAResource@336d0958.start]
                       HANDLE(0) : SID(0)
                       xid=MyXid@5ffe4958
                       flags=0
2004/07/21 19:01:29.372 Thread[main,5,main]@2113866075 [R][JdbcDbpsvXAResource@336d0958.start]
                       HANDLE(0) : SID(0)
2004/07/21 19:01:29.389 Thread[main,5,main]@2113866075 [E][JdbcDbpsvXAConnection@8bb8958.getConnection]
                       HANDLE(0) : SID(0)
2004/07/21 19:01:29.477 Thread[main,5,main]@2113866075 [R][JdbcDbpsvXAConnection@8bb8958.getConnection]
                       HANDLE(883163368) : SID(0)
                       Return=JP.co.Hitachi.soft.DBPSV_Driver.JdbcDbpsvConnection@78b60958
2004/07/21 19:01:29.478 Thread[main,5,main]@2113866075 [E][JdbcDbpsvConnection@78b60958.prepareStatement(1)]
                       HANDLE(883163368) : SID(0)
                       sql=INSERT INTO TRC_ex VALUES(?)
2004/07/21 19:01:29.571 Thread[main,5,main]@2113866075 [R][JdbcDbpsvConnection@78b60958.prepareStatement(1)]
                       HANDLE(883163368) : SID(1)
                       Return=JP.co.Hitachi.soft.DBPSV_Driver.JdbcDbpsvPreparedStatement@13934958
2004/07/21 19:01:29.614 Thread[main,5,main]@2113866075 [E][JdbcDbpsvPreparedStatement@13934958.executeUpdate(1)]
                       HANDLE(883163368) : SID(1)
                       sql=INSERT INTO TRC_ex VALUES(?)
2004/07/21 19:01:29.624 Thread[main,5,main]@2113866075 [R][JdbcDbpsvPreparedStatement@13934958.executeUpdate(1)]
                       HANDLE(883163368) : SID(1)
                       Return=1
2004/07/21 19:01:29.624 Thread[main,5,main]@2113866075 [E][JdbcDbpsvConnection@78b60958.close]
                       HANDLE(883163368) : SID(0)
2004/07/21 19:01:29.656 Thread[main,5,main]@2113866075 [R][JdbcDbpsvConnection@78b60958.close]
                       HANDLE(883163368) : SID(0)
2004/07/21 19:01:29.656 Thread[main,5,main]@2113866075 [E][JdbcDbpsvXAResource@336d0958.end]
                       HANDLE(0) : SID(0)
                       xid=MyXid@5ffe4958
                       flags=67108864
2004/07/21 19:01:29.658 Thread[main,5,main]@2113866075 [R][JdbcDbpsvXAResource@336d0958.end]
                       HANDLE(0) : SID(0)
2004/07/21 19:01:29.659 Thread[main,5,main]@2113866075 [E][JdbcDbpsvXAResource@336d0958.prepare]
                       HANDLE(0) : SID(0)
                       xid=MyXid@5ffe4958
2004/07/21 19:01:29.675 Thread[main,5,main]@2113866075 [R][JdbcDbpsvXAResource@336d0958.prepare]
                       HANDLE(0) : SID(0)
                       Return=0
2004/07/21 19:01:29.675 Thread[main,5,main]@2113866075 [E][JdbcDbpsvXAResource@336d0958.commit]
                       HANDLE(0) : SID(0)
                       xid=MyXid@5ffe4958
                       onePhase=false
2004/07/21 19:01:29.681 Thread[main,5,main]@2113866075 [R][JdbcDbpsvXAResource@336d0958.commit]
                       HANDLE(0) : SID(0)
2004/07/21 19:01:29.681 Thread[main,5,main]@2113866075 [E][JdbcDbpsvConnection@78b60958.createStatement(1)]
                       HANDLE(883163368) : SID(0)
2004/07/21 19:01:29.682 Thread[main,5,main]@2113866075:JP.co.Hitachi.soft.DBPSV_Driver.SQLException: KFDJ00006-E Connection is closed.[JdbcDbpsvConnection.createStatement(1)]
        at JP.co.Hitachi.soft.DBPSV_Driver.JdbcDbpsvConnection.createStatement(JdbcDbpsvConnection.java:529)
        at TRC_ex.main(TRC_ex.java:81)

(凡例)
太字は,トレース取得レベル1ではトレースが出力されないメソッドの情報です。
下線は,トレース取得レベル2ではトレースが出力されないメソッドの情報です。

トレース取得レベル5の場合の出力例

[1] Cosminexus DABroker for Java , DABroker for Java Version 2 02-11-/D
2004/07/21 18:58:47.122 Thread[main,5,main]@2113866026 [E][JdbcDbpsvXADataSource@5996092a.getXAConnection(1)]
                       HANDLE(0) : SID(0)
2004/07/21 18:58:47.141 Thread[main,5,main]@2113866026 [E][JdbcDbpsvXAConnection@8bb8929.getXAResource]
                       HANDLE(0) : SID(0)
2004/07/21 18:58:47.705 Thread[main,5,main]@2113866026 [R][JdbcDbpsvXAConnection@8bb8929.getXAResource]
                       HANDLE(0) : SID(0)
                       Return=JP.co.Hitachi.soft.DBPSV_Driver.JdbcDbpsvXAResource@336d0929
2004/07/21 18:58:47.706 Thread[main,5,main]@2113866026 [R][JdbcDbpsvXADataSource@5996092a.getXAConnection(1)]
                       HANDLE(0) : SID(0)
                       Return=JP.co.Hitachi.soft.DBPSV_Driver.JdbcDbpsvXAConnection@8bb8929
2004/07/21 18:58:47.709 Thread[main,5,main]@2113866026 [E][JdbcDbpsvXAConnection@8bb8929.getXAResource]
                       HANDLE(0) : SID(0)
2004/07/21 18:58:47.709 Thread[main,5,main]@2113866026 [R][JdbcDbpsvXAConnection@8bb8929.getXAResource]
                       HANDLE(0) : SID(0)
                       Return=JP.co.Hitachi.soft.DBPSV_Driver.JdbcDbpsvXAResource@336d0929
2004/07/21 18:58:47.710 Thread[main,5,main]@2113866026 [E][JdbcDbpsvXAResource@336d0929.start]
                       HANDLE(0) : SID(0)
                       xid=MyXid@5ffe4929
                       flags=0
2004/07/21 18:58:47.750 Thread[main,5,main]@2113866026 [R][JdbcDbpsvXAResource@336d0929.start]
                       HANDLE(0) : SID(0)
2004/07/21 18:58:47.770 Thread[main,5,main]@2113866026 [E][JdbcDbpsvXAConnection@8bb8929.getConnection]
                       HANDLE(0) : SID(0)
2004/07/21 18:58:47.858 Thread[main,5,main]@2113866026 [R][JdbcDbpsvXAConnection@8bb8929.getConnection]
                       HANDLE(883163368) : SID(0)
                       Return=JP.co.Hitachi.soft.DBPSV_Driver.JdbcDbpsvConnection@78454929
2004/07/21 18:58:47.858 Thread[main,5,main]@2113866026 [E][JdbcDbpsvConnection@78454929.prepareStatement(1)]
                       HANDLE(883163368) : SID(0)
                       sql=INSERT INTO TRC_ex VALUES(?)
2004/07/21 18:58:47.952 Thread[main,5,main]@2113866026 [R][JdbcDbpsvConnection@78454929.prepareStatement(1)]
                       HANDLE(883163368) : SID(1)
                       Return=JP.co.Hitachi.soft.DBPSV_Driver.JdbcDbpsvPreparedStatement@d2ec929
2004/07/21 18:58:47.994 Thread[main,5,main]@2113866026 [E][JdbcDbpsvPreparedStatement@d2ec929.executeUpdate(1)]
                       HANDLE(883163368) : SID(1)
                       sql=INSERT INTO TRC_ex VALUES(?)
2004/07/21 18:58:47.994 Thread[main,5,main]@2113866026 [E][JdbcDbpsvPreparedStatement@d2ec929.execute(1)]
                       HANDLE(883163368) : SID(1)
                       sql=INSERT INTO TRC_ex VALUES(?)
2004/07/21 18:58:48.004 Thread[main,5,main]@2113866026 [R][JdbcDbpsvPreparedStatement@d2ec929.execute(1)]
                       HANDLE(883163368) : SID(1)
                       Return=false
2004/07/21 18:58:48.004 Thread[main,5,main]@2113866026 [R][JdbcDbpsvPreparedStatement@d2ec929.executeUpdate(1)]
                       HANDLE(883163368) : SID(1)
                       Return=1
2004/07/21 18:58:48.004 Thread[main,5,main]@2113866026 [E][JdbcDbpsvConnection@78454929.close]
                       HANDLE(883163368) : SID(0)
2004/07/21 18:58:48.037 Thread[main,5,main]@2113866026 [R][JdbcDbpsvConnection@78454929.close]
                       HANDLE(883163368) : SID(0)
2004/07/21 18:58:48.037 Thread[main,5,main]@2113866026 [E][JdbcDbpsvXAResource@336d0929.end]
                       HANDLE(0) : SID(0)
                       xid=MyXid@5ffe4929
                       flags=67108864
2004/07/21 18:58:48.039 Thread[main,5,main]@2113866026 [R][JdbcDbpsvXAResource@336d0929.end]
                       HANDLE(0) : SID(0)
2004/07/21 18:58:48.039 Thread[main,5,main]@2113866026 [E][JdbcDbpsvXAResource@336d0929.prepare]
                       HANDLE(0) : SID(0)
                       xid=MyXid@5ffe4929
2004/07/21 18:58:48.053 Thread[main,5,main]@2113866026 [R][JdbcDbpsvXAResource@336d0929.prepare]
                       HANDLE(0) : SID(0)
                       Return=0
2004/07/21 18:58:48.053 Thread[main,5,main]@2113866026 [E][JdbcDbpsvXAResource@336d0929.commit]
                       HANDLE(0) : SID(0)
                       xid=MyXid@5ffe4929
                       onePhase=false
2004/07/21 18:58:48.059 Thread[main,5,main]@2113866026 [R][JdbcDbpsvXAResource@336d0929.commit]
                       HANDLE(0) : SID(0)
2004/07/21 18:58:48.059 Thread[main,5,main]@2113866026
[E][JdbcDbpsvConnection@78454929.createStatement(1)]
                       HANDLE(883163368) : SID(0)
2004/07/21 18:58:48.060 Thread[main,5,main]@2113866026:JP.co.Hitachi.soft.DBPSV_Driver.SQLException: KFDJ00006-E Connection is closed.[JdbcDbpsvConnection.createStatement(1)]
       at JP.co.Hitachi.soft.DBPSV_Driver.JdbcDbpsvConnection.createStatement(JdbcDbpsvConnection.java:529)
       at TRC_ex.main(TRC_ex.java:81)

(凡例)
太字は,トレース取得レベル1ではトレースが出力されないメソッドの情報です。
下線は,トレース取得レベル2ではトレースが出力されないメソッドの情報です。