Derby
  1. Derby
  2. DERBY-5169

Derby intermittently fails with an internal error

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Major Major
    • Resolution: Duplicate
    • Affects Version/s: None
    • Fix Version/s: None
    • Component/s: SQL
    • Labels:
      None
    • Environment:
      Derby 10.7.1.1 + patch for cycle detection problem
    • Bug behavior facts:
      Crash

      Description

      During the running of ManifoldCF tests, the JDBC error "No current connection" is thrown. Looking at derby.log for the time when this happens, the following can be found:

      Thu Mar 31 13:26:28 EDT 2011 Thread[Thread-458,5,main] (XID = 636), (SESSIONID \
      = 11), (DATABASE = /data/mcf/trunk/test-output/filesystem/dbname), (DRDAID = nu\
      ll), Failed Statement is: SELECT id,status,checktime FROM jobqueue WHERE jobid=\
      ? AND dochash=? FOR UPDATE
      org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED Internal Err\
      or-- statistics not found in selectivityForConglomerate.
      cd = ConglomerateDescriptor: conglomerateNumber = 1985 name = I1301592382768 u\
      uid = bfd00180-012f-0cf3-92ab-00000674d0a0 indexable = true
      numKeys = 2
      at org.apache.derby.shared.common.sanity.SanityManager.THROWASSERT(Sani\
      tyManager.java:162)
      at org.apache.derby.shared.common.sanity.SanityManager.THROWASSERT(Sani\
      tyManager.java:147)
      at org.apache.derby.iapi.sql.dictionary.TableDescriptor.selectivityForC\
      onglomerate(TableDescriptor.java:1345)
      at org.apache.derby.impl.sql.compile.PredicateList.selectivity(Predicat\
      eList.java:3905)
      at org.apache.derby.impl.sql.compile.FromBaseTable.estimateCost(FromBas\
      eTable.java:1279)
      at org.apache.derby.impl.sql.compile.OptimizerImpl.estimateTotalCost(Op\
      timizerImpl.java:2626)
      at org.apache.derby.impl.sql.compile.OptimizerImpl.costBasedCostOptimiz\
      able(OptimizerImpl.java:2172)
      at org.apache.derby.impl.sql.compile.OptimizerImpl.costOptimizable(Opti\
      mizerImpl.java:1985)
      at org.apache.derby.impl.sql.compile.FromBaseTable.optimizeIt(FromBaseT\
      able.java:521)
      at org.apache.derby.impl.sql.compile.ProjectRestrictNode.optimizeIt(Pro\
      jectRestrictNode.java:316)
      at org.apache.derby.impl.sql.compile.OptimizerImpl.costPermutation(Opti\
      mizerImpl.java:1939)
      at org.apache.derby.impl.sql.compile.SelectNode.optimize(SelectNode.jav\
      a:1916)
      at org.apache.derby.impl.sql.compile.DMLStatementNode.optimizeStatement\
      (DMLStatementNode.java:315)
      at org.apache.derby.impl.sql.compile.CursorNode.optimizeStatement(Curso\
      rNode.java:558)
      at org.apache.derby.impl.sql.GenericStatement.prepMinion(GenericStateme\
      nt.java:381)
      at org.apache.derby.impl.sql.GenericStatement.prepare(GenericStatement.\
      java:90)
      at org.apache.derby.impl.sql.conn.GenericLanguageConnectionContext.prep\
      areInternalStatement(GenericLanguageConnectionContext.java:1101)
      at org.apache.derby.impl.jdbc.EmbedPreparedStatement.<init>(EmbedPrepar\
      edStatement.java:131)
      at org.apache.derby.impl.jdbc.EmbedPreparedStatement20.<init>(EmbedPrep\
      aredStatement20.java:82)
      at org.apache.derby.impl.jdbc.EmbedPreparedStatement30.<init>(EmbedPrep\
      aredStatement30.java:63)
      at org.apache.derby.impl.jdbc.EmbedPreparedStatement40.<init>(EmbedPrep\
      aredStatement40.java:40)
      at org.apache.derby.jdbc.Driver40.newEmbedPreparedStatement(Driver40.ja\
      va:105)
      at org.apache.derby.impl.jdbc.EmbedConnection.prepareStatement(EmbedCon\
      nection.java:1613)
      at org.apache.derby.impl.jdbc.EmbedConnection.prepareStatement(EmbedCon\
      nection.java:1441)
      at com.bitmechanic.sql.PooledConnection.prepareStatement(PooledConnecti\
      on.java:352)
      at org.apache.manifoldcf.core.database.Database.execute(Database.java:5\
      86)
      at org.apache.manifoldcf.core.database.Database$ExecuteQueryThread.run(\
      Database.java:421)
      ---------------
      Stack traces for all live threads:
      Thread name=Expiration thread '1' id=243 priority=5 state=WAITING isdaemon=true
      java.lang.Object.wait(Native Method)
      java.lang.Object.wait(Object.java:485)
      org.apache.manifoldcf.crawler.system.DocumentCleanupQueue.getDocuments(\
      DocumentCleanupQueue.java:100)
      org.apache.manifoldcf.crawler.system.ExpireThread.run(ExpireThread.java\
      :89)

      Thread name=Document delete thread '0' id=253 priority=5 state=WAITING isdaemon\
      =true
      java.lang.Object.wait(Native Method)
      java.lang.Object.wait(Object.java:485)
      org.apache.manifoldcf.crawler.system.DocumentDeleteQueue.getDocuments(D\
      ocumentDeleteQueue.java:100)
      org.apache.manifoldcf.crawler.system.DocumentDeleteThread.run(DocumentD\
      eleteThread.java:89)

      Thread name=Worker thread '33' id=175 priority=5 state=WAITING isdaemon=true
      java.lang.Object.wait(Native Method)
      java.lang.Object.wait(Object.java:485)
      org.apache.manifoldcf.crawler.system.DocumentQueue.getDocument(Document\
      Queue.java:110)

      ...

      Thread name=Thread-460 id=469 priority=5 state=WAITING isdaemon=true
      java.lang.Object.wait(Native Method)
      java.lang.Object.wait(Object.java:485)
      org.apache.derby.impl.sql.GenericStatement.prepMinion(GenericStatement.\
      java:197)
      org.apache.derby.impl.sql.GenericStatement.prepare(GenericStatement.jav\
      a:90)
      org.apache.derby.impl.sql.conn.GenericLanguageConnectionContext.prepare\
      InternalStatement(GenericLanguageConnectionContext.java:1101)
      org.apache.derby.impl.jdbc.EmbedPreparedStatement.<init>(EmbedPreparedS\
      tatement.java:131)
      org.apache.derby.impl.jdbc.EmbedPreparedStatement20.<init>(EmbedPrepare\
      dStatement20.java:82)
      org.apache.derby.impl.jdbc.EmbedPreparedStatement30.<init>(EmbedPrepare\
      dStatement30.java:63)
      org.apache.derby.impl.jdbc.EmbedPreparedStatement40.<init>(EmbedPrepare\
      dStatement40.java:40)
      org.apache.derby.jdbc.Driver40.newEmbedPreparedStatement(Driver40.java:\
      105)
      org.apache.derby.impl.jdbc.EmbedConnection.prepareStatement(EmbedConnec\
      tion.java:1613)
      org.apache.derby.impl.jdbc.EmbedConnection.prepareStatement(EmbedConnec\
      tion.java:1441)

      ...

      Thread name=Thread-459 id=468 priority=5 state=RUNNABLE isdaemon=true
      java.lang.Object.hashCode(Native Method)
      org.apache.derby.impl.services.locks.Lock.hashCode(Lock.java:145)
      java.util.HashMap.get(HashMap.java:300)
      org.apache.derby.impl.services.locks.LockSpace.isLockHeld(LockSpace.jav\
      a:322)
      org.apache.derby.impl.services.locks.AbstractPool.isLockHeld(AbstractPo\
      ol.java:322)
      org.apache.derby.impl.store.raw.xact.RowLocking3.lockContainer(RowLocki\
      ng3.java:144)
      org.apache.derby.impl.store.raw.data.BaseContainerHandle.useContainer(B\
      aseContainerHandle.java:809)
      org.apache.derby.impl.store.raw.data.BaseDataFileFactory.openContainer(\
      BaseDataFileFactory.java:752)
      org.apache.derby.impl.store.raw.data.BaseDataFileFactory.openContainer(\
      BaseDataFileFactory.java:568)
      org.apache.derby.impl.store.raw.xact.Xact.openContainer(Xact.java:1313)
      org.apache.derby.impl.store.access.conglomerate.OpenConglomerate.init(O\
      penConglomerate.java:909)
      org.apache.derby.impl.store.access.heap.Heap.open(Heap.java:683)
      org.apache.derby.impl.store.access.RAMTransaction.openConglomerate(RAMT\
      ransaction.java:476)
      org.apache.derby.impl.store.access.RAMTransaction.openConglomerate(RAMT\
      ransaction.java:1308)
      org.apache.derby.impl.sql.catalog.DataDictionaryImpl.getDescriptorViaIn\
      dexMinion(DataDictionaryImpl.java:8567)
      org.apache.derby.impl.sql.catalog.DataDictionaryImpl.getDescriptorViaIn\
      dex(DataDictionaryImpl.java:8525)
      org.apache.derby.impl.sql.catalog.DataDictionaryImpl.locateSchemaRow(Da\
      taDictionaryImpl.java:1649)
      org.apache.derby.impl.sql.catalog.DataDictionaryImpl.getSchemaDescripto\
      r(DataDictionaryImpl.java:1516)
      org.apache.derby.impl.sql.compile.QueryTreeNode.getSchemaDescriptor(Que\
      ryTreeNode.java:1437)
      org.apache.derby.impl.sql.compile.QueryTreeNode.getSchemaDescriptor(Que\
      ryTreeNode.java:1370)
      org.apache.derby.impl.sql.compile.DMLModStatementNode.verifyTargetTable\
      (DMLModStatementNode.java:201)
      org.apache.derby.impl.sql.compile.DeleteNode.bindStatement(DeleteNode.j\
      ava:221)
      org.apache.derby.impl.sql.GenericStatement.prepMinion(GenericStatement.\
      java:324)
      org.apache.derby.impl.sql.GenericStatement.prepare(GenericStatement.jav\
      a:90)
      org.apache.derby.impl.sql.conn.GenericLanguageConnectionContext.prepare\
      InternalStatement(GenericLanguageConnectionContext.java:1101)
      org.apache.derby.impl.jdbc.EmbedPreparedStatement.<init>(EmbedPreparedS\
      tatement.java:131)
      org.apache.derby.impl.jdbc.EmbedPreparedStatement20.<init>(EmbedPrepare\
      dStatement20.java:82)
      org.apache.derby.impl.jdbc.EmbedPreparedStatement30.<init>(EmbedPrepare\
      dStatement30.java:63)
      org.apache.derby.impl.jdbc.EmbedPreparedStatement40.<init>(EmbedPrepare\
      dStatement40.java:40)
      org.apache.derby.jdbc.Driver40.newEmbedPreparedStatement(Driver40.java:\
      105)
      org.apache.derby.impl.jdbc.EmbedConnection.prepareStatement(EmbedConnec\
      tion.java:1613)
      org.apache.derby.impl.jdbc.EmbedConnection.prepareStatement(EmbedConnec\
      tion.java:1441)

      ...

      Thread name=Thread-458 id=467 priority=5 state=RUNNABLE isdaemon=true
      java.lang.Thread.dumpThreads(Native Method)
      java.lang.Thread.getAllStackTraces(Thread.java:1530)
      org.apache.derby.shared.common.sanity.ThreadDump.getStackDumpString(Thr\
      eadDump.java:34)
      sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.ja\
      va:39)
      sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccesso\
      rImpl.java:25)
      java.lang.reflect.Method.invoke(Method.java:597)
      org.apache.derby.shared.common.sanity.AssertFailure$1.run(AssertFailure\
      .java:165)
      java.security.AccessController.doPrivileged(Native Method)
      org.apache.derby.shared.common.sanity.AssertFailure.dumpThreads(AssertF\
      ailure.java:159)
      org.apache.derby.shared.common.sanity.AssertFailure.<init>(AssertFailur\
      e.java:72)
      org.apache.derby.shared.common.sanity.SanityManager.THROWASSERT(SanityM\
      anager.java:162)
      org.apache.derby.shared.common.sanity.SanityManager.THROWASSERT(SanityM\
      anager.java:147)
      org.apache.derby.iapi.sql.dictionary.TableDescriptor.selectivityForCong\
      lomerate(TableDescriptor.java:1345)
      org.apache.derby.impl.sql.compile.PredicateList.selectivity(PredicateLi\
      st.java:3905)
      org.apache.derby.impl.sql.compile.FromBaseTable.estimateCost(FromBaseTa\
      ble.java:1279)
      org.apache.derby.impl.sql.compile.OptimizerImpl.estimateTotalCost(Optim\
      izerImpl.java:2626)
      org.apache.derby.impl.sql.compile.OptimizerImpl.costBasedCostOptimizabl\
      e(OptimizerImpl.java:2172)
      org.apache.derby.impl.sql.compile.OptimizerImpl.costOptimizable(Optimiz\
      erImpl.java:1985)
      org.apache.derby.impl.sql.compile.FromBaseTable.optimizeIt(FromBaseTabl\
      e.java:521)
      org.apache.derby.impl.sql.compile.ProjectRestrictNode.optimizeIt(Projec\
      tRestrictNode.java:316)
      org.apache.derby.impl.sql.compile.OptimizerImpl.costPermutation(Optimiz\
      erImpl.java:1939)
      org.apache.derby.impl.sql.compile.SelectNode.optimize(SelectNode.java:1\
      916)
      org.apache.derby.impl.sql.compile.DMLStatementNode.optimizeStatement(DM\
      LStatementNode.java:315)
      org.apache.derby.impl.sql.compile.CursorNode.optimizeStatement(CursorNo\
      de.java:558)
      org.apache.derby.impl.sql.GenericStatement.prepMinion(GenericStatement.\
      java:381)
      org.apache.derby.impl.sql.GenericStatement.prepare(GenericStatement.jav\
      a:90)
      org.apache.derby.impl.sql.conn.GenericLanguageConnectionContext.prepare\
      InternalStatement(GenericLanguageConnectionContext.java:1101)
      org.apache.derby.impl.jdbc.EmbedPreparedStatement.<init>(EmbedPreparedS\
      tatement.java:131)
      org.apache.derby.impl.jdbc.EmbedPreparedStatement20.<init>(EmbedPrepare\
      dStatement20.java:82)
      org.apache.derby.impl.jdbc.EmbedPreparedStatement30.<init>(EmbedPrepare\
      dStatement30.java:63)
      org.apache.derby.impl.jdbc.EmbedPreparedStatement40.<init>(EmbedPrepare\
      dStatement40.java:40)
      org.apache.derby.jdbc.Driver40.newEmbedPreparedStatement(Driver40.java:\
      105)
      org.apache.derby.impl.jdbc.EmbedConnection.prepareStatement(EmbedConnec\
      tion.java:1613)
      org.apache.derby.impl.jdbc.EmbedConnection.prepareStatement(EmbedConnec\
      tion.java:1441)

      ...

      Thread name=derby.rawStoreDaemon id=11 priority=5 state=TIMED_WAITING isdaemon=\
      true
      java.lang.Object.wait(Native Method)
      org.apache.derby.impl.services.daemon.BasicDaemon.rest(BasicDaemon.java\
      :571)
      org.apache.derby.impl.services.daemon.BasicDaemon.run(BasicDaemon.java:\
      388)
      java.lang.Thread.run(Thread.java:662)

      ---------------

      Cleanup action completed
      Thu Mar 31 13:26:28 EDT 2011 Thread[Thread-472,5,main] (XID = 671), (SESSIONID \
      = 7), (DATABASE = /data/mcf/trunk/test-output/filesystem/dbname), (DRDAID = nul\
      l), Cleanup action starting
      Thu Mar 31 13:26:28 EDT 2011 Thread[Thread-472,5,main] (XID = 671), (SESSIONID \
      = 7), (DATABASE = /data/mcf/trunk/test-output/filesystem/dbname), (DRDAID = nul\
      l), Failed Statement is: INSERT INTO ingeststatus (id,changecount,dockey,lastve\
      rsion,firstingest,connectionname,authorityname,urihash,lastoutputversion,lastin\
      gest,docuri) VALUES (?,?,?,?,?,?,?,?,?,?,?) with 11 parameters begin parameter \
      #1: 1301592386640 :end parameter begin parameter #2: 1 :end parameter begin par\
      ameter #3: File Connection:C6F9B4AFF62656360BA4A21131C1D3C4A72922BE :end parame\
      ter begin parameter #4: CLOB(16) :end parameter begin parameter #5: 13015923887\
      06 :end parameter begin parameter #6: Null Connection :end parameter begin para\
      meter #7: :end parameter begin parameter #8: 22FF219C5BA7FDE80DDA8DDDAC753194F\
      04FAB13 :end parameter begin parameter #9: CLOB(0) :end parameter begin paramet\
      er #10: 1301592388706 :end parameter begin parameter #11: CLOB(62) :end paramet\
      er
      ERROR 23505: The statement was aborted because it would have caused a duplicate\
      key value in a unique or primary key constraint or unique index identified by \
      'I1301592382805' defined on 'INGESTSTATUS'.
      at org.apache.derby.iapi.error.StandardException.newException(StandardE\
      xception.java:303)
      at org.apache.derby.impl.sql.execute.IndexChanger.insertAndCheckDups(In\
      dexChanger.java:466)
      at org.apache.derby.impl.sql.execute.IndexChanger.doInsert(IndexChanger\
      .java:383)
      at org.apache.derby.impl.sql.execute.IndexChanger.insert(IndexChanger.j\
      ava:590)
      at org.apache.derby.impl.sql.execute.IndexSetChanger.insert(IndexSetCha\
      nger.java:268)
      at org.apache.derby.impl.sql.execute.RowChangerImpl.insertRow(RowChange\
      rImpl.java:453)
      at org.apache.derby.impl.sql.execute.InsertResultSet.normalInsertCore(I\
      nsertResultSet.java:1028)
      at org.apache.derby.impl.sql.execute.InsertResultSet.open(InsertResultS\
      et.java:505)
      at org.apache.derby.impl.sql.GenericPreparedStatement.executeStmt(Gener\
      icPreparedStatement.java:436)
      at org.apache.derby.impl.sql.GenericPreparedStatement.execute(GenericPr\
      eparedStatement.java:317)
      at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStat\
      ement.java:1241)
      at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(E\
      ement.java:1241)
      at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(E\
      mbedPreparedStatement.java:1686)
      at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(Embe\
      dPreparedStatement.java:308)
      at org.apache.manifoldcf.core.database.Database.execute(Database.java:\
      606)
      at org.apache.manifoldcf.core.database.Database$ExecuteQueryThread.run\
      (Database.java:421)
      Cleanup action completed
      ----------------------------------------------------------------

        Issue Links

          Activity

          Hide
          Knut Anders Hatlen added a comment -

          [bulk update] Close all resolved issues that haven't been updated for more than one year.

          Show
          Knut Anders Hatlen added a comment - [bulk update] Close all resolved issues that haven't been updated for more than one year.
          Hide
          Karl Wright added a comment -

          Thanks for the advice; I'll rebuild and give it a try.

          Show
          Karl Wright added a comment - Thanks for the advice; I'll rebuild and give it a try.
          Hide
          Knut Anders Hatlen added a comment -

          The problem reported by the assert isn't fatal, and if you'd used non-debug jars, the code would just use a heuristic instead of the missing statistics and be able to continue. If you've built the jar files yourself, you can try this by running "ant clobber" and "ant insane" before "ant buildsource buildjars".

          Show
          Knut Anders Hatlen added a comment - The problem reported by the assert isn't fatal, and if you'd used non-debug jars, the code would just use a heuristic instead of the missing statistics and be able to continue. If you've built the jar files yourself, you can try this by running "ant clobber" and "ant insane" before "ant buildsource buildjars".
          Hide
          Karl Wright added a comment -

          Sure you can close this. It does look like the same bug. I thought the traces as recorded might be interesting, though.
          This is really easy to reproduce running the ManifoldCF test suite, but it is definitely intermittent. If you have additional diagnostics you'd like me to try, please let me know.

          Show
          Karl Wright added a comment - Sure you can close this. It does look like the same bug. I thought the traces as recorded might be interesting, though. This is really easy to reproduce running the ManifoldCF test suite, but it is definitely intermittent. If you have additional diagnostics you'd like me to try, please let me know.
          Hide
          Knut Anders Hatlen added a comment -

          The stack trace looks similar to DERBY-5153. Would it be OK to close this one as a duplicate?

          Show
          Knut Anders Hatlen added a comment - The stack trace looks similar to DERBY-5153 . Would it be OK to close this one as a duplicate?

            People

            • Assignee:
              Unassigned
              Reporter:
              Karl Wright
            • Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Development