Scalable Database Server, HiRDB Version 8 UAP Development Guide

[Contents][Index][Back][Next]

17.13.3 Output example and analysis method

Organization of this subsection
(1) Output example
(2) Analysis method

(1) Output example

An output example of the Exception trace log is shown below:

 
[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) Analysis method

This item explains the analysis method of the Exception trace log. You can use a text editor to reference the Exception trace log.

Described below is an example of analyzing the Exception trace log shown in (1) Output example.

Analysis example

To analyze the Exception trace log:

  1. Extract the sequentially numbered information, including the exception to be investigated.
  2. Categorize the information by using the thread identification information, and separate the information by thread.
  3. Arrange the information in time sequence based on the acquisition time.
    Table 17-51 shows what the results look like.

    Table 17-51 Example in which the Exception trace log is arranged in time sequence

    Date and time Thread 1 Thread 2 Thread 3 Thread 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 occurred
    KFPJ20006-E Connection closed

  4. Check the contents of the exception error.
    The information indicates that an SQLException occurred in Thread 3 at 2006/07/06 23:07:42.535, and that a Statement or Connection object had already been closed.
  5. Check the operation of the object in the time sequence.
    Because the object ID of the Connection object in the next thread is the same, we know that the four threads were being processed in the same connection.
    • Thread 1 at 2006/07/06 23:07:09.129
    • Thread 2 at 2006/07/06 23:07:28.332
    • Thread 3 at 2006/07/06 23:07:28.348
    • Thread 4 at 2006/07/06 23:07:30.332
  6. Search for the location of the error cause.
    Because we know that the four threads have the same connection, we can search for the locations where the Statement.close or Connection.close method was executed, and learn that Thread 4 executed the Connection.close method at 2006/07/06 23:07:42.098. From this, we know that the cause of the SQLException that occurred in Thread 3 at 2006/07/06 23:07:42.535 was that Thread 4 executed the Connection.close method at 2006/07/06 23:07:42.098.

[Contents][Back][Next]

[Trademarks]

All Rights Reserved. Copyright (C) 2007, Hitachi, Ltd.