Return-Path: X-Original-To: apmail-db-derby-dev-archive@www.apache.org Delivered-To: apmail-db-derby-dev-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id 5030560EE for ; Wed, 1 Jun 2011 18:44:30 +0000 (UTC) Received: (qmail 61835 invoked by uid 500); 1 Jun 2011 18:44:30 -0000 Delivered-To: apmail-db-derby-dev-archive@db.apache.org Received: (qmail 61808 invoked by uid 500); 1 Jun 2011 18:44:30 -0000 Mailing-List: contact derby-dev-help@db.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: Delivered-To: mailing list derby-dev@db.apache.org Received: (qmail 61800 invoked by uid 99); 1 Jun 2011 18:44:30 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 01 Jun 2011 18:44:30 +0000 X-ASF-Spam-Status: No, hits=-2000.0 required=5.0 tests=ALL_TRUSTED,T_RP_MATCHES_RCVD X-Spam-Check-By: apache.org Received: from [140.211.11.116] (HELO hel.zones.apache.org) (140.211.11.116) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 01 Jun 2011 18:44:27 +0000 Received: from hel.zones.apache.org (hel.zones.apache.org [140.211.11.116]) by hel.zones.apache.org (Postfix) with ESMTP id C2045EE44A for ; Wed, 1 Jun 2011 18:43:47 +0000 (UTC) Date: Wed, 1 Jun 2011 18:43:47 +0000 (UTC) From: "Mike Matrigali (JIRA)" To: derby-dev@db.apache.org Message-ID: <266739582.60618.1306953827791.JavaMail.tomcat@hel.zones.apache.org> In-Reply-To: <1659807883.47108.1306451867471.JavaMail.tomcat@hel.zones.apache.org> Subject: [jira] [Issue Comment Edited] (DERBY-5248) Java Process Crash Causes Corrupt DB MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 [ https://issues.apache.org/jira/browse/DERBY-5248?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13042354#comment-13042354 ] Mike Matrigali edited comment on DERBY-5248 at 6/1/11 6:42 PM: --------------------------------------------------------------- After pouring through the log records and what runs during recovery I have found at the following problem. The problem occurs while backing a purge on a btree. The normal place for this to happen would be by the background daemon doing post commit work, although this work can fall back on the actual user thread for various reasons. I can't tell from what I have exactly where the purges came from. I do know the purges are space reclamation and not splits because they are all one row at a time. The actual problem is proper undo requires that the system always insure that there will be enough space to do the undo. In this case there is not enough space and the application of the undo actually trashes the page by the data of the row which grows from the front of page backward overwriting the slot table which grows from the back of the page toward the top. The problem set of log records is evident from the last few records in the log: ... many records leading to the end 10946 : Page Op: Page(1,C(0, 1409)) pv 27734 : Purge : 1 slots 1 (recordId=8038) instant = (1,30696447) logEnd = (1,30696511) 10944 : Page Op: Page(1,C(0, 1409)) pv 27735 : Insert : Slot=352 recordId=9452 instant = (1,30696511) logEnd = (1,30696580) 10944 : Page Op: Page(2,C(0, 1168)) pv 6403 : Update Slot=5 recordId=11 instant = (1,30696580) logEnd = (1,30696713) 10944 : EndXact null Committed : transactionStatus = Committed instant = (1,30696713) logEnd = (1,30696746) DEBUG LogTrace OUTPUT: detected zapped log end on log file 1 end marker at 30696746 real end at 134217728^M DEBUG LogTrace OUTPUT: C:\tmp\_t\objectdb\log\log2.dat does not exist^M The problem is that transaction 10946 purges a row from page 1 which actually removes the bytes from the page and then before that transaction commits and or aborts transaction 10944 inserts a row on page 1 and commits. There never is an abort or commit in the log for the purge indicating that the test crash happened before the commit could be made. Because undo always requires space be available purges should always be committed/aborted before allowing any other access to page. Note the heap code does this correctly by not releasing the latch explicitly but instead leaving it latched and letting commit unlatch it with the following code segment, it may be a little harder in btree due to the datastructures: // If no purge happened on the page and the page is not // removed, feel free to unlatch it. Otherwise, let // transaction commit take care of it. if (!purgingDone) { page.unlatch(); page = null; } By code inspection I looked at btree post commit and there is a problem there which I logged as DERBY-5258. I have been trying to reproduce this with a real system but have not been able to so far. The "distance" from the time the latch on page1 is released by the purge and the commit happens is only a few instructions so I was surprised that it could be made to happen. I did note however that for the bug to happen as we see in this database we don't need the crash to happen exactly in these few instructions, only that another thread gets the latch on the page and does an insert on the page before the commit. This is because the internal transaction does a "no sync" commit for performance reasons, which only puts the log record into the buffer. A crash anytime before that buffer is written to disk by filling or by a real commit would leave the db in the state that it is. Some things that may be making this application more likely to hit this are: o the btree index row is small so there are a lot of rows on page 1 of the index o there seems to be a LOT of inserts and deletes on page 1 of the index o The application has set a very large log buffer size - I didn't even know people were playing with this tuning option was (Author: mikem): After pouring through the log records and what runs during recovery I have found at the following problem. The problem occurs while backing a purge on a btree. The normal place for this to happen would be by the background daemon doing post commit work, although this work can fall back on the actual user thread for various reasons. I can't tell from what I have exactly where the purges came from. I do know the purges are space reclamation and not splits because they are all one row at a time. The actual problem is proper undo requires that the system always insure that there will be enough space to do the undo. In this case there is not enough space and the application of the undo actually trashes the page by the data of the row which grows from the front of page backward overwriting the slot table which grows from the back of the page toward the top. The problem set of log records is evident from the last few records in the log: ... many records leading to the end 10946 : Page Op: Page(1,C(0, 1409)) pv 27734 : Purge : 1 slots 1 (recordId=8038) instant = (1,30696447) logEnd = (1,30696511) 10944 : Page Op: Page(1,C(0, 1409)) pv 27735 : Insert : Slot=352 recordId=9452 instant = (1,30696511) logEnd = (1,30696580) 10944 : Page Op: Page(2,C(0, 1168)) pv 6403 : Update Slot=5 recordId=11 instant = (1,30696580) logEnd = (1,30696713) 10944 : EndXact null Committed : transactionStatus = Committed instant = (1,30696713) logEnd = (1,30696746) DEBUG LogTrace OUTPUT: detected zapped log end on log file 1 end marker at 30696746 real end at 134217728^M DEBUG LogTrace OUTPUT: C:\tmp\_t\objectdb\log\log2.dat does not exist^M The problem is that transaction 10946 purges a row from page 1 which actually removes the bytes from the page and then before that transaction commits and or aborts transaction 10944 inserts a row on page 1 and commits. There never is an abort or commit in the log for the purge indicating that the test crash happened before the commit could be made. Because undo always requires space be available purges should always be committed/aborted before allowing any other access to page. Note the heap code does this correctly by not releasing the latch explicitly but instead leaving it latched and letting commit unlatch it with the following code segment, it may be a little harder in btree due to the datastructures: // If no purge happened on the page and the page is not // removed, feel free to unlatch it. Otherwise, let // transaction commit take care of it. if (!purgingDone) { page.unlatch(); page = null; } By code inspection I looked at btree post commit and there is a problem there which I logged as DERBY-5358. I have been trying to reproduce this with a real system but have not been able to so far. The "distance" from the time the latch on page1 is released by the purge and the commit happens is only a few instructions so I was surprised that it could be made to happen. I did note however that for the bug to happen as we see in this database we don't need the crash to happen exactly in these few instructions, only that another thread gets the latch on the page and does an insert on the page before the commit. This is because the internal transaction does a "no sync" commit for performance reasons, which only puts the log record into the buffer. A crash anytime before that buffer is written to disk by filling or by a real commit would leave the db in the state that it is. Some things that may be making this application more likely to hit this are: o the btree index row is small so there are a lot of rows on page 1 of the index o there seems to be a LOT of inserts and deletes on page 1 of the index o The application has set a very large log buffer size - I didn't even know people were playing with this tuning option > Java Process Crash Causes Corrupt DB > ------------------------------------ > > Key: DERBY-5248 > URL: https://issues.apache.org/jira/browse/DERBY-5248 > Project: Derby > Issue Type: Bug > Components: Store > 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 > > Attachments: c581.dat.xml.gz, ij_recovery_log_trace.log.gz, log.ctrl.xml, log1.dat.xml.gz, objectdb.zip > > > 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.(EmbedConnection.java:385) > at org.apache.derby.impl.jdbc.EmbedConnection30.(EmbedConnection30.java:73) > at org.apache.derby.impl.jdbc.EmbedConnection40.(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.(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.(EmbedConnection.java:385) > org.apache.derby.impl.jdbc.EmbedConnection30.(EmbedConnection30.java:73) > org.apache.derby.impl.jdbc.EmbedConnection40.(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.(EmbedConnection.java:385) > at org.apache.derby.impl.jdbc.EmbedConnection30.(EmbedConnection30.java:73) > at org.apache.derby.impl.jdbc.EmbedConnection40.(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.(Unknown Source) > at org.apache.derby.impl.jdbc.EmbedConnection30.(Unknown Source) > at org.apache.derby.impl.jdbc.EmbedConnection40.(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