Derby
  1. Derby
  2. DERBY-5124

NPE or assert failure printed when dropping table while statistics are written out

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 10.8.1.2
    • Fix Version/s: 10.8.1.2
    • Component/s: Services
    • Labels:
      None

      Description

      To find out what would happen if a table was dropped while its statistics were being written to disk, I put a breakpoint in IndexStatisticsImpl.writeUpdatedStats() right after the call to dropStatisticsDescriptors(), started an ij session in the debugger and executed some statements to make the istat code kick in. When the breakpoint was hit, I dropped the table being updated in ij, before letting the istat thread continue.

      With insane jars, the following NPE was printed on the ij console:

      Exception in thread "index-stat-thread" java.lang.NullPointerException
      at org.apache.derby.impl.services.daemon.IndexStatisticsDaemonImpl.writeUpdatedStats(IndexStatisticsDaemonImpl.java:556)
      at org.apache.derby.impl.services.daemon.IndexStatisticsDaemonImpl.updateIndexStatsMinion(IndexStatisticsDaemonImpl.java:486)
      at org.apache.derby.impl.services.daemon.IndexStatisticsDaemonImpl.generateStatistics(IndexStatisticsDaemonImpl.java:323)
      at org.apache.derby.impl.services.daemon.IndexStatisticsDaemonImpl.processingLoop(IndexStatisticsDaemonImpl.java:759)
      at org.apache.derby.impl.services.daemon.IndexStatisticsDaemonImpl.run(IndexStatisticsDaemonImpl.java:675)
      at java.lang.Thread.run(Thread.java:662)

      Apart from the stack trace being printed, nothing bad happened. The istat thread was able to recover, and the ij session was unaffected too.

      Using a debug build, I got an assert failure instead:

      Exception in thread "index-stat-thread" org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED transaction not pristine
      at org.apache.derby.shared.common.sanity.SanityManager.THROWASSERT(SanityManager.java:162)
      at org.apache.derby.shared.common.sanity.SanityManager.THROWASSERT(SanityManager.java:147)
      at org.apache.derby.impl.services.daemon.IndexStatisticsDaemonImpl.processingLoop(IndexStatisticsDaemonImpl.java:810)
      at org.apache.derby.impl.services.daemon.IndexStatisticsDaemonImpl.run(IndexStatisticsDaemonImpl.java:675)
      at java.lang.Thread.run(Thread.java:662)

      The assert failure prevented some cleanup from happening, so the istat thread seemed to hold on to a lock on SYSSTATISTICS, so the following statement would keep failing in ij after on:

      ij> select * from sys.sysstatistics;
      STATID |REFERENCEID |TABLEID |CREATIONTIMESTAMP |&|VALID|COLCOUNT |STATISTICS
      --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
      ERROR 40XL1: A lock could not be obtained within the time requested

      1. null.diff
        0.9 kB
        Knut Anders Hatlen

        Issue Links

          Activity

          Hide
          Knut Anders Hatlen added a comment -

          Committed revision 1080573.

          Show
          Knut Anders Hatlen added a comment - Committed revision 1080573.
          Hide
          Knut Anders Hatlen added a comment -

          The attached patch adds a null check to the logging code, so that it doesn't fail with a NullPointerException. This also fixes the assert failure in debug builds. The assert happened because the NPE prevented the istat tx from committing, and the cleanup code expected the tx to have no uncommitted operations.

          Show
          Knut Anders Hatlen added a comment - The attached patch adds a null check to the logging code, so that it doesn't fail with a NullPointerException. This also fixes the assert failure in debug builds. The assert happened because the NPE prevented the istat tx from committing, and the cleanup code expected the tx to have no uncommitted operations.
          Hide
          Knut Anders Hatlen added a comment -

          The NPE happens in the logging:

          // Log some information.
          log(asBackgroundTask, td,
          "wrote stats for index " +
          dd.getConglomerateDescriptor(index).getDescriptorName() +
          " (" + index + "): rows=" + numRows +
          ", card=" + cardToStr(cardinality));

          Presumably dd.getConglomerateDescriptor() returns null because the index doesn't exist anymore.

          Show
          Knut Anders Hatlen added a comment - The NPE happens in the logging: // Log some information. log(asBackgroundTask, td, "wrote stats for index " + dd.getConglomerateDescriptor(index).getDescriptorName() + " (" + index + "): rows=" + numRows + ", card=" + cardToStr(cardinality)); Presumably dd.getConglomerateDescriptor() returns null because the index doesn't exist anymore.

            People

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

              Dates

              • Created:
                Updated:
                Resolved:

                Development