スケーラブルデータベースサーバ　HiRDB Version 8 UAP開発ガイド

[目次][索引][前へ][次へ]

18.15.3　出力例と解析方法

＜この項の構成＞
(1)　出力例
(2)　解析方法

(1)　出力例

Exceptionトレースログの出力例を次に示します。

 
[1] HiRDB_Type4_JDBC_Driver 08-00
2006/07/06 23:07:09.129 Thread[main,5,main]@1259414:[E][PrdbConnection@82c01f.createStatement(1)]
                        ConnectionID(sds:23:20484) : SID(0)
2006/07/06 23:07:09.160 Thread[main,5,main]@1259414:[R][PrdbConnection@82c01f.createStatement(1)]
                        ConnectionID(sds:23:20484) : SID(0)
                        Return=JP.co.Hitachi.soft.HiRDB.JDBC.PrdbStatement@1e4cbc4
2006/07/06 23:07:09.160 Thread[main,5,main]@1259414:[E][PrdbStatement@1e4cbc4.execute]
                        ConnectionID(sds:23:20484) : SID(0)
                        sql=DELETE FROM SEINO_TABLE
2006/07/06 23:07:14.285 Thread[main,5,main]@1259414:[E][PrdbConnection@82c01f.commit]
                        ConnectionID(sds:23:20484) : SID(0)
2006/07/06 23:07:14.301 Thread[main,5,main]@1259414:[R][PrdbConnection@82c01f.commit]
                        ConnectionID(sds:23:20484) : SID(0)
2006/07/06 23:07:14.301 Thread[main,5,main]@1259414:[R][PrdbStatement@1e4cbc4.execute]
                        ConnectionID(sds:23:20484) : SID(1)
                        Return=false
2006/07/06 23:07:14.301 Thread[main,5,main]@1259414:[E][PrdbConnection@82c01f.prepareStatement(1)]
                        ConnectionID(sds:23:20484) : SID(0)
                        sql=INSERT INTO SEINO_TABLE VALUES(?, ?)
2006/07/06 23:07:14.348 Thread[main,5,main]@1259414:[R][PrdbConnection@82c01f.prepareStatement(1)]
                        ConnectionID(sds:23:20484) : SID(0)
                        Return=JP.co.Hitachi.soft.HiRDB.JDBC.PrdbPreparedStatement@15d56d5
2006/07/06 23:07:26.567 Thread[main,5,main]@1259414:[E][PrdbConnection@82c01f.commit]
                        ConnectionID(sds:23:20484) : SID(0)
2006/07/06 23:07:26.567 Thread[main,5,main]@1259414:[R][PrdbConnection@82c01f.commit]
                        ConnectionID(sds:23:20484) : SID(0)
2006/07/06 23:07:26.567 Thread[main,5,main]@1259414:[E][PrdbStatement@1e4cbc4.executeQuery]
                        ConnectionID(sds:23:20484) : SID(0)
                        sql=SELECT * FROM SEINO_TABLE
2006/07/06 23:07:26.676 Thread[main,5,main]@1259414:[R][PrdbStatement@1e4cbc4.executeQuery]
                        ConnectionID(sds:23:20484) : SID(1)
                        Return=JP.co.Hitachi.soft.HiRDB.JDBC.PrdbResultSet@3eca90
2006/07/06 23:07:28.332 Thread[main,5,main]@1259414:[E][PrdbResultSet@3eca90.close]
                        ConnectionID(sds:23:20484) : SID(1)
2006/07/06 23:07:28.332 Thread[main,5,main]@1259414:[E][PrdbConnection@82c01f.commit]
                        ConnectionID(sds:23:20484) : SID(0)
2006/07/06 23:07:28.332 Thread[main,5,main]@1259414:[R][PrdbConnection@82c01f.commit]
                        ConnectionID(sds:23:20484) : SID(0)
2006/07/06 23:07:28.332 Thread[main,5,main]@1259414:[R][PrdbResultSet@3eca90.close]
                        ConnectionID(sds:23:20484) : SID(0)
2006/07/06 23:07:28.332 Thread[Thread-0,5,main]@30090737:[E][PrdbConnection@82c01f.prepareStatement(1)]
                        ConnectionID(sds:23:20484) : SID(0)
                        sql=SELECT * FROM SEINO_TABLE
2006/07/06 23:07:28.332 Thread[Thread-0,5,main]@30090737:[R][PrdbConnection@82c01f.prepareStatement(1)]
                        ConnectionID(sds:23:20484) : SID(0)
                        Return=JP.co.Hitachi.soft.HiRDB.JDBC.PrdbPreparedStatement@2808b3
