[
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
