db-derby-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Mike Matrigali (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (DERBY-5281) Derby DB Corrupt After Crash
Date Thu, 16 Jun 2011 21:52:47 GMT

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

Mike Matrigali commented on DERBY-5281:
---------------------------------------

Below is a small exerpt from fulllogrecorddump.log.
It shows that:
    transaction 2989 does a number of purges to page 1 of container 1409.
    transaction 2993 does a subsequent insert to same page with no commit/abort from 2989
    transaction 2992 does a subsequent insert and commit to same page with no commit/abort
from 2989

This is the scenario that the fix for DERBY-5258 tried to address.


... lots of log records before this
DEBUG LogTrace OUTPUT: scanned 2989 : Page Operation: Page(1,Container(0, 1409)) pageVersion
5753 : Purge : 1 slots starting at 2 (recordId=665) insta
nt = (1,3364851) logEnd = (1,3364912) logIn at 22 available 23^M
DEBUG LogTrace OUTPUT: scanned 2989 : Page Operation: Page(1,Container(0, 1409)) pageVersion
5754 : Purge : 1 slots starting at 1 (recordId=664) insta
nt = (1,3364912) logEnd = (1,3364973) logIn at 22 available 23^M
DEBUG LogTrace OUTPUT: scanned 2993 : Page Operation: Page(1,Container(0, 1409)) pageVersion
5755 : Insert :  Slot=336 recordId=2149 instant = (1,3364
973) logEnd = (1,3365040) logIn at 25 available 26^M
DEBUG LogTrace OUTPUT: scanned 2992 : Page Operation: Page(1,Container(0, 1409)) pageVersion
5756 : Insert :  Slot=336 recordId=2150 instant = (1,3365
040) logEnd = (1,3365107) logIn at 25 available 26^M
DEBUG LogTrace OUTPUT: scanned 2992 : Page Operation: Page(13,Container(0, 1168)) pageVersion
650 : Update  Slot=11 recordId=17 instant = (1,3365107)
logEnd = (1,3365276) logIn at 20 available 133^M
DEBUG LogTrace OUTPUT: scanned 2992 : Page Operation: Page(13,Container(0, 1168)) pageVersion
651 : Update  Slot=14 recordId=20 instant = (1,3365276)
logEnd = (1,3365836) logIn at 20 available 524^M
DEBUG LogTrace OUTPUT: scanned 2992 : EndXact null Committed : transactionStatus =  Committed
instant = (1,3365836) logEnd = (1,3365869) logIn at 13 a
vailable 4^M
... this is last log record, thus where the log on disk was when the crash happened.


>From the sane attempt to boot we get the following.  The internal checks notice after
the insert that a problem exists on the page.
The problem is that allowing inserts onto the page after the purges are committed or aborted
may lead to page corruption.  The inserts
take up space on the page that abort of the purges need.  When the purges are undone, they
can overwrite other rows or row headers leading
to a number of different boot problems that may each create a different error when booting
for the same underlying cause.

> Derby DB Corrupt After Crash
> ----------------------------
>
>                 Key: DERBY-5281
>                 URL: https://issues.apache.org/jira/browse/DERBY-5281
>             Project: Derby
>          Issue Type: Bug
>          Components: Store
>    Affects Versions: 10.8.1.2
>         Environment: Rhel 4u7
> 2ghz x 2 CPU
> 2gb RAM
> WARN     java.runtime.name                       : Java(TM) SE Runtime Environment
> WARN     java.runtime.version                    : 1.6.0_24-b07
> WARN     java.specification.name                 : Java Platform API Specification
> WARN     java.specification.vendor               : Sun Microsystems Inc.
> WARN     java.specification.version              : 1.6
> WARN     java.vendor                             : Sun Microsystems Inc.
> WARN     java.vendor.url                         : http://java.sun.com/
> WARN     java.vendor.url.bug                     : http://java.sun.com/cgi-bin/bugreport.cgi
> WARN     java.version                            : 1.6.0_24
> WARN     java.vm.info                            : mixed mode
> WARN     java.vm.name                            : Java HotSpot(TM) Server VM
> WARN     java.vm.specification.name              : Java Virtual Machine Specification
> WARN     java.vm.specification.vendor            : Sun Microsystems Inc.
> WARN     java.vm.specification.version           : 1.0
> WARN     java.vm.vendor                          : Sun Microsystems Inc.
> WARN     java.vm.version                         : 19.1-b02
> WARN     line.separator                          : 
> WARN     
> WARN     linked-java-process-max-runtime         : 1980
> WARN     os.arch                                 : i386
> WARN     os.name                                 : Linux
> WARN     os.version                              : 2.6.9-78.0.13.ELsmp
> Derby 10.8.1.2 + fix for DERBY-5258 (r1133470)
>            Reporter: Tim Wu
>            Priority: Critical
>             Fix For: 10.8.1.2
>
>         Attachments: fulllogrecorddump.jar, objectdb.zip, runtimelogrecorddump.jar, sane_output.zip
>
>
> Steps to hit the issue:
> 1. Create a derby db with a few tables
> 2. Perform some db operations (there's going to be a mix of selects, updates, and inserts
here across several tables).
> 3. Kill the java process during the db operations
> 4. Attempt to start the java process again.
> 5. Repeat from (2) a few times.
> After a few iterations, starting derby fails with this exception:
> Exception in thread "main" java.sql.SQLException: Failed to start database '/Users/tim/jiras/mnk-2519/ObjectDataSynchronousWriteTest/objectdb/datadb'
with class loader sun.misc.Launcher$AppClassLoader@61e63e3d, 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/jiras/mnk-2519/ObjectDataSynchronousWriteTest/objectdb/datadb'
with class loader sun.misc.Launcher$AppClassLoader@61e63e3d, 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 2989, 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
> The circumstances are essentially the same as what was in DERBY-5248, but the error seems
to be a bit different. Opening a fresh issue since the nature of the problem is not quite
clear. This issue can be merged if the root cause is found to be the same.
> I'm attaching the corrupted db along with the output from opening the db with a sane
build. Please let me know if any more information is needed.

--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

Mime
View raw message