db-derby-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Rick Hillegas (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (DERBY-6533) Add a quiet mode to NsTest
Date Wed, 21 May 2014 19:22:39 GMT

    [ https://issues.apache.org/jira/browse/DERBY-6533?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14005123#comment-14005123
] 

Rick Hillegas commented on DERBY-6533:
--------------------------------------

I have updated my installation on the 8 core machine to use jar files built from the head
of trunk after checking in derby-6542-02-af-useNewSequenceGenerator.diff. Here is the output
from a 6 hour run.

Summary: A couple errors 1 minute into the test, starting with a problem in destroying a transaction
while firing a delete trigger. The a half hour into the test there was one TooMuchContention
exception on the user-created sequence.

{noformat}
STATISTICS OF OPERATIONS DONE
-----------------------------



Start time = 2014-05-21 14:11:38.358
End time = 2014-05-21 20:11:26.506
Duration = 359 minutes



SUCCESSFUL: 
	Number of INSERTS = 2544388
	Number of UPDATES = 1253208
	Number of DELETES = 1253550
	Number of SELECTS = 103324

FAILED: 
	Number of failed INSERTS = 1
	Number of failed UPDATES = 1216899
	Number of failed DELETES = 1217258
	Number of failed SELECTS = 0

  Note that this may not be the same as the server side connections made
   to the database especially if connection pooling is employed

NOTE: Failing operations could be because of locking issue that are
directly related to the application logic.  They are not necessarily bugs.

Max sequence counter peeked at = 2576467


Last total memory = 6312427520, last free memory = 5520965304 as measured at Wed May 21 20:08:22
CEST 2014



	Number of X0Y84 = 1
	Number of 08003 = 1
	Number of XJ001 = 1


//////////////////////////////////////////////////////////////
//    
//    Count = 1, SQLState = XJ001, Message = Java exception: '-1: java.lang.ArrayIndexOutOfBoundsException'.
//    
//    First occurrence at 2014-05-21 14:12:56.693, last occurrence at 2014-05-21 14:12:56.693
//    
//////////////////////////////////////////////////////////////

java.sql.SQLException: Java exception: '-1: java.lang.ArrayIndexOutOfBoundsException'.
	at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(SQLExceptionFactory.java:107)
	at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(SQLExceptionFactory.java:133)
	at org.apache.derby.impl.jdbc.Util.seeNextException(Util.java:255)
	at org.apache.derby.impl.jdbc.Util.javaException(Util.java:277)
	at org.apache.derby.impl.jdbc.TransactionResourceImpl.wrapInSQLException(TransactionResourceImpl.java:437)
	at org.apache.derby.impl.jdbc.TransactionResourceImpl.handleException(TransactionResourceImpl.java:353)
	at org.apache.derby.impl.jdbc.EmbedConnection.handleException(EmbedConnection.java:2396)
	at org.apache.derby.impl.jdbc.ConnectionChild.handleException(ConnectionChild.java:82)
	at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java:1430)
	at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(EmbedPreparedStatement.java:1709)
	at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeLargeUpdate(EmbedPreparedStatement.java:320)
	at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(EmbedPreparedStatement.java:309)
	at org.apache.derbyTesting.system.nstest.utils.DbUtil.delete_one_row(DbUtil.java:436)
	at org.apache.derbyTesting.system.nstest.tester.TesterObject.doIUDOperation(TesterObject.java:193)
	at org.apache.derbyTesting.system.nstest.tester.Tester1.startTesting(Tester1.java:121)
	at org.apache.derbyTesting.system.nstest.NsTest.run(NsTest.java:805)
Caused by: ERROR XJ001: Java exception: '-1: java.lang.ArrayIndexOutOfBoundsException'.
	at org.apache.derby.iapi.error.StandardException.newException(StandardException.java:290)
	at org.apache.derby.impl.jdbc.SQLExceptionFactory.wrapArgsForTransportAcrossDRDA(SQLExceptionFactory.java:162)
	at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(SQLExceptionFactory.java:74)
	... 15 more
