Details

    • Type: Bug
    • Status: Done
    • Resolution: Done
    • Affects Version/s: JOURNAL_HA_BRANCH
    • Fix Version/s: None
    • Component/s: RWStore

      Description

      LUBM U50 fails during closure computation against RWStore r4012.

           [java] Load: 6890949 stmts added in 121.193 secs, rate= 56858, commitLatency=0ms
      
      ...
      
          [java] LUBM_U50.lex.ID2TERM{nodes=404,leaves=25447, bytes=110094704, averageBytesPerRecord=4258}, LUBM_U50.lex.TERM2ID{nodes=639,leaves=37491, bytes=140111692, averageBytesPerRecord=3674}, LUBM_U50.spo.POS{nodes=9,leaves=12579, bytes=50583058, averageBytesPerRecord=4018}, LUBM_U50.spo.SPO{nodes=83,leaves=22376, bytes=83627476, averageBytesPerRecord=3723}, LUBM_U50.spo.OSP{nodes=113,leaves=34008, bytes=138103883, averageBytesPerRecord=4047}
           [java] Computing closure.
           [java] Exception in thread "main" java.lang.RuntimeException: java.lang.RuntimeException: Could not commit index: name=LUBM_U50.spo.OSP, commitList=[DirtyListener{name=LUBM_U50.spo.OSP,needsCheckpoint}, DirtyListener{name=LUBM_U50.spo.POS,needsCheckpoint}, DirtyListener{name=LUBM_U50.spo.SPO,needsCheckpoint}]
           [java] 	at com.bigdata.rdf.rules.InferenceEngine.computeClosure(InferenceEngine.java:572)
           [java] 	at com.bigdata.rdf.rules.InferenceEngine.computeClosure(InferenceEngine.java:486)
           [java] 	at com.bigdata.rdf.store.DataLoader.doClosure(DataLoader.java:1172)
           [java] 	at com.bigdata.rdf.store.DataLoader.main(DataLoader.java:1394)
           [java] Caused by: java.lang.RuntimeException: Could not commit index: name=LUBM_U50.spo.OSP, commitList=[DirtyListener{name=LUBM_U50.spo.OSP,needsCheckpoint}, DirtyListener{name=LUBM_U50.spo.POS,needsCheckpoint}, DirtyListener{name=LUBM_U50.spo.SPO,needsCheckpoint}]
           [java] 	at com.bigdata.journal.Name2Addr.handleCommit(Name2Addr.java:570)
           [java] 	at com.bigdata.journal.AbstractJournal.notifyCommitters(AbstractJournal.java:1968)
           [java] 	at com.bigdata.journal.AbstractJournal.commitNow(AbstractJournal.java:2311)
           [java] 	at com.bigdata.journal.AbstractJournal.commit(AbstractJournal.java:2229)
           [java] 	at com.bigdata.relation.rule.eval.ProgramTask.executeMutation(ProgramTask.java:495)
           [java] 	at com.bigdata.relation.rule.eval.ProgramTask.executeProgramWithEmbeddedClosure(ProgramTask.java:752)
           [java] 	at com.bigdata.relation.rule.eval.ProgramTask.call(ProgramTask.java:260)
           [java] 	at com.bigdata.rdf.rules.RDFJoinNexus.runLocalProgram(RDFJoinNexus.java:1772)
           [java] 	at com.bigdata.rdf.rules.RDFJoinNexus.runProgram(RDFJoinNexus.java:1752)
           [java] 	at com.bigdata.rdf.rules.RDFJoinNexus.runMutation(RDFJoinNexus.java:1701)
           [java] 	at com.bigdata.rdf.rules.InferenceEngine.computeClosure(InferenceEngine.java:564)
           [java] 	... 3 more
           [java] Caused by: java.lang.AssertionError: Record exists for offset in cache: offset=977850368
           [java] 	at com.bigdata.io.writecache.WriteCache.write(WriteCache.java:757)
           [java] 	at com.bigdata.io.writecache.WriteCacheService.write(WriteCacheService.java:1460)
           [java] 	at com.bigdata.io.writecache.WriteCacheService.write(WriteCacheService.java:1371)
           [java] 	at com.bigdata.rwstore.RWStore.alloc(RWStore.java:1964)
           [java] 	at com.bigdata.journal.RWStrategy.write(RWStrategy.java:211)
           [java] 	at com.bigdata.journal.RWStrategy.write(RWStrategy.java:176)
           [java] 	at com.bigdata.journal.AbstractJournal.write(AbstractJournal.java:2638)
           [java] 	at com.bigdata.btree.AbstractBTree.writeNodeOrLeaf(AbstractBTree.java:3734)
           [java] 	at com.bigdata.btree.AbstractBTree.writeNodeRecursive(AbstractBTree.java:3546)
           [java] 	at com.bigdata.btree.BTree.flush(BTree.java:723)
           [java] 	at com.bigdata.btree.BTree.writeCheckpoint2(BTree.java:863)
           [java] 	at com.bigdata.btree.BTree.writeCheckpoint(BTree.java:834)
           [java] 	at com.bigdata.btree.BTree.handleCommit(BTree.java:1137)
           [java] 	at com.bigdata.journal.Name2Addr.handleCommit(Name2Addr.java:562)
           [java] 	... 13 more
      

      When I turned WriteCacheBLZG-843 into a warning, I then encountered this in WriteCacheService.

         [java] Computing closure.
           [java] Exception in thread "main" java.lang.RuntimeException: java.lang.RuntimeException: Could not commit index: name=LUBM_U50.spo.OSP, commitList=[DirtyListener{name=LUBM_U50.spo.OSP,needsCheckpoint}, DirtyListener{name=LUBM_U50.spo.POS,needsCheckpoint}, DirtyListener{name=LUBM_U50.spo.SPO,needsCheckpoint}]
           [java] 	at com.bigdata.rdf.rules.InferenceEngine.computeClosure(InferenceEngine.java:572)
           [java] 	at com.bigdata.rdf.rules.InferenceEngine.computeClosure(InferenceEngine.java:486)
           [java] 	at com.bigdata.rdf.store.DataLoader.doClosure(DataLoader.java:1172)
           [java] 	at com.bigdata.rdf.store.DataLoader.main(DataLoader.java:1394)
           [java] Caused by: java.lang.RuntimeException: Could not commit index: name=LUBM_U50.spo.OSP, commitList=[DirtyListener{name=LUBM_U50.spo.OSP,needsCheckpoint}, DirtyListener{name=LUBM_U50.spo.POS,needsCheckpoint}, DirtyListener{name=LUBM_U50.spo.SPO,needsCheckpoint}]
           [java] 	at com.bigdata.journal.Name2Addr.handleCommit(Name2Addr.java:570)
           [java] 	at com.bigdata.journal.AbstractJournal.notifyCommitters(AbstractJournal.java:1968)
           [java] 	at com.bigdata.journal.AbstractJournal.commitNow(AbstractJournal.java:2311)
           [java] 	at com.bigdata.journal.AbstractJournal.commit(AbstractJournal.java:2229)
           [java] 	at com.bigdata.relation.rule.eval.ProgramTask.executeMutation(ProgramTask.java:495)
           [java] 	at com.bigdata.relation.rule.eval.ProgramTask.executeProgramWithEmbeddedClosure(ProgramTask.java:752)
           [java] 	at com.bigdata.relation.rule.eval.ProgramTask.call(ProgramTask.java:260)
           [java] 	at com.bigdata.rdf.rules.RDFJoinNexus.runLocalProgram(RDFJoinNexus.java:1772)
           [java] 	at com.bigdata.rdf.rules.RDFJoinNexus.runProgram(RDFJoinNexus.java:1752)
           [java] 	at com.bigdata.rdf.rules.RDFJoinNexus.runMutation(RDFJoinNexus.java:1701)
           [java] 	at com.bigdata.rdf.rules.InferenceEngine.computeClosure(InferenceEngine.java:564)
           [java] 	... 3 more
           [java] Caused by: java.lang.AssertionError: Record already in cache: offset=977850368
           [java] 	at com.bigdata.io.writecache.WriteCacheService.write(WriteCacheService.java:1468)
           [java] 	at com.bigdata.io.writecache.WriteCacheService.write(WriteCacheService.java:1371)
           [java] 	at com.bigdata.rwstore.RWStore.alloc(RWStore.java:1964)
           [java] 	at com.bigdata.journal.RWStrategy.write(RWStrategy.java:211)
           [java] 	at com.bigdata.journal.RWStrategy.write(RWStrategy.java:176)
           [java] 	at com.bigdata.journal.AbstractJournal.write(AbstractJournal.java:2638)
           [java] 	at com.bigdata.btree.AbstractBTree.writeNodeOrLeaf(AbstractBTree.java:3734)
           [java] 	at com.bigdata.btree.AbstractBTree.writeNodeRecursive(AbstractBTree.java:3546)
           [java] 	at com.bigdata.btree.BTree.flush(BTree.java:723)
           [java] 	at com.bigdata.btree.BTree.writeCheckpoint2(BTree.java:863)
           [java] 	at com.bigdata.btree.BTree.writeCheckpoint(BTree.java:834)
           [java] 	at com.bigdata.btree.BTree.handleCommit(BTree.java:1137)
           [java] 	at com.bigdata.journal.Name2Addr.handleCommit(Name2Addr.java:562)
           [java] 	... 13 more
      
      

      And if I turn WriteCacheService#1468 into a warning as well, I then see this:

           [java] Exception in thread "main" java.lang.RuntimeException: java.util.concurrent.ExecutionException: java.util.concurrent.ExecutionException: java.lang.RuntimeException: com.bigdata.util.concurrent.ExecutionExceptions: 1 errors : [java.util.concurrent.ExecutionException: java.util.concurrent.ExecutionException: java.lang.RuntimeException: java.lang.RuntimeException: java.lang.RuntimeException: java.lang.RuntimeException: java.lang.RuntimeException: java.util.concurrent.ExecutionException: java.lang.IllegalArgumentException: Unable to read data]
           [java] 	at com.bigdata.rdf.rules.InferenceEngine.computeClosure(InferenceEngine.java:572)
           [java] 	at com.bigdata.rdf.rules.InferenceEngine.computeClosure(InferenceEngine.java:486)
           [java] 	at com.bigdata.rdf.store.DataLoader.doClosure(DataLoader.java:1172)
           [java] 	at com.bigdata.rdf.store.DataLoader.main(DataLoader.java:1394)
           [java] Caused by: java.util.concurrent.ExecutionException: java.util.concurrent.ExecutionException: java.lang.RuntimeException: com.bigdata.util.concurrent.ExecutionExceptions: 1 errors : [java.util.concurrent.ExecutionException: java.util.concurrent.ExecutionException: java.lang.RuntimeException: java.lang.RuntimeException: java.lang.RuntimeException: java.lang.RuntimeException: java.lang.RuntimeException: java.util.concurrent.ExecutionException: java.lang.IllegalArgumentException: Unable to read data]
           [java] 	at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:222)
           [java] 	at java.util.concurrent.FutureTask.get(FutureTask.java:83)
           [java] 	at com.bigdata.relation.rule.eval.ProgramTask.executeMutation(ProgramTask.java:526)
           [java] 	at com.bigdata.relation.rule.eval.ProgramTask.executeProgramWithEmbeddedClosure(ProgramTask.java:752)
           [java] 	at com.bigdata.relation.rule.eval.ProgramTask.call(ProgramTask.java:260)
           [java] 	at com.bigdata.rdf.rules.RDFJoinNexus.runLocalProgram(RDFJoinNexus.java:1772)
           [java] 	at com.bigdata.rdf.rules.RDFJoinNexus.runProgram(RDFJoinNexus.java:1752)
           [java] 	at com.bigdata.rdf.rules.RDFJoinNexus.runMutation(RDFJoinNexus.java:1701)
           [java] 	at com.bigdata.rdf.rules.InferenceEngine.computeClosure(InferenceEngine.java:564)
           [java] 	... 3 more
           [java] Caused by: java.util.concurrent.ExecutionException: java.lang.RuntimeException: com.bigdata.util.concurrent.ExecutionExceptions: 1 errors : [java.util.concurrent.ExecutionException: java.util.concurrent.ExecutionException: java.lang.RuntimeException: java.lang.RuntimeException: java.lang.RuntimeException: java.lang.RuntimeException: java.lang.RuntimeException: java.util.concurrent.ExecutionException: java.lang.IllegalArgumentException: Unable to read data]
           [java] 	at com.bigdata.relation.rule.eval.AbstractStepTask.runOne(AbstractStepTask.java:309)
           [java] 	at com.bigdata.relation.rule.eval.MutationTask.call(MutationTask.java:118)
           [java] 	at com.bigdata.relation.rule.eval.MutationTask.call(MutationTask.java:55)
           [java] 	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
           [java] 	at java.util.concurrent.FutureTask.run(FutureTask.java:138)
           [java] 	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
           [java] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
           [java] 	at java.lang.Thread.run(Thread.java:619)
           [java] Caused by: java.lang.RuntimeException: com.bigdata.util.concurrent.ExecutionExceptions: 1 errors : [java.util.concurrent.ExecutionException: java.util.concurrent.ExecutionException: java.lang.RuntimeException: java.lang.RuntimeException: java.lang.RuntimeException: java.lang.RuntimeException: java.lang.RuntimeException: java.util.concurrent.ExecutionException: java.lang.IllegalArgumentException: Unable to read data]
           [java] 	at com.bigdata.relation.rule.eval.pipeline.JoinMasterTask.call(JoinMasterTask.java:453)
           [java] 	at com.bigdata.relation.rule.eval.pipeline.JoinMasterTask.call(JoinMasterTask.java:252)
           [java] 	at com.bigdata.relation.rule.eval.AbstractStepTask.runOne(AbstractStepTask.java:307)
           [java] 	... 7 more
           [java] Caused by: com.bigdata.util.concurrent.ExecutionExceptions: 1 errors : [java.util.concurrent.ExecutionException: java.util.concurrent.ExecutionException: java.lang.RuntimeException: java.lang.RuntimeException: java.lang.RuntimeException: java.lang.RuntimeException: java.lang.RuntimeException: java.util.concurrent.ExecutionException: java.lang.IllegalArgumentException: Unable to read data]
           [java] 	at com.bigdata.relation.rule.eval.pipeline.JoinMasterTask.awaitAll(JoinMasterTask.java:640)
           [java] 	at com.bigdata.relation.rule.eval.pipeline.JoinMasterTask.call(JoinMasterTask.java:389)
           [java] 	... 9 more
      

      However, if I modify RWStore#1592 as follows:

      				if (false&&m_minReleaseAge == 0) {
      

      Then the closure is computed correctly. That is, this is clearly an interaction with the optimization to use session for improved recycling when transactions are also in use.

        Activity

        Hide
        martyncutcher martyncutcher added a comment -

        This problem is related to the freeing of session protected allocations. When the session finally releases the allocations to be recycled it must clear any writes from the writeCache. The data must remain in the writeCache until this point since it is possible that transactions will require access to unwritten allocations.

        The error was in the calculation of the physical addresses to be cleared for high bit offsets in an AllocBlock.

        Fixed in r4023

        Show
        martyncutcher martyncutcher added a comment - This problem is related to the freeing of session protected allocations. When the session finally releases the allocations to be recycled it must clear any writes from the writeCache. The data must remain in the writeCache until this point since it is possible that transactions will require access to unwritten allocations. The error was in the calculation of the physical addresses to be cleared for high bit offsets in an AllocBlock. Fixed in r4023

          People

          • Assignee:
            martyncutcher martyncutcher
            Reporter:
            bryanthompson bryanthompson
          • Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved: