[DERBY-2254] Assert during log file switch: log file position exceeded max log file size

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 10.5.3.0
• Fix Version/s: 10.5.3.2, 10.6.2.4, 10.7.1.4, 10.8.2.2, 10.9.1.0
• Component/s: Store
• Labels: derby_triage10_5_2
• Environment: Solaris 10, Java SE 6 build 104
• Urgency: Normal
• Issue & fix info: Patch Available
• Bug behavior facts: Data corruption
• Assignee: Richard N. Hillegas
• Reporter: Olav Sandstaa
• Created: 18/Jan/07 20:21
• Updated: 17/Jun/13 09:19
• Resolved: 21/Mar/12 00:03

Description

When running simple tpc-b like transactions against a embedded Derby based on a SANE build of trunk the following assertion occurs for the background thread and all user threads:

org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size

This seems to occur during a switch to a new log file.

derby.log contains the following call stack for the background thread:

Exception trace:
org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
at org.apache.derby.impl.store.raw.log.LogToFile.checkpointWithTran(LogToFile.java:1540)
at org.apache.derby.impl.store.raw.log.LogToFile.checkpoint(LogToFile.java:1357)
at org.apache.derby.impl.store.raw.RawStore.checkpoint(RawStore.java:439)
at org.apache.derby.impl.store.raw.log.LogToFile.performWork(LogToFile.java:3416)
at org.apache.derby.impl.services.daemon.BasicDaemon.serviceClient(BasicDaemon.java:331)
at org.apache.derby.impl.services.daemon.BasicDaemon.work(BasicDaemon.java:668)
at org.apache.derby.impl.services.daemon.BasicDaemon.run(BasicDaemon.java:394)
at java.lang.Thread.run(Thread.java:619)
2007-01-17 23:09:48.638 GMT Thread[derby.rawStoreDaemon,5,derby.daemons] Cleanup action starting
org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
at org.apache.derby.impl.store.raw.log.LogToFile.checkpointWithTran(LogToFile.java:1540)
at org.apache.derby.impl.store.raw.log.LogToFile.checkpoint(LogToFile.java:1357)
at org.apache.derby.impl.store.raw.RawStore.checkpoint(RawStore.java:439)
at org.apache.derby.impl.store.raw.log.LogToFile.performWork(LogToFile.java:3416)
at org.apache.derby.impl.services.daemon.BasicDaemon.serviceClient(BasicDaemon.java:331)
at org.apache.derby.impl.services.daemon.BasicDaemon.work(BasicDaemon.java:668)
at org.apache.derby.impl.services.daemon.BasicDaemon.run(BasicDaemon.java:394)
at java.lang.Thread.run(Thread.java:619)
Cleanup action completed

For my user threads the call stack is similar:

Database Class Loader started - derby.database.classpath=''
2007-01-17 23:09:36.401 GMT Thread[Thread-51,5,main] (XID = 12632406), (SESSIONID = 51), (DATABASE = /export/home/tmp/derby-db), (DRDAID = null), Cleanup action starting
2007-01-17 23:09:36.401 GMT Thread[Thread-51,5,main] (XID = 12632406), (SESSIONID = 51), (DATABASE = /export/home/tmp/derby-db), (DRDAID = null), Failed Statement is: UPDATE accounts SET abal = abal + ? WHERE aid = ? AND bid = ?
org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED log file position exceeded max log file size
at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:120)
at org.apache.derby.impl.store.raw.log.LogCounter.makeLogInstantAsLong(LogCounter.java:120)
at org.apache.derby.impl.store.raw.log.LogToFile.switchLogFile(LogToFile.java:1900)
at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(LogToFile.java:3530)
at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(FileLogger.java:345)
at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Xact.java:1185)
at org.apache.derby.impl.store.raw.data.LoggableActions.doAction(LoggableActions.java:221)
at org.apache.derby.impl.store.raw.data.LoggableActions.actionUpdate(LoggableActions.java:85)
at org.apache.derby.impl.store.raw.data.StoredPage.doUpdateAtSlot(StoredPage.java:8521)
at org.apache.derby.impl.store.raw.data.BasePage.updateAtSlot(BasePage.java:1108)
at org.apache.derby.impl.store.access.conglomerate.GenericConglomerateController.replace(GenericConglomerateController.java:479)
at org.apache.derby.impl.sql.execute.RowChangerImpl.updateRow(RowChangerImpl.java:523)
at org.apache.derby.impl.sql.execute.UpdateResultSet.collectAffectedRows(UpdateResultSet.java:566)
at org.apache.derby.impl.sql.execute.UpdateResultSet.open(UpdateResultSet.java:260)
at org.apache.derby.impl.sql.GenericPreparedStatement.execute(GenericPreparedStatement.java:358)
at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java:1182)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(EmbedPreparedStatement.java:1652)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(EmbedPreparedStatement.java:299)
at com.sun.derby.perf.clients.tpcb.DBConnection.performTransaction(DBConnection.java:595)
at com.sun.derby.perf.clients.tpcb.Client.run(Client.java:218)

After this it seems like no user threads are able to connect to the database (not surpricing).

This happend using a SANE build and I am unsure by just looking at the assertion in the code whether this situation would have been fatal also if I had been using an INSANE build.

Issue Links

• is required by: DERBY-5654 10.5 Backport issue (2012)
• relates to: DERBY-2286 Exception NoSpaceOnPage does not provide SQLState or exception text