Java Process Crash Causes Corrupt DB
------------------------------------
Key: DERBY-5248
URL: https://issues.apache.org/jira/browse/DERBY-5248
Project: Derby
Issue Type: Bug
Affects Versions: 10.8.1.2
Environment: Red Hat Enterprise Linux ES release 4 (Nahant Update 7)
java version "1.6.0_01"
Java(TM) SE Runtime Environment (build 1.6.0_01-b06)
Java HotSpot(TM) Server VM (build 1.6.0_01-b06, mixed mode)
Derby 10.8.1.2
Reporter: Tim Wu
Fix For: 10.8.1.3
During some crash tests on our product, we hit an issue where after a crash,
the derby db is stuck in a corrupted state. The db fails to boot with the
following error when started up with the debug jar:
org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED incorrect
deleted row count. Should be: 903, instead got: 902, maxSlot = 1255,
recordCount = 1255
at
org.apache.derby.shared.common.sanity.SanityManager.THROWASSERT(SanityManager.java:162)
at
org.apache.derby.shared.common.sanity.SanityManager.THROWASSERT(SanityManager.java:147)
at
org.apache.derby.impl.store.raw.data.BasePage.internalNonDeletedRecordCount(BasePage.java:1432)
at
org.apache.derby.impl.store.raw.data.CachedPage.releaseExclusive(CachedPage.java:488)
at
org.apache.derby.impl.store.raw.data.StoredPage.releaseExclusive(StoredPage.java:1066)
at org.apache.derby.impl.store.raw.data.BasePage.unlatch(BasePage.java:1370)
at
org.apache.derby.impl.store.raw.data.PageBasicOperation.releaseResource(PageBasicOperation.java:195)
at
org.apache.derby.impl.store.raw.data.PhysicalUndoOperation.releaseResource(PhysicalUndoOperation.java:177)
at org.apache.derby.impl.store.raw.log.FileLogger.undo(FileLogger.java:1055)
at org.apache.derby.impl.store.raw.xact.Xact.abort(Xact.java:952)
at
org.apache.derby.impl.store.raw.xact.XactFactory.rollbackAllTransactions(XactFactory.java:547)
at org.apache.derby.impl.store.raw.log.LogToFile.recover(LogToFile.java:1229)
at org.apache.derby.impl.store.raw.RawStore.boot(RawStore.java:339)
at
org.apache.derby.impl.services.monitor.BaseMonitor.boot(BaseMonitor.java:1982)
at
org.apache.derby.impl.services.monitor.TopService.bootModule(TopService.java:334)
at
org.apache.derby.impl.services.monitor.BaseMonitor.startModule(BaseMonitor.java:531)
at
org.apache.derby.iapi.services.monitor.Monitor.bootServiceModule(Monitor.java:427)
at
org.apache.derby.impl.store.access.RAMAccessManager.boot(RAMAccessManager.java:1019)
at
org.apache.derby.impl.services.monitor.BaseMonitor.boot(BaseMonitor.java:1982)
at
org.apache.derby.impl.services.monitor.TopService.bootModule(TopService.java:334)
at
org.apache.derby.impl.services.monitor.BaseMonitor.startModule(BaseMonitor.java:531)
at
org.apache.derby.iapi.services.monitor.Monitor.bootServiceModule(Monitor.java:427)
at org.apache.derby.impl.db.BasicDatabase.bootStore(BasicDatabase.java:749)
at org.apache.derby.impl.db.BasicDatabase.boot(BasicDatabase.java:177)
at
org.apache.derby.impl.services.monitor.BaseMonitor.boot(BaseMonitor.java:1982)
at
org.apache.derby.impl.services.monitor.TopService.bootModule(TopService.java:334)
at
org.apache.derby.impl.services.monitor.BaseMonitor.bootService(BaseMonitor.java:1816)
at
org.apache.derby.impl.services.monitor.BaseMonitor.startProviderService(BaseMonitor.java:1682)
at
org.apache.derby.impl.services.monitor.BaseMonitor.findProviderAndStartService(BaseMonitor.java:1560)
at
org.apache.derby.impl.services.monitor.BaseMonitor.startPersistentService(BaseMonitor.java:979)
at
org.apache.derby.iapi.services.monitor.Monitor.startPersistentService(Monitor.java:550)
at
org.apache.derby.impl.jdbc.EmbedConnection.bootDatabase(EmbedConnection.java:2697)
at org.apache.derby.impl.jdbc.EmbedConnection.<init>(EmbedConnection.java:385)
at
org.apache.derby.impl.jdbc.EmbedConnection30.<init>(EmbedConnection30.java:73)
at
org.apache.derby.impl.jdbc.EmbedConnection40.<init>(EmbedConnection40.java:51)
at org.apache.derby.jdbc.Driver40.getNewEmbedConnection(Driver40.java:70)
at org.apache.derby.jdbc.InternalDriver.connect(InternalDriver.java:248)
at org.apache.derby.jdbc.AutoloadedDriver.connect(AutoloadedDriver.java:144)
at java.sql.DriverManager.getConnection(DriverManager.java:582)
at java.sql.DriverManager.getConnection(DriverManager.java:154)
at OpenDerby.main(OpenDerby.java:17)
---------------
Stack traces for all live threads:
Thread name=main id=1 priority=5 state=RUNNABLE isdaemon=false
java.lang.Thread.dumpThreads(Native Method)
java.lang.Thread.getAllStackTraces(Thread.java:1554)
org.apache.derby.shared.common.sanity.ThreadDump.getStackDumpString(ThreadDump.java:34)
sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
java.lang.reflect.Method.invoke(Method.java:597)
org.apache.derby.shared.common.sanity.AssertFailure$1.run(AssertFailure.java:165)
java.security.AccessController.doPrivileged(Native Method)
org.apache.derby.shared.common.sanity.AssertFailure.dumpThreads(AssertFailure.java:159)
org.apache.derby.shared.common.sanity.AssertFailure.<init>(AssertFailure.java:72)
org.apache.derby.shared.common.sanity.SanityManager.THROWASSERT(SanityManager.java:162)
org.apache.derby.shared.common.sanity.SanityManager.THROWASSERT(SanityManager.java:147)
org.apache.derby.impl.store.raw.data.BasePage.internalNonDeletedRecordCount(BasePage.java:1432)
org.apache.derby.impl.store.raw.data.CachedPage.releaseExclusive(CachedPage.java:488)
org.apache.derby.impl.store.raw.data.StoredPage.releaseExclusive(StoredPage.java:1066)
org.apache.derby.impl.store.raw.data.BasePage.unlatch(BasePage.java:1370)
org.apache.derby.impl.store.raw.data.PageBasicOperation.releaseResource(PageBasicOperation.java:195)
org.apache.derby.impl.store.raw.data.PhysicalUndoOperation.releaseResource(PhysicalUndoOperation.java:177)
org.apache.derby.impl.store.raw.log.FileLogger.undo(FileLogger.java:1055)
org.apache.derby.impl.store.raw.xact.Xact.abort(Xact.java:952)
org.apache.derby.impl.store.raw.xact.XactFactory.rollbackAllTransactions(XactFactory.java:547)
org.apache.derby.impl.store.raw.log.LogToFile.recover(LogToFile.java:1229)
org.apache.derby.impl.store.raw.RawStore.boot(RawStore.java:339)
org.apache.derby.impl.services.monitor.BaseMonitor.boot(BaseMonitor.java:1982)
org.apache.derby.impl.services.monitor.TopService.bootModule(TopService.java:334)
org.apache.derby.impl.services.monitor.BaseMonitor.startModule(BaseMonitor.java:531)
org.apache.derby.iapi.services.monitor.Monitor.bootServiceModule(Monitor.java:427)
org.apache.derby.impl.store.access.RAMAccessManager.boot(RAMAccessManager.java:1019)
org.apache.derby.impl.services.monitor.BaseMonitor.boot(BaseMonitor.java:1982)
org.apache.derby.impl.services.monitor.TopService.bootModule(TopService.java:334)
org.apache.derby.impl.services.monitor.BaseMonitor.startModule(BaseMonitor.java:531)
org.apache.derby.iapi.services.monitor.Monitor.bootServiceModule(Monitor.java:427)
org.apache.derby.impl.db.BasicDatabase.bootStore(BasicDatabase.java:749)
org.apache.derby.impl.db.BasicDatabase.boot(BasicDatabase.java:177)
org.apache.derby.impl.services.monitor.BaseMonitor.boot(BaseMonitor.java:1982)
org.apache.derby.impl.services.monitor.TopService.bootModule(TopService.java:334)
org.apache.derby.impl.services.monitor.BaseMonitor.bootService(BaseMonitor.java:1816)
org.apache.derby.impl.services.monitor.BaseMonitor.startProviderService(BaseMonitor.java:1682)
org.apache.derby.impl.services.monitor.BaseMonitor.findProviderAndStartService(BaseMonitor.java:1560)
org.apache.derby.impl.services.monitor.BaseMonitor.startPersistentService(BaseMonitor.java:979)
org.apache.derby.iapi.services.monitor.Monitor.startPersistentService(Monitor.java:550)
org.apache.derby.impl.jdbc.EmbedConnection.bootDatabase(EmbedConnection.java:2697)
org.apache.derby.impl.jdbc.EmbedConnection.<init>(EmbedConnection.java:385)
org.apache.derby.impl.jdbc.EmbedConnection30.<init>(EmbedConnection30.java:73)
org.apache.derby.impl.jdbc.EmbedConnection40.<init>(EmbedConnection40.java:51)
org.apache.derby.jdbc.Driver40.getNewEmbedConnection(Driver40.java:70)
org.apache.derby.jdbc.InternalDriver.connect(InternalDriver.java:248)
org.apache.derby.jdbc.AutoloadedDriver.connect(AutoloadedDriver.java:144)
java.sql.DriverManager.getConnection(DriverManager.java:582)
java.sql.DriverManager.getConnection(DriverManager.java:154)
OpenDerby.main(OpenDerby.java:17)
Thread name=derby.rawStoreDaemon id=12 priority=5 state=TIMED_WAITING
isdaemon=true
java.lang.Object.wait(Native Method)
org.apache.derby.impl.services.daemon.BasicDaemon.rest(BasicDaemon.java:576)
org.apache.derby.impl.services.daemon.BasicDaemon.run(BasicDaemon.java:390)
java.lang.Thread.run(Thread.java:680)
Thread name=Finalizer id=3 priority=8 state=WAITING isdaemon=true
java.lang.Object.wait(Native Method)
java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)
java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:134)
java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)
Thread name=Reference Handler id=2 priority=10 state=WAITING isdaemon=true
java.lang.Object.wait(Native Method)
java.lang.Object.wait(Object.java:485)
java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
Thread name=Signal Dispatcher id=6 priority=9 state=RUNNABLE isdaemon=true
Thread name=Timer-0 id=10 priority=5 state=WAITING isdaemon=true
java.lang.Object.wait(Native Method)
java.lang.Object.wait(Object.java:485)
java.util.TimerThread.mainLoop(Timer.java:483)
java.util.TimerThread.run(Timer.java:462)
---------------
Exception in thread "main" java.sql.SQLException: Failed to start database
'/Users/tim/Downloads/LinkedBlockingQueueCrashTest/objectdb/datadb' with class
loader sun.misc.Launcher$AppClassLoader@40affc70, see the next exception for
details.
at
org.apache.derby.impl.jdbc.SQLExceptionFactory40.getSQLException(SQLExceptionFactory40.java:98)
at org.apache.derby.impl.jdbc.Util.newEmbedSQLException(Util.java:142)
at org.apache.derby.impl.jdbc.Util.seeNextException(Util.java:278)
at
org.apache.derby.impl.jdbc.EmbedConnection.bootDatabase(EmbedConnection.java:2736)
at org.apache.derby.impl.jdbc.EmbedConnection.<init>(EmbedConnection.java:385)
at
org.apache.derby.impl.jdbc.EmbedConnection30.<init>(EmbedConnection30.java:73)
at
org.apache.derby.impl.jdbc.EmbedConnection40.<init>(EmbedConnection40.java:51)
at org.apache.derby.jdbc.Driver40.getNewEmbedConnection(Driver40.java:70)
at org.apache.derby.jdbc.InternalDriver.connect(InternalDriver.java:248)
at org.apache.derby.jdbc.AutoloadedDriver.connect(AutoloadedDriver.java:144)
at java.sql.DriverManager.getConnection(DriverManager.java:582)
at java.sql.DriverManager.getConnection(DriverManager.java:154)
at OpenDerby.main(OpenDerby.java:17)
Caused by: java.sql.SQLException: Failed to start database
'/Users/tim/Downloads/LinkedBlockingQueueCrashTest/objectdb/datadb' with class
loader sun.misc.Launcher$AppClassLoader@40affc70, see the next exception for
details.
at
org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(SQLExceptionFactory.java:45)
at
org.apache.derby.impl.jdbc.SQLExceptionFactory40.wrapArgsForTransportAcrossDRDA(SQLExceptionFactory40.java:122)
at
org.apache.derby.impl.jdbc.SQLExceptionFactory40.getSQLException(SQLExceptionFactory40.java:71)
... 12 more
Caused by: java.sql.SQLException: Java exception: 'ASSERT FAILED incorrect
deleted row count. Should be: 903, instead got: 902, maxSlot = 1255,
recordCount = 1255: org.apache.derby.shared.common.sanity.AssertFailure'.
at
org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(SQLExceptionFactory.java:45)
at
org.apache.derby.impl.jdbc.SQLExceptionFactory40.wrapArgsForTransportAcrossDRDA(SQLExceptionFactory40.java:122)
at
org.apache.derby.impl.jdbc.SQLExceptionFactory40.getSQLException(SQLExceptionFactory40.java:71)
at org.apache.derby.impl.jdbc.Util.newEmbedSQLException(Util.java:142)
at org.apache.derby.impl.jdbc.Util.javaException(Util.java:299)
at
org.apache.derby.impl.jdbc.EmbedConnection.bootDatabase(EmbedConnection.java:2732)
... 9 more
Caused by: org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED
incorrect deleted row count. Should be: 903, instead got: 902, maxSlot = 1255,
recordCount = 1255
at
org.apache.derby.shared.common.sanity.SanityManager.THROWASSERT(SanityManager.java:162)
at
org.apache.derby.shared.common.sanity.SanityManager.THROWASSERT(SanityManager.java:147)
at
org.apache.derby.impl.store.raw.data.BasePage.internalNonDeletedRecordCount(BasePage.java:1432)
at
org.apache.derby.impl.store.raw.data.CachedPage.releaseExclusive(CachedPage.java:488)
at
org.apache.derby.impl.store.raw.data.StoredPage.releaseExclusive(StoredPage.java:1066)
at org.apache.derby.impl.store.raw.data.BasePage.unlatch(BasePage.java:1370)
at
org.apache.derby.impl.store.raw.data.PageBasicOperation.releaseResource(PageBasicOperation.java:195)
at
org.apache.derby.impl.store.raw.data.PhysicalUndoOperation.releaseResource(PhysicalUndoOperation.java:177)
at org.apache.derby.impl.store.raw.log.FileLogger.undo(FileLogger.java:1055)
at org.apache.derby.impl.store.raw.xact.Xact.abort(Xact.java:952)
at
org.apache.derby.impl.store.raw.xact.XactFactory.rollbackAllTransactions(XactFactory.java:547)
at org.apache.derby.impl.store.raw.log.LogToFile.recover(LogToFile.java:1229)
at org.apache.derby.impl.store.raw.RawStore.boot(RawStore.java:339)
at
org.apache.derby.impl.services.monitor.BaseMonitor.boot(BaseMonitor.java:1982)
at
org.apache.derby.impl.services.monitor.TopService.bootModule(TopService.java:334)
at
org.apache.derby.impl.services.monitor.BaseMonitor.startModule(BaseMonitor.java:531)
at
org.apache.derby.iapi.services.monitor.Monitor.bootServiceModule(Monitor.java:427)
at
org.apache.derby.impl.store.access.RAMAccessManager.boot(RAMAccessManager.java:1019)
at
org.apache.derby.impl.services.monitor.BaseMonitor.boot(BaseMonitor.java:1982)
at
org.apache.derby.impl.services.monitor.TopService.bootModule(TopService.java:334)
at
org.apache.derby.impl.services.monitor.BaseMonitor.startModule(BaseMonitor.java:531)
at
org.apache.derby.iapi.services.monitor.Monitor.bootServiceModule(Monitor.java:427)
at org.apache.derby.impl.db.BasicDatabase.bootStore(BasicDatabase.java:749)
at org.apache.derby.impl.db.BasicDatabase.boot(BasicDatabase.java:177)
at
org.apache.derby.impl.services.monitor.BaseMonitor.boot(BaseMonitor.java:1982)
at
org.apache.derby.impl.services.monitor.TopService.bootModule(TopService.java:334)
at
org.apache.derby.impl.services.monitor.BaseMonitor.bootService(BaseMonitor.java:1816)
at
org.apache.derby.impl.services.monitor.BaseMonitor.startProviderService(BaseMonitor.java:1682)
at
org.apache.derby.impl.services.monitor.BaseMonitor.findProviderAndStartService(BaseMonitor.java:1560)
at
org.apache.derby.impl.services.monitor.BaseMonitor.startPersistentService(BaseMonitor.java:979)
at
org.apache.derby.iapi.services.monitor.Monitor.startPersistentService(Monitor.java:550)
at
org.apache.derby.impl.jdbc.EmbedConnection.bootDatabase(EmbedConnection.java:2697)
... 9 more
It also fails with a slightly different error using the non-debug jar:
Exception in thread "main" java.sql.SQLException: Failed to start database
'/Users/tim/Downloads/LinkedBlockingQueueCrashTest/objectdb/datadb' with class
loader sun.misc.Launcher$AppClassLoader@40affc70, see the next exception for
details.
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.seeNextException(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedConnection.bootDatabase(Unknown
Source)
at org.apache.derby.impl.jdbc.EmbedConnection.<init>(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedConnection30.<init>(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedConnection40.<init>(Unknown Source)
at org.apache.derby.jdbc.Driver40.getNewEmbedConnection(Unknown Source)
at org.apache.derby.jdbc.InternalDriver.connect(Unknown Source)
at org.apache.derby.jdbc.AutoloadedDriver.connect(Unknown Source)
at java.sql.DriverManager.getConnection(DriverManager.java:582)
at java.sql.DriverManager.getConnection(DriverManager.java:154)
at OpenDerby.main(OpenDerby.java:16)
Caused by: java.sql.SQLException: Failed to start database
'/Users/tim/Downloads/LinkedBlockingQueueCrashTest/objectdb/datadb' with class
loader sun.misc.Launcher$AppClassLoader@40affc70, see the next exception for
details.
at
org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(Unknown Source)
at
org.apache.derby.impl.jdbc.SQLExceptionFactory40.wrapArgsForTransportAcrossDRDA(Unknown
Source)
... 13 more
Caused by: java.sql.SQLException: An exception was thrown during transaction
abort.
at
org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(Unknown Source)
at
org.apache.derby.impl.jdbc.SQLExceptionFactory40.wrapArgsForTransportAcrossDRDA(Unknown
Source)
at
org.apache.derby.impl.jdbc.SQLExceptionFactory40.getSQLException(Unknown Source)
at org.apache.derby.impl.jdbc.Util.generateCsSQLException(Unknown
Source)
... 10 more
Caused by: 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.raw.xact.XactFactory.rollbackAllTransactions(Unknown
Source)
at org.apache.derby.impl.store.raw.log.LogToFile.recover(Unknown Source)
at org.apache.derby.impl.store.raw.RawStore.boot(Unknown Source)
at org.apache.derby.impl.services.monitor.BaseMonitor.boot(Unknown
Source)
at org.apache.derby.impl.services.monitor.TopService.bootModule(Unknown
Source)
at
org.apache.derby.impl.services.monitor.BaseMonitor.startModule(Unknown Source)
at
org.apache.derby.iapi.services.monitor.Monitor.bootServiceModule(Unknown Source)
at org.apache.derby.impl.store.access.RAMAccessManager.boot(Unknown
Source)
at org.apache.derby.impl.services.monitor.BaseMonitor.boot(Unknown
Source)
at org.apache.derby.impl.services.monitor.TopService.bootModule(Unknown
Source)
at
org.apache.derby.impl.services.monitor.BaseMonitor.startModule(Unknown Source)
at
org.apache.derby.iapi.services.monitor.Monitor.bootServiceModule(Unknown Source)
at org.apache.derby.impl.db.BasicDatabase.bootStore(Unknown Source)
at org.apache.derby.impl.db.BasicDatabase.boot(Unknown Source)
at org.apache.derby.impl.services.monitor.BaseMonitor.boot(Unknown
Source)
at org.apache.derby.impl.services.monitor.TopService.bootModule(Unknown
Source)
at
org.apache.derby.impl.services.monitor.BaseMonitor.bootService(Unknown Source)
at
org.apache.derby.impl.services.monitor.BaseMonitor.startProviderService(Unknown
Source)
at
org.apache.derby.impl.services.monitor.BaseMonitor.findProviderAndStartService(Unknown
Source)
at
org.apache.derby.impl.services.monitor.BaseMonitor.startPersistentService(Unknown
Source)
at
org.apache.derby.iapi.services.monitor.Monitor.startPersistentService(Unknown
Source)
... 10 more
Caused by: ERROR XSLA8: Cannot rollback transaction 10946, 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)
... 32 more
Caused by: ERROR XSLA1: Log Record has been sent to the stream, but it cannot
be applied to the store (Object null). This may cause recovery problems also.
at org.apache.derby.iapi.error.StandardException.newException(Unknown
Source)
at org.apache.derby.impl.store.raw.log.FileLogger.logAndUndo(Unknown
Source)
at org.apache.derby.impl.store.raw.xact.Xact.logAndUndo(Unknown Source)
... 33 more
Caused by: ERROR XSDB0: Unexpected exception on in-memory page
Page(1,Container(0, 1409))
at org.apache.derby.iapi.error.StandardException.newException(Unknown
Source)
at
org.apache.derby.impl.store.raw.data.StoredPage.storeRecordForInsert(Unknown
Source)
at org.apache.derby.impl.store.raw.data.StoredPage.storeRecord(Unknown
Source)
at org.apache.derby.impl.store.raw.data.PurgeOperation.undoMe(Unknown
Source)
at
org.apache.derby.impl.store.raw.data.PhysicalUndoOperation.doMe(Unknown Source)
... 35 more
I have the zipped up db that causes the problem. Will attach it to this bug
report.
--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira
