Derby
  1. Derby
  2. DERBY-2254

Assert during log file switch: log file position exceeded max log file size

    Details

    • Urgency:
      Normal
    • Issue & fix info:
      Patch Available
    • Bug behavior facts:
      Data corruption

      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.

      1. d2254.zip
        2 kB
        Rick Hillegas
      2. derby-2254-01-ab-accountForMoreOverhead.diff
        8 kB
        Rick Hillegas
      3. derby-2254-01-ac-accountForMoreOverhead.diff
        8 kB
        Rick Hillegas

        Issue Links

          Activity

          Olav Sandstaa created issue -
          Knut Anders Hatlen made changes -
          Field Original Value New Value
          Bug behavior facts [Crash]
          Urgency Normal
          Kathey Marsden made changes -
          Labels derby_triage10_5_2
          Rick Hillegas made changes -
          Bug behavior facts [Crash] [Data corruption]
          Rick Hillegas made changes -
          Link This issue relates to DERBY-2286 [ DERBY-2286 ]
          Rick Hillegas made changes -
          Attachment d2254.zip [ 12478725 ]
          Rick Hillegas made changes -
          Assignee Rick Hillegas [ rhillegas ]
          Rick Hillegas made changes -
          Rick Hillegas made changes -
          Issue & fix info [Patch Available]
          Rick Hillegas made changes -
          Rick Hillegas made changes -
          Status Open [ 1 ] Resolved [ 5 ]
          Fix Version/s 10.8.1.3 [ 12316378 ]
          Fix Version/s 10.9.0.0 [ 12316344 ]
          Resolution Fixed [ 1 ]
          Rick Hillegas made changes -
          Fix Version/s 10.8.1.4 [ 12316500 ]
          Fix Version/s 10.8.1.3 [ 12316378 ]
          Knut Anders Hatlen made changes -
          Fix Version/s 10.8.1.5 [ 12316676 ]
          Fix Version/s 10.8.1.4 [ 12316500 ]
          Myrna van Lunteren made changes -
          Fix Version/s 10.8.2.0 [ 12317955 ]
          Fix Version/s 10.8.1.6 [ 12316676 ]
          Myrna van Lunteren made changes -
          Fix Version/s 10.8.2.2 [ 12317968 ]
          Fix Version/s 10.8.2.0 [ 12317955 ]
          Kathey Marsden made changes -
          Affects Version/s 10.5.3.0 [ 12314117 ]
          Affects Version/s 10.3.1.4 [ 12312590 ]
          Kathey Marsden made changes -
          Link This issue is required by DERBY-5654 [ DERBY-5654 ]
          Kathey Marsden made changes -
          Resolution Fixed [ 1 ]
          Status Resolved [ 5 ] Reopened [ 4 ]
          Mike Matrigali made changes -
          Assignee Rick Hillegas [ rhillegas ] Mike Matrigali [ mikem ]
          Mike Matrigali made changes -
          Assignee Mike Matrigali [ mikem ] Rick Hillegas [ rhillegas ]
          Fix Version/s 10.5.3.2 [ 12315436 ]
          Fix Version/s 10.6.2.3 [ 12315434 ]
          Fix Version/s 10.7.1.4 [ 12315902 ]
          Mike Matrigali made changes -
          Status Reopened [ 4 ] Resolved [ 5 ]
          Resolution Fixed [ 1 ]
          Knut Anders Hatlen made changes -
          Status Resolved [ 5 ] Closed [ 6 ]
          Gavin made changes -
          Workflow jira [ 12394584 ] Default workflow, editable Closed status [ 12802759 ]

            People

            • Assignee:
              Rick Hillegas
              Reporter:
              Olav Sandstaa
            • Votes:
              2 Vote for this issue
              Watchers:
              5 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Development