Caused by: java.lang.ArrayIndexOutOfBoundsException: -1
	at java.util.ArrayList.elementData(ArrayList.java:403)
	at java.util.ArrayList.remove(ArrayList.java:480)
	at org.apache.derby.iapi.services.context.ContextManager.popContext(ContextManager.java:209)
	at org.apache.derby.iapi.services.context.ContextImpl.popMe(ContextImpl.java:81)
	at org.apache.derby.impl.store.access.RAMTransaction.destroy(RAMTransaction.java:2013)
	at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(SPSDescriptor.java:788)
	at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(SPSDescriptor.java:655)
	at org.apache.derby.impl.sql.execute.GenericTriggerExecutor.executeSPS(GenericTriggerExecutor.java:171)
	at org.apache.derby.impl.sql.execute.GenericTriggerExecutor.executeWhenClauseAndAction(GenericTriggerExecutor.java:346)
	at org.apache.derby.impl.sql.execute.RowTriggerExecutor.fireTrigger(RowTriggerExecutor.java:113)
	at org.apache.derby.impl.sql.execute.TriggerEventActivator.notifyEvent(TriggerEventActivator.java:272)
	at org.apache.derby.impl.sql.execute.DeleteResultSet.fireAfterTriggers(DeleteResultSet.java:469)
	at org.apache.derby.impl.sql.execute.DeleteResultSet.open(DeleteResultSet.java:158)
	at org.apache.derby.impl.sql.GenericPreparedStatement.executeStmt(GenericPreparedStatement.java:470)
	at org.apache.derby.impl.sql.GenericPreparedStatement.execute(GenericPreparedStatement.java:349)
	at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java:1338)
	... 7 more


//////////////////////////////////////////////////////////////
//    
//    Count = 1, SQLState = 08003, Message = No current connection.
//    
//    First occurrence at 2014-05-21 14:12:56.695, last occurrence at 2014-05-21 14:12:56.695
//    
//////////////////////////////////////////////////////////////

java.sql.SQLNonTransientConnectionException: No current connection.
	at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(SQLExceptionFactory.java:80)
	at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(SQLExceptionFactory.java:133)
	at org.apache.derby.impl.jdbc.Util.generateCsSQLException(Util.java:228)
	at org.apache.derby.impl.jdbc.Util.generateCsSQLException(Util.java:223)
	at org.apache.derby.impl.jdbc.Util.noCurrentConnection(Util.java:239)
	at org.apache.derby.impl.jdbc.EmbedConnection.checkIfClosed(EmbedConnection.java:2371)
	at org.apache.derby.impl.jdbc.EmbedConnection.getTransactionIsolation(EmbedConnection.java:2266)
	at org.apache.derby.impl.jdbc.EmbedConnection.setTransactionIsolation(EmbedConnection.java:2217)
	at org.apache.derbyTesting.system.nstest.utils.DbUtil.delete_one_row(DbUtil.java:443)
	at org.apache.derbyTesting.system.nstest.tester.TesterObject.doIUDOperation(TesterObject.java:193)
	at org.apache.derbyTesting.system.nstest.tester.Tester1.startTesting(Tester1.java:121)
	at org.apache.derbyTesting.system.nstest.NsTest.run(NsTest.java:805)
Caused by: ERROR 08003: No current connection.
	at org.apache.derby.iapi.error.StandardException.newException(StandardException.java:290)
	at org.apache.derby.impl.jdbc.SQLExceptionFactory.wrapArgsForTransportAcrossDRDA(SQLExceptionFactory.java:162)
	at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(SQLExceptionFactory.java:74)
	... 11 more


//////////////////////////////////////////////////////////////
//    
//    Count = 1, SQLState = X0Y84, Message = Too much contention on sequence NSTESTTAB_SEQ.
This is probably caused by an uncommitted scan of the SYS.SYSSEQUENCES catalog. Do not query
this catalog directly. Instead, use the SYSCS_UTIL.SYSCS_PEEK_AT_SEQUENCE function to view
the current value of a sequence generator.
//    
//    First occurrence at 2014-05-21 14:32:42.785, last occurrence at 2014-05-21 14:32:42.785
//    
//////////////////////////////////////////////////////////////

java.sql.SQLException: Too much contention on sequence NSTESTTAB_SEQ. This is probably caused
by an uncommitted scan of the SYS.SYSSEQUENCES catalog. Do not query this catalog directly.
Instead, use the SYSCS_UTIL.SYSCS_PEEK_AT_SEQUENCE function to view the current value of a
sequence generator.
	at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(SQLExceptionFactory.java:107)
	at org.apache.derby.impl.jdbc.Util.generateCsSQLException(Util.java:233)
	at org.apache.derby.impl.jdbc.TransactionResourceImpl.wrapInSQLException(TransactionResourceImpl.java:424)
	at org.apache.derby.impl.jdbc.TransactionResourceImpl.handleException(TransactionResourceImpl.java:353)
	at org.apache.derby.impl.jdbc.EmbedConnection.handleException(EmbedConnection.java:2396)
	at org.apache.derby.impl.jdbc.ConnectionChild.handleException(ConnectionChild.java:82)
	at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java:1430)
	at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(EmbedPreparedStatement.java:1709)
	at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeLargeUpdate(EmbedPreparedStatement.java:320)
	at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(EmbedPreparedStatement.java:309)
	at org.apache.derbyTesting.system.nstest.utils.DbUtil.add_one_row(DbUtil.java:196)
	at org.apache.derbyTesting.system.nstest.tester.TesterObject.doIUDOperation(TesterObject.java:164)
	at org.apache.derbyTesting.system.nstest.tester.Tester2.startTesting(Tester2.java:113)
	at org.apache.derbyTesting.system.nstest.NsTest.run(NsTest.java:809)
