[DERBY-5422] IndexOutOfBoundsException followed by NullPointerException in cleanup during system.nstest

• Type: Bug
• Status: Closed
• Priority: Critical
• Resolution: Cannot Reproduce
• Affects Version/s: 10.9.1.0
• Component/s: Test
• Environment: Windows XP, with ibm 1.6 SR9 FP1
• Urgency: Blocker
• Bug behavior facts: Regression
• Assignee: Unassigned
• Reporter: Myrna van Lunteren
• Created: 20/Sep/11 04:16
• Updated: 17/Apr/12 22:23
• Resolved: 17/Apr/12 22:23

Description

During the embedded NsTest system test on windows XP I saw the following in derby.log:

Tue Sep 13 16:25:03 PDT 2011:
Booting Derby version The Apache Software Foundation - Apache Derby - 10.8.2.1 - (1170221): instance b779ce27-0132-6516-81e1-000000312348
on database directory D:\10.8.2.1\tst\restoredir\nstestdb with class loader sun.misc.Launcher$AppClassLoader@40504050
Loaded from file:/D:/10.8.2.1/jars/derby.jar
java.vendor=IBM Corporation
java.runtime.version=jvmwi3260sr9-20110203_74623
java.fullversion=JRE 1.6.0 IBM J9 2.4 Windows Server 2003 x86-32 jvmwi3260sr9-20110203_74623 (JIT enabled, AOT enabled)
J9VM - 20110203_074623
JIT - r9_20101028_17488ifx3
GC - 20101027_AA
user.dir=D:\10.8.2.1\tst
derby.system.home=null
New exception raised during cleanup Index: -1, Size: 15
java.lang.IndexOutOfBoundsException: Index: -1, Size: 15
at java.util.ArrayList.remove(ArrayList.java:552)
at org.apache.derby.iapi.services.context.ContextManager.popContext(Unknown Source)
at org.apache.derby.iapi.services.context.ContextImpl.popMe(Unknown Source)
at org.apache.derby.impl.store.access.RAMTransaction.destroy(Unknown Source)
at org.apache.derby.impl.sql.conn.GenericLanguageConnectionContext.doRollback(Unknown Source)
at org.apache.derby.impl.sql.conn.GenericLanguageConnectionContext.internalRollback(Unknown Source)
at org.apache.derby.impl.sql.conn.GenericLanguageConnectionContext.cleanupOnError(Unknown Source)
at org.apache.derby.iapi.services.context.ContextManager.cleanupOnError(Unknown Source)
at org.apache.derby.impl.sql.catalog.SequenceUpdater.clearIdentity(Unknown Source)
at org.apache.derby.impl.services.cache.ConcurrentCache.removeEntry(Unknown Source)
at org.apache.derby.impl.services.cache.ConcurrentCache.ageOut(Unknown Source)
at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.clearSequenceCaches(Unknown Source)
at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.clearCaches(Unknown Source)
at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.doneReading(Unknown Source)
at org.apache.derby.impl.sql.GenericStatement.prepMinion(Unknown Source)
at org.apache.derby.impl.sql.GenericStatement.prepareStorable(Unknown Source)
at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.compileStatement(Unknown Source)
at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.prepareAndRelease(Unknown Source)
at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
at org.apache.derby.impl.sql.execute.GenericTriggerExecutor.executeSPS(Unknown Source)
at org.apache.derby.impl.sql.execute.RowTriggerExecutor.fireTrigger(Unknown Source)
at org.apache.derby.impl.sql.execute.TriggerEventActivator.notifyEvent(Unknown Source)
at org.apache.derby.impl.sql.execute.DeleteResultSet.fireAfterTriggers(Unknown Source)
at org.apache.derby.impl.sql.execute.DeleteResultSet.open(Unknown Source)
at org.apache.derby.impl.sql.GenericPreparedStatement.executeStmt(Unknown Source)
at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(Unknown Source)
at org.apache.derbyTesting.system.nstest.utils.DbUtil.delete_one_row(DbUtil.java:452)
at org.apache.derbyTesting.system.nstest.tester.TesterObject.doIUDOperation(TesterObject.java:175)
at org.apache.derbyTesting.system.nstest.tester.Tester1.startTesting(Tester1.java:118)
at org.apache.derbyTesting.system.nstest.NsTest.run(NsTest.java:551)
Cleanup action completed
New exception raised during cleanup null
java.lang.NullPointerException
at org.apache.derby.impl.sql.compile.CompilerContextImpl.initRequiredPriv(Unknown Source)
at org.apache.derby.impl.sql.compile.CompilerContextImpl.resetContext(Unknown Source)
at org.apache.derby.impl.sql.compile.CompilerContextImpl.cleanupOnError(Unknown Source)
at org.apache.derby.iapi.services.context.ContextManager.cleanupOnError(Unknown Source)
at org.apache.derby.impl.jdbc.TransactionResourceImpl.cleanupOnError(Unknown Source)
at org.apache.derby.impl.jdbc.TransactionResourceImpl.handleException(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedConnection.handleException(Unknown Source)
at org.apache.derby.impl.jdbc.ConnectionChild.handleException(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(Unknown Source)
at org.apache.derbyTesting.system.nstest.utils.DbUtil.delete_one_row(DbUtil.java:452)
at org.apache.derbyTesting.system.nstest.tester.TesterObject.doIUDOperation(TesterObject.java:175)
at org.apache.derbyTesting.system.nstest.tester.Tester1.startTesting(Tester1.java:118)
at org.apache.derbyTesting.system.nstest.NsTest.run(NsTest.java:551)
Tue Sep 13 16:25:12 PDT 2011 Thread[Thread 1,5,main] Equally severe exception raised during cleanup (ignored) null
java.lang.NullPointerException
at org.apache.derby.impl.sql.compile.CompilerContextImpl.initRequiredPriv(Unknown Source)
at org.apache.derby.impl.sql.compile.CompilerContextImpl.resetContext(Unknown Source)
at org.apache.derby.impl.sql.compile.CompilerContextImpl.cleanupOnError(Unknown Source)
at org.apache.derby.iapi.services.context.ContextManager.cleanupOnError(Unknown Source)
at org.apache.derby.impl.jdbc.TransactionResourceImpl.cleanupOnError(Unknown Source)
at org.apache.derby.impl.jdbc.TransactionResourceImpl.handleException(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedConnection.handleException(Unknown Source)
at org.apache.derby.impl.jdbc.ConnectionChild.handleException(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(Unknown Source)
at org.apache.derbyTesting.system.nstest.utils.DbUtil.delete_one_row(DbUtil.java:452)
at org.apache.derbyTesting.system.nstest.tester.TesterObject.doIUDOperation(TesterObject.java:175)
at org.apache.derbyTesting.system.nstest.tester.Tester1.startTesting(Tester1.java:118)
at org.apache.derbyTesting.system.nstest.NsTest.run(NsTest.java:551)
Cleanup action completed

It appears this caused the Tester1 thread to loose the connection:
---------------------
Tester1Thread 1 dbUtil ----> During failure to execute delete stmt, exception thrown was : java.sql.SQLTransactionRollbackException: An internal error was identified by RawStore module.
TObj -->At this point - executing delete_one_row(), exception thrown was : No current connection.
java.sql.SQLNonTransientConnectionException: No current connection.
at org.apache.derby.impl.jdbc.SQLExceptionFactory40.getSQLException(Unknown Source)
at org.apache.derby.impl.jdbc.Util.newEmbedSQLException(Unknown Source)
at org.apache.derby.impl.jdbc.Util.newEmbedSQLException(Unknown Source)
at org.apache.derby.impl.jdbc.Util.noCurrentConnection(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedConnection.checkIfClosed(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedConnection.setupContextStack(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedConnection.prepareStatement(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedConnection.prepareStatement(Unknown Source)
at org.apache.derbyTesting.system.nstest.utils.DbUtil.add_one_row(DbUtil.java:96)
at org.apache.derbyTesting.system.nstest.tester.TesterObject.doIUDOperation(TesterObject.java:148)
at org.apache.derbyTesting.system.nstest.tester.Tester1.startTesting(Tester1.java:118)
at org.apache.derbyTesting.system.nstest.NsTest.run(NsTest.java:551)
Caused by: java.sql.SQLException: No current connection.
at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(Unknown Source)
at org.apache.derby.impl.jdbc.SQLExceptionFactory40.wrapArgsForTransportAcrossDRDA(Unknown Source)
... 12 more
-------------------------------

Issue Links

• is related to: DERBY-5448 In the 10.8 branch, back out the concurrency improvements introduced by using SequenceUpdaters to allocate identity values.
• is related to: DERBY-5495 Master issue to track fixes to sequence generators
• is related to: DERBY-4437 Concurrent inserts into table with identity column perform poorly
• relates to: DERBY-5661 ASSERT failure in nstest; Exception in thread "derby.index-stat-thread" org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED transaction not pristine
• relates to: DERBY-5671 NsTest does not run on trunk do multiple issues stemming from concurrency improvements
• relates to: DERBY-5423 ERROR X0Y84: Too much contention on sequence NSTESTTAB in ns system test