db-derby-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Rajesh Kartha <karth...@gmail.com>
Subject Database shutdown during transaction abort/rollback (after deadlock detection)
Date Thu, 07 Sep 2006 22:29:23 GMT
Hello,

I have been running some tests (long running)  against the 10.2 beta and 
in the recent runs saw an error where the
database was shutdown due to some severe error while aborting a 
transaction/roll back after a deadlock detection.

Little background:
---------------------
The test uses Derby client to connect to an encrypted database single 
table with 18 columns of varying data types,
with a trigger to fire an insert into another table of the same schema 
after every delete.
70 user threads + 1 backup/restore/re-encrypt thread are spawned off  to 
perform the operations. The user threads
does mainly SELECT and IUD operations with queries like the following:
Example:
select max(serialkey) from nstesttab where serialkey > ?
update nstesttab set t_real = ?  where serialkey = <random value>
delete from nstesttab where serialkey = ?
...
The test uses default settings and the user threads are expected to get 
timeouts (or deadlocks is some cases).

While the backup/restore/re-encrypt thread wakes up every 10 mins to 
perform the work of 1) an online-backup 2) perform
consistency checks 3) restore a new db from the backup 4)  re-encrypt 
the restored database with a new bootPassword.

The issue that I have seen twice, after an 10-12 hr run,  happens while 
attempting to abort a transaction/roll back
once a deadlock occurred and one of the victim was chosen.  In the 
current case the deadlock trace indicates the
victim chosen has an Xn id of  1046938578, but there is no operation 
associated to that  - ?

*  Waiting XID : {1046938578, 
org.apache.derby.impl.store.raw.data.BaseContainerHandle@4b184b18} , 
NSTEST, ?*

Anways, once this error occurs the database is no longer available.

At this moment it is not clear what may be causing this, will begin by 
logging a JIRA for now to track this.  Meanwhile I will try to
reproduce this as a smaller test case, using a sane build and verify 
this does not happen on 10.1.3 (without the online/re-encrypt thread).

If anyone has any suggestions/insights please do reply.

-Rajesh

Attached is the derby.log file during one of the runs. Here is snippet 
of the errors from the derby.log file:

------------  BEGIN SHUTDOWN ERROR STACK -------------

ERROR XSLA8: Cannot rollback transaction 1046938578, trying to 
compensate null operation with null
    at 