Caused by: ERROR X0Y84: Too much contention on sequence NSTESTTAB_SEQ. This is probably caused
by an uncommitted scan of the SYS.SYSSEQUENCES catalog. Do not query this catalog directly.
Instead, use the SYSCS_UTIL.SYSCS_PEEK_AT_SEQUENCE function to view the current value of a
sequence generator.
	at org.apache.derby.iapi.error.StandardException.newException(StandardException.java:290)
	at org.apache.derby.iapi.error.StandardException.newException(StandardException.java:285)
	at org.apache.derby.impl.sql.catalog.SequenceUpdater.tooMuchContentionException(SequenceUpdater.java:182)
	at org.apache.derby.impl.sql.catalog.SequenceUpdater.getCurrentValueAndAdvance(SequenceUpdater.java:418)
	at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.getCurrentValueAndAdvance(DataDictionaryImpl.java:10306)
	at org.apache.derby.impl.sql.execute.BaseActivation.getCurrentValueAndAdvance(BaseActivation.java:763)
	at org.apache.derby.exe.ac1db1e91ax0146x1eb1xab81x000017ae4fe0ef9.e0(Unknown Source)
	at org.apache.derby.impl.services.reflect.DirectCall.invoke(ReflectGeneratedClass.java:101)
	at org.apache.derby.impl.sql.execute.RowResultSet.getNextRowCore(RowResultSet.java:150)
	at org.apache.derby.impl.sql.execute.NormalizeResultSet.getNextRowCore(NormalizeResultSet.java:188)
	at org.apache.derby.impl.sql.execute.DMLWriteResultSet.getNextRowCore(DMLWriteResultSet.java:143)
	at org.apache.derby.impl.sql.execute.InsertResultSet.getNextRowCore(InsertResultSet.java:1311)
	at org.apache.derby.impl.sql.execute.InsertResultSet.open(InsertResultSet.java:503)
	at org.apache.derby.impl.sql.GenericPreparedStatement.executeStmt(GenericPreparedStatement.java:470)
	at org.apache.derby.impl.sql.GenericPreparedStatement.execute(GenericPreparedStatement.java:349)
	at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java:1338)
	... 7 more
{noformat}


> Add a quiet mode to NsTest
> --------------------------
>
>                 Key: DERBY-6533
>                 URL: https://issues.apache.org/jira/browse/DERBY-6533
>             Project: Derby
>          Issue Type: Improvement
>          Components: Test
>    Affects Versions: 10.11.0.0
>            Reporter: Rick Hillegas
>            Assignee: Rick Hillegas
>         Attachments: derby-6533-01-aa-quietMode.diff, derby-6533-02-aa-sequencesAndMoreStats.diff,
derby-6533-02-aa-sequencesAndMoreStats.out, derby-6533-03-timerThread.diff, derby-6533-04-outOfMemory.diff,
derby-6533-05-aa-dieQuickly.diff, derby-6533-07-aa-moreDefensiveCode.diff, derby-6533-08-aa-sortErrors.diff,
derby-6533-aa-anotherNPE.diff, nstest.out, nstest.out, nstest.out, nstest.out, nstest.out,
nstest.out, nstest.out, nstest.out, nstest.out, nstest.out, nstest.out, nstest.out, nstest.out
>
>
> Right now NsTest produces an enormous log file. This may be useful for tracking down
some errors. However, this can also make it hard to find the signal in the noise. It would
be good to turn off the chatty diagnostics which report the result of every insert, update,
delete, and select. A summary at the end may be good enough, including a summary of the number
of times each kind of error (SQLState) was seen. While I'm in there, I plan to make other
smallish changes.



--
This message was sent by Atlassian JIRA
(v6.2#6252)

Mime
View raw message