2006/07/06 23:07:28.348 Thread[Thread-1,5,main]@5462872:[E][PrdbConnection@82c01f.prepareStatement(1)]
                        ConnectionID(sds:23:20484) : SID(0)
                        sql=DELETE FROM SEINO_TABLE WHERE I1=?
2006/07/06 23:07:28.358 Thread[Thread-1,5,main]@5462872:[E][PrdbConnection@82c01f.commit]
                        ConnectionID(sds:23:20484) : SID(0)
2006/07/06 23:07:29.672 Thread[Thread-1,5,main]@5462872:[R][PrdbConnection@82c01f.commit]
                        ConnectionID(sds:23:20484) : SID(0)
2006/07/06 23:07:30.098 Thread[Thread-1,5,main]@5462872:[R][PrdbConnection@82c01f.prepareStatement(1)]
                        ConnectionID(sds:23:20484) : SID(0)
                        Return=JP.co.Hitachi.soft.HiRDB.JDBC.PrdbPreparedStatement@922804
2006/07/06 23:07:30.332 Thread[Thread-2,5,main]@25253977:[E][PrdbConnection@82c01f.rollback(1)]
                        ConnectionID(sds:23:20484) : SID(0)
2006/07/06 23:07:42.098 Thread[Thread-2,5,main]@25253977:[R][PrdbConnection@82c01f.rollback(1)]
                        ConnectionID(sds:23:20484) : SID(0)
2006/07/06 23:07:42.098 Thread[Thread-2,5,main]@25253977:[E][PrdbConnection@82c01f.close]
                        ConnectionID(sds:23:20484) : SID(0)
2006/07/06 23:07:42.098 Thread[Thread-2,5,main]@25253977:[R][PrdbConnection@82c01f.close]
                        ConnectionID(sds:23:20484) : SID(0)
2006/07/06 23:07:42.535 Thread[Thread-1,5,main]@5462872:Exception:
ExceptionClass: SQLException
UapEnvironment: *
Message: KFPJ20006-E Connection closed[PrdbPreparedStatement.setInt]
ErrorCode: -1020006
SQLState: R2400
Etc.: *,*,****
java.sql.SQLException: KFPJ20006-E Connection closed[PrdbPreparedStatement.setInt]
at JP.co.Hitachi.soft.HiRDB.JDBC.JdbMakeException.generateSQLException(JdbMakeException.java:31)
at JP.co.Hitachi.soft.HiRDB.JDBC.PrdbStatement.generateClosedSQLException(PrdbStatement.java:3005)
at JP.co.Hitachi.soft.HiRDB.JDBC.PrdbPreparedStatement.setInt(PrdbPreparedStatement.java:1170)
at Exception1.run(ExceptionTraceSample.java:57)
[2] HiRDB_Type4_JDBC_Driver 08-00
2006/07/06 23:07:25.723 Thread[Thread-3,5,main]@13249998:[E][PrdbConnection@119cca4.prepareStatement(1)]
                        ConnectionID(sds:24:20484) : SID(0)
                        sql=SELECT * FROM SEINO_TABLE
2006/07/06 23:07:25.770 Thread[Thread-4,5,main]@25839584:[E][PrdbConnection@119cca4.rollback(1)]
                        ConnectionID(sds:24:20484) : SID(0)
2006/07/06 23:07:25.770 Thread[Thread-4,5,main]@25839584:[R][PrdbConnection@119cca4.rollback(1)]
                        ConnectionID(sds:24:20484) : SID(0)
2006/07/06 23:07:25.770 Thread[Thread-5,5,main]@24431647:[E][PrdbConnection@119cca4.prepareStatement(1)]
                        ConnectionID(sds:24:20484) : SID(0)
                        sql=SELECT ** FROM SEINO_TABLE
