Derby
  1. Derby
  2. DERBY-3992

cleanupOnError does not log the original exception if it encounters an error on cleanup

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Major Major
    • Resolution: Cannot Reproduce
    • Affects Version/s: 10.5.1.1
    • Fix Version/s: None
    • Component/s: Services
    • Urgency:
      Normal
    • Issue & fix info:
      High Value Fix

      Description

      Recently I encountered a couple of cases where we encountered an error on cleanupOnError so the original exception that caused the cleanup action was lost. It would be useful if the exception passed to cleanupOnError was logged regardless of whether there was a subsequent exception on cleanup.

      Here are a couple sample traces. The first was from a user site.
      ----------------------------------------------------------------
      New exception raised during cleanup null
      java.lang.NullPointerException
      at org.apache.derby.impl.store.raw.log.LogToFile.flush(Unknown Source)
      at org.apache.derby.impl.store.raw.log.LogToFile.flush(Unknown Source)
      at org.apache.derby.impl.store.raw.data.BaseDataFileFactory.flush(Unknown Source)
      at org.apache.derby.impl.store.raw.data.CachedPage.writePage(Unknown Source)
      at org.apache.derby.impl.store.raw.data.CachedPage.clean(Unknown Source)
      at org.apache.derby.impl.services.cache.CachedItem.clean(Unknown Source)
      at org.apache.derby.impl.services.cache.Clock.cleanCache(Unknown Source)
      at org.apache.derby.impl.services.cache.Clock.cleanAll(Unknown Source)
      at org.apache.derby.impl.services.cache.Clock.shutdown(Unknown Source)
      at org.apache.derby.impl.store.raw.data.BaseDataFileFactory.stop(Unknown Source)
      at org.apache.derby.impl.services.monitor.TopService.stop(Unknown Source)
      at org.apache.derby.impl.services.monitor.TopService.shutdown(Unknown Source)
      at org.apache.derby.impl.services.monitor.BaseMonitor.shutdown(Unknown Source)
      at org.apache.derby.impl.db.DatabaseContextImpl.cleanupOnError(Unknown Source)
      at org.apache.derby.iapi.services.context.ContextManager.cleanupOnError(Unknown Source)
      at org.apache.derby.impl.jdbc.TransactionResourceImpl.cleanupOnError(Unknown Source)
      at org.apache.derby.impl.jdbc.TransactionResourceImpl.handleException(Unknown Source)
      at org.apache.derby.impl.jdbc.EmbedConnection.handleException(Unknown Source)
      at org.apache.derby.impl.jdbc.EmbedConnection.<init>(Unknown Source)
      at org.apache.derby.jdbc.Driver30.getNewEmbedConnection(Unknown Source)
      at org.apache.derby.jdbc.InternalDriver.connect(Unknown Source)
      at java.sql.DriverManager.getConnection(DriverManager.java:562)
      at java.sql.DriverManager.getConnection(DriverManager.java:186)

      The second was from a run on IBM 1.6 of store/encryptDatabaseTest1.sql.
      I can't reproduce the error.
      New exception raised during cleanup name can't be null
      java.lang.NullPointerException: name can't be null
      at java.io.FilePermission.init(FilePermission.java:183)
      at java.io.FilePermission.<init>(FilePermission.java:267)
      at java.lang.SecurityManager.checkRead(SecurityManager.java:871)
      at java.io.File.list(File.java:983)
      at org.apache.derby.impl.store.raw.data.BaseDataFileFactory.run(BaseDataFileFactory.java:2640)
      at java.security.AccessController.doPrivileged(AccessController.java:251)
      at org.apache.derby.impl.store.raw.data.BaseDataFileFactory.removeStubs(BaseDataFileFactory.java:1591)
      at org.apache.derby.impl.store.raw.data.BaseDataFileFactory.stop(BaseDataFileFactory.java:499)
      at org.apache.derby.impl.services.monitor.TopService.stop(TopService.java:405)
      at org.apache.derby.impl.services.monitor.TopService.shutdown(TopService.java:349)
      at org.apache.derby.impl.services.monitor.BaseMonitor.shutdown(BaseMonitor.java:239)
      at org.apache.derby.impl.db.DatabaseContextImpl.cleanupOnError(DatabaseContextImpl.java:60)
      at org.apache.derby.iapi.services.context.ContextManager.cleanupOnError(ContextManager.java:332)
      at org.apache.derby.impl.jdbc.TransactionResourceImpl.cleanupOnError(TransactionResourceImpl.java:419)
      at org.apache.derby.impl.jdbc.EmbedConnection.<init>(EmbedConnection.java:584)
      at org.apache.derby.jdbc.Driver40.getNewEmbedConnection(Driver40.java:68)
      at org.apache.derby.jdbc.InternalDriver.connect(InternalDriver.java:238)
      at org.apache.derby.jdbc.AutoloadedDriver.connect(AutoloadedDriver.java:119)
      at java.sql.DriverManager.getConnection(DriverManager.java:316)
      at java.sql.DriverManager.getConnection(DriverManager.java:297)
      at org.apache.derby.impl.tools.ij.ij.dynamicConnection(ij.java:1329)
      at org.apache.derby.impl.tools.ij.ij.ConnectStatement(ij.java:1179)
      at org.apache.derby.impl.tools.ij.ij.ijStatement(ij.java:1007)
      at org.apache.derby.impl.tools.ij.utilMain.runScriptGuts(utilMain.java:328)
      at org.apache.derby.impl.tools.ij.utilMain.go(utilMain.java:248)
      at org.apache.derby.impl.tools.ij.Main.go(Main.java:215)
      at org.apache.derby.impl.tools.ij.Main.mainCore(Main.java:181)
      at org.apache.derby.impl.tools.ij.Main.main(Main.java:73)
      at org.apache.derby.tools.ij.main(ij.java:59)

      In both cases it would have been useful to have the original exception

        Issue Links

          Activity

          Hide
          Mamta A. Satoor added a comment -

          Kathey, I will go ahead and close the jira for now since we don't have a repro. We can reopen it in future if needed

          Show
          Mamta A. Satoor added a comment - Kathey, I will go ahead and close the jira for now since we don't have a repro. We can reopen it in future if needed
          Hide
          Kathey Marsden added a comment -

          Mamta, Should we close this cannot reproduce? The examples I sited were real ones but were from quite some time ago. Maybe something has changed since then?

          Show
          Kathey Marsden added a comment - Mamta, Should we close this cannot reproduce? The examples I sited were real ones but were from quite some time ago. Maybe something has changed since then?
          Hide
          Mamta A. Satoor added a comment -

          I have been looking at the cleanup code when Derby encounters an exception. The most relevant method is ContextManager.cleanupOnError. The code starting at
          forever: for (; {
          prints the error at hand into derby.log and then goes through another loop for all the contexts on the stack and calls clenup on each one of those stacks individually. If we counter an exception during the individual context cleanup, then we print that error too depending on the severity of error. So if my understanding of the code is correct, I think we are already reporting the original exception in the log file.

          I tried a real simple ij script below
          java -Dij.exceptionTrace=true org.apache.derby.tools.ij
          connect 'jdbc:derby:db1;create=true';
          – table t1 doesn't exist.
          insert into t1 values(2);
          exit;
          I put some printlns in the clenaup code in ContextManager and indeed see that we print the table does not exist exception before we start cleaning up the contexts on the stack. I have attached the patch with the printlns(on the console and to derby.log) to this jira.

          Show
          Mamta A. Satoor added a comment - I have been looking at the cleanup code when Derby encounters an exception. The most relevant method is ContextManager.cleanupOnError. The code starting at forever: for (; { prints the error at hand into derby.log and then goes through another loop for all the contexts on the stack and calls clenup on each one of those stacks individually. If we counter an exception during the individual context cleanup, then we print that error too depending on the severity of error. So if my understanding of the code is correct, I think we are already reporting the original exception in the log file. I tried a real simple ij script below java -Dij.exceptionTrace=true org.apache.derby.tools.ij connect 'jdbc:derby:db1;create=true'; – table t1 doesn't exist. insert into t1 values(2); exit; I put some printlns in the clenaup code in ContextManager and indeed see that we print the table does not exist exception before we start cleaning up the contexts on the stack. I have attached the patch with the printlns(on the console and to derby.log) to this jira.
          Hide
          Knut Anders Hatlen added a comment -

          Triaged for 10.5.2.

          Show
          Knut Anders Hatlen added a comment - Triaged for 10.5.2.
          Hide
          Kathey Marsden added a comment -

          releasing this issue for now. I am not currently working on it.

          Show
          Kathey Marsden added a comment - releasing this issue for now. I am not currently working on it.

            People

            • Assignee:
              Unassigned
              Reporter:
              Kathey Marsden
            • Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Development