org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
    at org.apache.derby.impl.store.raw.log.FileLogger.undo(Unknown Source)
    at org.apache.derby.impl.store.raw.xact.Xact.abort(Unknown Source)
    at org.apache.derby.impl.store.access.RAMTransaction.abort(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.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.execute(Unknown 
Source)
    at org.apache.derby.impl.drda.DRDAStatement.execute(Unknown Source)
    at 
org.apache.derby.impl.drda.DRDAConnThread.parseEXCSQLSTTobjects(Unknown 
Source)
    at org.apache.derby.impl.drda.DRDAConnThread.parseEXCSQLSTT(Unknown 
Source)
    at org.apache.derby.impl.drda.DRDAConnThread.processCommands(Unknown 
Source)
    at org.apache.derby.impl.drda.DRDAConnThread.run(Unknown Source)
============= begin nested exception, level (1) ===========
ERROR 40001: A lock could not be obtained due to a deadlock, cycle of 
locks and waiters is:
Lock : LATCH, NSTESTTAB, Page(1,Container(0, 977))
  Waiting XID : {1046938578, 
org.apache.derby.impl.store.raw.data.BaseContainerHandle@4b184b18} , 
NSTEST, ?
  Granted XID : {1046938887, 
org.apache.derby.impl.store.raw.data.BaseContainerHandle@67ec67ec}
Lock : LATCH, NSTESTTAB, Page(463,Container(0, 977))
  Waiting XID : {1046938887, 
org.apache.derby.impl.store.raw.data.BaseContainerHandle@67ec67ec} , 
NSTEST, select max(serialkey) from nstesttab where serialkey > ?
  Granted XID : {1046938880, 
org.apache.derby.impl.store.raw.data.BaseContainerHandle@669a669a}
Lock : LATCH, NSTESTTAB, Page(518,Container(0, 977))
  Waiting XID : {1046938880, 
org.apache.derby.impl.store.raw.data.BaseContainerHandle@669a669a} , 
NSTEST, select max(serialkey) from nstesttab where serialkey > ?
  Granted XID : {1046938862, 
org.apache.derby.impl.store.raw.data.BaseContainerHandle@59ec59ec}
Lock : LATCH, NSTESTTAB, Page(519,Container(0, 977))
  Waiting XID : {1046938862, 
org.apache.derby.impl.store.raw.data.BaseContainerHandle@59ec59ec} , 
NSTEST, select max(serialkey) from nstesttab where serialkey > ?
  Granted XID : {1046938858, 
org.apache.derby.impl.store.raw.data.BaseContainerHandle@580a580a}
Lock : ROW, NSTESTTAB, (520,1)
  Waiting XID : {1046938858, S} , NSTEST, select max(serialkey) from 
nstesttab where serialkey > ?
  Granted XID : {1046938636, S}
Lock : ROW, NSTESTTAB, (1346,45)
  Waiting XID : {1046938636, X} , NSTEST, update nstesttab set t_int = 
?  where serialkey = 82706
  Granted XID : {1046938578, X}
. The selected victim is XID : 1046938578.
    at 
org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
    at 
org.apache.derby.impl.services.locks.Deadlock.buildException(Unknown Source)
    at org.apache.derby.impl.services.locks.LockSet.lockObject(Unknown 
Source)
    at 
org.apache.derby.impl.services.locks.SinglePool.latchObject(Unknown Source)
    at 
org.apache.derby.impl.store.raw.data.BasePage.setExclusive(Unknown Source)
    at 
org.apache.derby.impl.store.raw.data.BaseContainer.latchPage(Unknown Source)
    at 
org.apache.derby.impl.store.raw.data.FileContainer.latchPage(Unknown Source)
    at 
org.apache.derby.impl.store.raw.data.FileContainer.getUserPage(Unknown 
Source)
    at 
org.apache.derby.impl.store.raw.data.FileContainer.getPage(Unknown Source)
    at 
org.apache.derby.impl.store.raw.data.BaseContainerHandle.getPage(Unknown 
Source)
    at org.apache.derby.impl.store.access.btree.ControlRow.Get(Unknown 
Source)
    at 
org.apache.derby.impl.store.access.btree.index.B2IUndo.findUndo(Unknown 
Source)
    at 
org.apache.derby.impl.store.raw.data.LogicalPageOperation.findLogicalPage(Unknown 
Source)
    at 
org.apache.derby.impl.store.raw.data.LogicalPageOperation.generateUndo(Unknown 
Source)
    at org.apache.derby.impl.store.raw.log.FileLogger.undo(Unknown Source)
    at org.apache.derby.impl.store.raw.xact.Xact.abort(Unknown Source)
    at org.apache.derby.impl.store.access.RAMTransaction.abort(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.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.execute(Unknown 
Source)
    at org.apache.derby.impl.drda.DRDAStatement.execute(Unknown Source)
    at 
org.apache.derby.impl.drda.DRDAConnThread.parseEXCSQLSTTobjects(Unknown 
Source)
    at org.apache.derby.impl.drda.DRDAConnThread.parseEXCSQLSTT(Unknown 
Source)
    at org.apache.derby.impl.drda.DRDAConnThread.processCommands(Unknown 
Source)
    at org.apache.derby.impl.drda.DRDAConnThread.run(Unknown Source)
============= end nested exception, level (1) ===========


------------  END SHUTDOWN ERROR STACK -------------

New exception raised during cleanup An exception was thrown during 
transaction abort.
ERROR XSTB0: An exception was thrown during transaction abort.
    at 
org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
    at org.apache.derby.impl.store.raw.xact.Xact.abort(Unknown Source)
    at org.apache.derby.impl.store.access.RAMTransaction.abort(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.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.execute(Unknown 
Source)
    at org.apache.derby.impl.drda.DRDAStatement.execute(Unknown Source)
    at 
org.apache.derby.impl.drda.DRDAConnThread.parseEXCSQLSTTobjects(Unknown 
Source)
    at org.apache.derby.impl.drda.DRDAConnThread.parseEXCSQLSTT(Unknown 
Source)
    at org.apache.derby.impl.drda.DRDAConnThread.processCommands(Unknown 
Source)
    at org.apache.derby.impl.drda.DRDAConnThread.run(Unknown Source)
============= begin nested exception, level (1) ===========
ERROR XSLA8: Cannot rollback transaction 1046938578, trying to 
compensate null operation with null
    at 
org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
    at org.apache.derby.impl.store.raw.log.FileLogger.undo(Unknown Source)
    at org.apache.derby.impl.store.raw.xact.Xact.abort(Unknown Source)
    at org.apache.derby.impl.store.access.RAMTransaction.abort(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.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.execute(Unknown 
Source)
    at org.apache.derby.impl.drda.DRDAStatement.execute(Unknown Source)
    at 
org.apache.derby.impl.drda.DRDAConnThread.parseEXCSQLSTTobjects(Unknown 
Source)
    at org.apache.derby.impl.drda.DRDAConnThread.parseEXCSQLSTT(Unknown 
Source)
    at org.apache.derby.impl.drda.DRDAConnThread.processCommands(Unknown 
Source)
    at org.apache.derby.impl.drda.DRDAConnThread.run(Unknown Source)
============= end nested exception, level (1) ===========
============= begin nested exception, level (2) ===========
ERROR 40001: A lock could not be obtained due to a deadlock, cycle of 
locks and waiters is:
Lock : LATCH, NSTESTTAB, Page(1,Container(0, 977))
  Waiting XID : {1046938578, 
org.apache.derby.impl.store.raw.data.BaseContainerHandle@4b184b18} , 
NSTEST, ?
  Granted XID : {1046938887, 
org.apache.derby.impl.store.raw.data.BaseContainerHandle@67ec67ec}
Lock : LATCH, NSTESTTAB, Page(463,Container(0, 977))
  Waiting XID : {1046938887, 
org.apache.derby.impl.store.raw.data.BaseContainerHandle@67ec67ec} , 
NSTEST, select max(serialkey) from nstesttab where serialkey > ?
  Granted XID : {1046938880, 
org.apache.derby.impl.store.raw.data.BaseContainerHandle@669a669a}
Lock : LATCH, NSTESTTAB, Page(518,Container(0, 977))
  Waiting XID : {1046938880, 
org.apache.derby.impl.store.raw.data.BaseContainerHandle@669a669a} , 
NSTEST, select max(serialkey) from nstesttab where serialkey > ?
  Granted XID : {1046938862, 
org.apache.derby.impl.store.raw.data.BaseContainerHandle@59ec59ec}
Lock : LATCH, NSTESTTAB, Page(519,Container(0, 977))
  Waiting XID : {1046938862, 
org.apache.derby.impl.store.raw.data.BaseContainerHandle@59ec59ec} , 
NSTEST, select max(serialkey) from nstesttab where serialkey > ?
  Granted XID : {1046938858, 
org.apache.derby.impl.store.raw.data.BaseContainerHandle@580a580a}
Lock : ROW, NSTESTTAB, (520,1)
  Waiting XID : {1046938858, S} , NSTEST, select max(serialkey) from 
nstesttab where serialkey > ?
  Granted XID : {1046938636, S}
Lock : ROW, NSTESTTAB, (1346,45)
  Waiting XID : {1046938636, X} , NSTEST, update nstesttab set t_int = 
?  where serialkey = 82706
  Granted XID : {1046938578, X}
. The selected victim is XID : 1046938578.
    at 
org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
    at 
org.apache.derby.impl.services.locks.Deadlock.buildException(Unknown Source)
    at org.apache.derby.impl.services.locks.LockSet.lockObject(Unknown 
Source)
    at 
org.apache.derby.impl.services.locks.SinglePool.latchObject(Unknown Source)
    at 
org.apache.derby.impl.store.raw.data.BasePage.setExclusive(Unknown Source)
    at 
org.apache.derby.impl.store.raw.data.BaseContainer.latchPage(Unknown Source)
    at 
org.apache.derby.impl.store.raw.data.FileContainer.latchPage(Unknown Source)
    at 
org.apache.derby.impl.store.raw.data.FileContainer.getUserPage(Unknown 
Source)
    at 
org.apache.derby.impl.store.raw.data.FileContainer.getPage(Unknown Source)
    at 
org.apache.derby.impl.store.raw.data.BaseContainerHandle.getPage(Unknown 
Source)
    at org.apache.derby.impl.store.access.btree.ControlRow.Get(Unknown 
Source)
    at 
org.apache.derby.impl.store.access.btree.index.B2IUndo.findUndo(Unknown 
Source)
    at 
org.apache.derby.impl.store.raw.data.LogicalPageOperation.findLogicalPage(Unknown 
Source)
    at 
org.apache.derby.impl.store.raw.data.LogicalPageOperation.generateUndo(Unknown 
Source)
    at org.apache.derby.impl.store.raw.log.FileLogger.undo(Unknown Source)
    at org.apache.derby.impl.store.raw.xact.Xact.abort(Unknown Source)
    at org.apache.derby.impl.store.access.RAMTransaction.abort(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.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.execute(Unknown 
Source)
    at org.apache.derby.impl.drda.DRDAStatement.execute(Unknown Source)
    at 
org.apache.derby.impl.drda.DRDAConnThread.parseEXCSQLSTTobjects(Unknown 
Source)
    at org.apache.derby.impl.drda.DRDAConnThread.parseEXCSQLSTT(Unknown 
Source)
    at org.apache.derby.impl.drda.DRDAConnThread.processCommands(Unknown 
Source)
    at org.apache.derby.impl.drda.DRDAConnThread.run(Unknown Source)
============= end nested exception, level (2) ===========
2006-09-07 14:31:24.325 GMT Thread[DRDAConnThread_16,5,main] Shutting 
down due to severe error.An exception was thrown during transaction abort.
New exception raised during cleanup An exception was thrown during 
transaction abort.
New exception raised during cleanup An exception was thrown during 
transaction abort.
ERROR XSTB0: An exception was thrown during transaction abort.
    at 
org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
    at org.apache.derby.impl.store.raw.xact.Xact.abort(Unknown Source)
    at org.apache.derby.impl.store.access.RAMTransaction.abort(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.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.execute(Unknown 
Source)
    at org.apache.derby.impl.drda.DRDAStatement.execute(Unknown Source)
    at 
org.apache.derby.impl.drda.DRDAConnThread.parseEXCSQLSTTobjects(Unknown 
Source)
    at org.apache.derby.impl.drda.DRDAConnThread.parseEXCSQLSTT(Unknown 
Source)
    at org.apache.derby.impl.drda.DRDAConnThread.processCommands(Unknown 
Source)
    at org.apache.derby.impl.drda.DRDAConnThread.run(Unknown Source)


Mime
View raw message