2006/07/06 23:07:25.863 Thread[Thread-5,5,main]@24431647:Exception:
ExceptionClass: SQLException
UapEnvironment: USER(USER1), NAMEPORT(20249), CWAITTIME(0), SWAITTIME(600), HOST(dragon2), FESHOST( ), 
SERVICEGRP(sds), SWATCHTIME( ), SERVICEPORT( ), SRVTYPE(WS), CLTRCVPORT( ), CLTRCVADDR( ), FESGRP( )
Message: KFPA11105-E Invalid token "*" after token "*"[PrdbStatement.prepare]
ErrorCode: -105
SQLState: R0000
Etc.: 4,sqapyac1.c(651),SET 
java.sql.SQLException: KFPA11105-E Invalid token "*" after token "*"[PrdbStatement.prepare]
at JP.co.Hitachi.soft.HiRDB.JDBC.CltSection.prepare(CltSection.java:1497)
at JP.co.Hitachi.soft.HiRDB.JDBC.PrdbStatement.prepare(PrdbStatement.java:2834)
at JP.co.Hitachi.soft.HiRDB.JDBC.PrdbPreparedStatement.<init>(PrdbPreparedStatement.java:109)
at JP.co.Hitachi.soft.HiRDB.JDBC.PrdbConnection.prepareStatement(PrdbConnection.java:1041)
at Exception1.run(ExceptionTraceSample.java:64)

(2)　解析方法

Exceptionトレースログの解析方法について説明します。Exceptionトレースログはテキストエディタなどで参照できます。

ここでは，「(1) 出力例」のExceptionトレースログを解析する例を示します。

解析例
  1. 調査対象の例外を含む通番の情報を抜き出します。
  2. 情報をThread識別情報で分類し，スレッドごとに分割します。
  3. 取得時刻によって，情報を時系列に並べます。
    次の表に示すようになります。

    表18-89　Exceptionトレースログを時系列に並べた例

    日時 スレッド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
    2006/07/06
    23:07:09.129    		 PrdbConnection
    @82c01f.createStatement(1)    		 　 　 　
    2006/07/06
    23:07:09.160    		 PrdbStatement
    @1e4cbc4.execute    		 　 　 　
    2006/07/06
    23:07:14.285    		 PrdbConnection
    @82c01f.commit    		 　 　 　
    2006/07/06
    23:07:14.301    		 PrdbConnection
    @82c01f.prepareStatement(1)    		 　 　 　
    2006/07/06
    23:07:26.567    		 PrdbConnection
    @82c01f.commit    		 　 　 　
    2006/07/06
    23:07:26.567    		 PrdbStatement
    @1e4cbc4.executeQuery    		 　 　 　
    2006/07/06
    23:07:26.567    		 PrdbStatement
    @1e4cbc4.execute    		 　 　 　
    2006/07/06
    23:07:28.332    		 PrdbResultSet
    @3eca90.close    		 PrdbConnection
    @82c01f.prepareStatement(1)    		 　 　
    2006/07/06
    23:07:28.332    		 PrdbConnection
    @82c01f.commit    		 　 　 　
    2006/07/06
    23:07:28.348    		 　 　 PrdbConnection
    @82c01f.prepareStatement(1)    		 　
    2006/07/06
    23:07:28.358    		 　 　 PrdbConnection
    @82c01f.commit    		 　
    2006/07/06
    23:07:30.332    		 　 　 　 PrdbConnection
    @82c01f.rollback
    2006/07/06
    23:07:42.098    		 　 　 　 PrdbConnection
    @82c01f.close
    2006/07/06
    23:07:42.535    		 　 　 SQLException発生
    KFPJ20006-E Connection closed    		 　
    　
  4. Exceptionのエラーの内容を確認します。
    2006/07/06 23:07:42.535のスレッド3でSQLExceptionが発生し，Statementオブジェクト又はConnectionオブジェクトが既にクローズされていることが分かります。
  5. 時系列でオブジェクトの操作を確認します。
    次のスレッドのConnectionオブジェクトのオブジェクトIDが同じであることから，四つのスレッドが同一のコネクションで処理されていることが分かります。
    • 2006/07/06 23:07:09.129のスレッド1
    • 2006/07/06 23:07:28.332のスレッド2
    • 2006/07/06 23:07:28.348のスレッド3
    • 2006/07/06 23:07:30.332のスレッド4
  6. エラーの原因である箇所を探します。
    四つのスレッドが同一のコネクションであることは分かったので，Statement.closeメソッド又はConnection.closeメソッドを実行している箇所を探すと，スレッド4が2006/07/06 23:07:42.098でConnection.closeメソッドを実行していることが分かります。このことから，2006/07/06 23:07:42.535のスレッド3で発生したSQLExceptionの原因は，スレッド4が2006/07/06 23:07:42.098でConnection.closeメソッドを実行したことであると分かります。

[目次][前へ][次へ]

[商品名称に関する表示]

All Rights Reserved. Copyright (C) 2006, 2016, Hitachi, Ltd.