Derby
  1. Derby
  2. DERBY-4813

TriggerTests failed to apply log record to store

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Major Major
    • Resolution: Duplicate
    • Affects Version/s: 10.6.2.1
    • Fix Version/s: None
    • Component/s: Store
    • Labels:
      None
    • Environment:
      Microsoft© Windows Server© 2008 - 6.0.6002 Service Pack 2
      Sun Microsystems Inc. java version 1.4.2_16
    • Bug behavior facts:
      Regression Test Failure

      Description

      This failure was seen when testing the Derby 10.6.2.0 release candidate:

      1) test5InsertAfterTriggerNoReferencingClause(org.apache.derbyTesting.functionTests.tests.memory.TriggerTests)java.sql.SQLException: Log Record has been sent to the stream, but it cannot be applied to the store (Object null). This may cause recovery problems also.

      http://dbtg.foundry.sun.com/derby/test/10.6.2.0_RC/jvm1.4/testing/testlog/w2008-32/997075-suitesAll_diff.txt

      Will attach logs and the database to the bug report.

      1. failure.zip
        5.94 MB
        Knut Anders Hatlen

        Issue Links

          Activity

          Gavin made changes -
          Workflow jira [ 12521329 ] Default workflow, editable Closed status [ 12800472 ]
          Knut Anders Hatlen made changes -
          Status Open [ 1 ] Closed [ 6 ]
          Resolution Duplicate [ 3 ]
          Hide
          Knut Anders Hatlen added a comment -

          Closing as a duplicate of DERBY-4481.

          Show
          Knut Anders Hatlen added a comment - Closing as a duplicate of DERBY-4481 .
          Knut Anders Hatlen made changes -
          Link This issue duplicates DERBY-4481 [ DERBY-4481 ]
          Knut Anders Hatlen made changes -
          Affects Version/s 10.6.2.1 [ 12315343 ]
          Affects Version/s 10.6.2.0 [ 12315342 ]
          Knut Anders Hatlen made changes -
          Link This issue relates to DERBY-151 [ DERBY-151 ]
          Knut Anders Hatlen made changes -
          Link This issue relates to DERBY-4481 [ DERBY-4481 ]
          Hide
          Knut Anders Hatlen added a comment -

          Thanks Kathey. Those two issues look suspiciously similar. I'll keep it open a little longer while investigating, but I'll probably close it as a duplicate of DERBY-4481 if I don't find any evidence suggesting that it's a different issue.

          Show
          Knut Anders Hatlen added a comment - Thanks Kathey. Those two issues look suspiciously similar. I'll keep it open a little longer while investigating, but I'll probably close it as a duplicate of DERBY-4481 if I don't find any evidence suggesting that it's a different issue.
          Hide
          Kathey Marsden added a comment -

          Previously accidentally put this comment on DERBY-4481.

          Hi Knut, I thought I would mention that similar errors were seen in DERBY-4481 and started happening after the interrupt was introduced in the Derby151Test. I don't know if it is related, but thought I would put it out there as a data point.

          Show
          Kathey Marsden added a comment - Previously accidentally put this comment on DERBY-4481 . Hi Knut, I thought I would mention that similar errors were seen in DERBY-4481 and started happening after the interrupt was introduced in the Derby151Test. I don't know if it is related, but thought I would put it out there as a data point.
          Hide
          Knut Anders Hatlen added a comment -

          I see that derby.log contains many occurrences of this message before the test fails:

          ------------ BEGIN ERROR MESSAGE -------------

          new log file exist and cannot be deleted C:\cludev\jagtmp\autoderbyN_derbyall\suitesAll_1\log\system\wombat\log\log454.dat
          ------------ END ERROR MESSAGE -------------

          The test run had a failure in StreamingColumnTest (an intermittent failure fixed in DERBY-4531 but not backported) before the problems in TriggersTest, so perhaps a file handle was left open and caused problems when later trying to write to that file? It's a bit strange, though, that so many other tests ran in between without any issues, but it may of course be that none of those tests produced enough log files to hit that file.

          Hmmm... So it seems this log454.dat file that we cannot delete, prevents us from switching from log453.dat, and we just continue appending log records to file 453 until it exceeds the maximum size. Would it be a more appropriate response to fail immediately in the case where we cannot switch log files, and tell the user to force the removal of the file that's blocking us?

          Show
          Knut Anders Hatlen added a comment - I see that derby.log contains many occurrences of this message before the test fails: ------------ BEGIN ERROR MESSAGE ------------- new log file exist and cannot be deleted C:\cludev\jagtmp\autoderbyN_derbyall\suitesAll_1\log\system\wombat\log\log454.dat ------------ END ERROR MESSAGE ------------- The test run had a failure in StreamingColumnTest (an intermittent failure fixed in DERBY-4531 but not backported) before the problems in TriggersTest, so perhaps a file handle was left open and caused problems when later trying to write to that file? It's a bit strange, though, that so many other tests ran in between without any issues, but it may of course be that none of those tests produced enough log files to hit that file. Hmmm... So it seems this log454.dat file that we cannot delete, prevents us from switching from log453.dat, and we just continue appending log records to file 453 until it exceeds the maximum size. Would it be a more appropriate response to fail immediately in the case where we cannot switch log files, and tell the user to force the removal of the file that's blocking us?
          Knut Anders Hatlen made changes -
          Field Original Value New Value
          Attachment failure.zip [ 12455373 ]
          Hide
          Knut Anders Hatlen added a comment -

          Attached is a zip file with derby.log and the failed database.

          As indicated by the error message, there is one very large log file in the database:

          $ ls -lh wombat/log/
          total 524653
          rw-rr- 1 kah staff 48 Sep 18 06:29 log.ctrl
          rw-rr- 1 kah staff 256M Sep 18 06:29 log453.dat
          rw-rr- 1 kah staff 24 Sep 18 06:29 log454.dat
          rw-rr- 1 kah staff 48 Sep 18 06:29 logmirror.ctrl

          Show
          Knut Anders Hatlen added a comment - Attached is a zip file with derby.log and the failed database. As indicated by the error message, there is one very large log file in the database: $ ls -lh wombat/log/ total 524653 rw-r r - 1 kah staff 48 Sep 18 06:29 log.ctrl rw-r r - 1 kah staff 256M Sep 18 06:29 log453.dat rw-r r - 1 kah staff 24 Sep 18 06:29 log454.dat rw-r r - 1 kah staff 48 Sep 18 06:29 logmirror.ctrl
          Hide
          Knut Anders Hatlen added a comment -

          The root exception has the following stack trace:

          ERROR XSLAL: log record size 32 707 exceeded the maximum allowable log file size 268 435 455. Error encountered in log file 453, position 268 414 521.
          at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
          at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(Unknown Source)
          at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(Unknown Source)
          at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Unknown Source)
          at org.apache.derby.impl.store.raw.data.LoggableActions.doAction(Unknown Source)
          at org.apache.derby.impl.store.raw.data.LoggableActions.actionInsert(Unknown Source)
          at org.apache.derby.impl.store.raw.data.BasePage.insertLongColumn(Unknown Source)
          at org.apache.derby.impl.store.raw.data.BasePage.insertAllowOverflow(Unknown Source)
          at org.apache.derby.impl.store.raw.data.BasePage.insert(Unknown Source)
          at org.apache.derby.impl.store.access.heap.HeapController.doInsert(Unknown Source)
          at org.apache.derby.impl.store.access.heap.HeapController.insertAndFetchLocation(Unknown Source)
          at org.apache.derby.impl.sql.execute.RowChangerImpl.insertRow(Unknown Source)
          at org.apache.derby.impl.sql.execute.InsertResultSet.normalInsertCore(Unknown Source)
          at org.apache.derby.impl.sql.execute.InsertResultSet.open(Unknown Source)
          at org.apache.derby.impl.sql.GenericPreparedStatement.executeStmt(Unknown Source)
          at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
          at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
          at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
          at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(Unknown Source)
          at org.apache.derbyTesting.functionTests.tests.memory.TriggerTests.basicSetup(TriggerTests.java:282)
          at org.apache.derbyTesting.functionTests.tests.memory.TriggerTests.test5InsertAfterTriggerNoReferencingClause(TriggerTests.java:1176)
          at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
          at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
          at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
          at java.lang.reflect.Method.invoke(Method.java:324)
          at junit.framework.TestCase.runTest(TestCase.java:164)
          at junit.framework.TestCase.runBare(TestCase.java:130)
          at org.apache.derbyTesting.junit.BaseTestCase.runBare(BaseTestCase.java:109)

          Show
          Knut Anders Hatlen added a comment - The root exception has the following stack trace: ERROR XSLAL: log record size 32 707 exceeded the maximum allowable log file size 268 435 455. Error encountered in log file 453, position 268 414 521. at org.apache.derby.iapi.error.StandardException.newException(Unknown Source) at org.apache.derby.impl.store.raw.log.LogToFile.appendLogRecord(Unknown Source) at org.apache.derby.impl.store.raw.log.FileLogger.logAndDo(Unknown Source) at org.apache.derby.impl.store.raw.xact.Xact.logAndDo(Unknown Source) at org.apache.derby.impl.store.raw.data.LoggableActions.doAction(Unknown Source) at org.apache.derby.impl.store.raw.data.LoggableActions.actionInsert(Unknown Source) at org.apache.derby.impl.store.raw.data.BasePage.insertLongColumn(Unknown Source) at org.apache.derby.impl.store.raw.data.BasePage.insertAllowOverflow(Unknown Source) at org.apache.derby.impl.store.raw.data.BasePage.insert(Unknown Source) at org.apache.derby.impl.store.access.heap.HeapController.doInsert(Unknown Source) at org.apache.derby.impl.store.access.heap.HeapController.insertAndFetchLocation(Unknown Source) at org.apache.derby.impl.sql.execute.RowChangerImpl.insertRow(Unknown Source) at org.apache.derby.impl.sql.execute.InsertResultSet.normalInsertCore(Unknown Source) at org.apache.derby.impl.sql.execute.InsertResultSet.open(Unknown Source) at org.apache.derby.impl.sql.GenericPreparedStatement.executeStmt(Unknown Source) at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source) at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source) at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source) at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(Unknown Source) at org.apache.derbyTesting.functionTests.tests.memory.TriggerTests.basicSetup(TriggerTests.java:282) at org.apache.derbyTesting.functionTests.tests.memory.TriggerTests.test5InsertAfterTriggerNoReferencingClause(TriggerTests.java:1176) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:324) at junit.framework.TestCase.runTest(TestCase.java:164) at junit.framework.TestCase.runBare(TestCase.java:130) at org.apache.derbyTesting.junit.BaseTestCase.runBare(BaseTestCase.java:109)
          Knut Anders Hatlen created issue -

            People

            • Assignee:
              Unassigned
              Reporter:
              Knut Anders Hatlen
            • Votes:
              0 Vote for this issue
              Watchers:
              0 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Development