Details
-
Bug
-
Status: Closed
-
Major
-
Resolution: Cannot Reproduce
-
TDB 0.10.1, TDB 1.0.0
-
None
Description
We've found two queries so far that fail to time out in a reasonable time after the timeout elapses. The severity of the issue varies. In one case, the query completes without error ~30 minutes after it should have aborted. In the other case, the query runs indefinitely.
Beyond wasted resources, the critical issue for us is that queries must reliably abort in order for TDB to flush the writeback queue. Failure to flush the queue leads to stack overflows and heap exhaustion.
I haven't been able to isolate a testcase yet, but in both cases, the problem appears to be isolated to an OPTIONAL block. Running under the debugger, the process was suspended after the query should have aborted. I placed comments in the stack below to show 1) the last iterator in the stack with abortFlag == true and 2) the QueryIterPeek directly above it has abortIterator == false. All iterators above the first comment have not been aborted, so it appears that the abort signal does not propagate sufficiently.
I'm not sure if this affects ARQ in general. I'm filing this against TDB because the QueryIterTDB below the comments is the last to have requestCancel() called. Its killList includes the two IterAbortables directly above it. Nothing else above that QueryIterTDB is aborted.
Thread [main] (Suspended) com.hp.hpl.jena.tdb.index.bplustree.BPTreeNode.recordsPageId(com.hp.hpl.jena.tdb.index.bplustree.BPTreeNode, com.hp.hpl.jena.tdb.base.record.Record) line: 277 com.hp.hpl.jena.tdb.index.bplustree.BPlusTree.iterator(com.hp.hpl.jena.tdb.index.bplustree.BPTreeNode, com.hp.hpl.jena.tdb.base.record.Record, com.hp.hpl.jena.tdb.base.record.Record) line: 378 com.hp.hpl.jena.tdb.index.bplustree.BPlusTree.iterator(com.hp.hpl.jena.tdb.base.record.Record, com.hp.hpl.jena.tdb.base.record.Record) line: 366 com.hp.hpl.jena.tdb.index.TupleIndexRecord.findWorker(org.apache.jena.atlas.lib.Tuple<com.hp.hpl.jena.tdb.store.NodeId>, boolean, boolean) line: 164 com.hp.hpl.jena.tdb.index.TupleIndexRecord.findOrScan(org.apache.jena.atlas.lib.Tuple<com.hp.hpl.jena.tdb.store.NodeId>) line: 84 com.hp.hpl.jena.tdb.index.TupleIndexRecord.performFind(org.apache.jena.atlas.lib.Tuple<com.hp.hpl.jena.tdb.store.NodeId>) line: 78 com.hp.hpl.jena.tdb.index.TupleIndexRecord(com.hp.hpl.jena.tdb.index.TupleIndexBase).find(org.apache.jena.atlas.lib.Tuple<com.hp.hpl.jena.tdb.store.NodeId>) line: 91 com.hp.hpl.jena.tdb.index.TupleTable.find(org.apache.jena.atlas.lib.Tuple<com.hp.hpl.jena.tdb.store.NodeId>) line: 197 com.hp.hpl.jena.tdb.nodetable.NodeTupleTableConcrete.find(org.apache.jena.atlas.lib.Tuple<com.hp.hpl.jena.tdb.store.NodeId>) line: 169 com.hp.hpl.jena.tdb.solver.StageMatchTuple.makeNextStage(com.hp.hpl.jena.tdb.solver.BindingNodeId) line: 91 com.hp.hpl.jena.tdb.solver.StageMatchTuple.makeNextStage(java.lang.Object) line: 37 com.hp.hpl.jena.tdb.solver.StageMatchTuple(org.apache.jena.atlas.iterator.RepeatApplyIterator<T>).hasNext() line: 49 com.hp.hpl.jena.tdb.solver.SolverLib$IterAbortable<T>.hasNext() line: 193 org.apache.jena.atlas.iterator.Iter$4.hasNext() line: 293 com.hp.hpl.jena.tdb.solver.QueryIterTDB(com.hp.hpl.jena.sparql.engine.iterator.QueryIterPlainWrapper).hasNextBinding() line: 54 com.hp.hpl.jena.tdb.solver.QueryIterTDB(com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorBase).hasNext() line: 112 com.hp.hpl.jena.sparql.engine.iterator.QueryIterDefaulting.hasNextBinding() line: 54 com.hp.hpl.jena.sparql.engine.iterator.QueryIterDefaulting(com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorBase).hasNext() line: 112 com.hp.hpl.jena.sparql.engine.main.iterator.QueryIterOptionalIndex(com.hp.hpl.jena.sparql.engine.iterator.QueryIterRepeatApply).hasNextBinding() line: 81 com.hp.hpl.jena.sparql.engine.main.iterator.QueryIterOptionalIndex(com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorBase).hasNext() line: 112 #### abortIterator == false #### com.hp.hpl.jena.sparql.engine.iterator.QueryIterPeek.hasNextBinding() line: 57 com.hp.hpl.jena.sparql.engine.iterator.QueryIterPeek(com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorBase).hasNext() line: 112 org.apache.jena.atlas.iterator.Iter$4.hasNext() line: 293 com.hp.hpl.jena.tdb.solver.StageMatchTuple(org.apache.jena.atlas.iterator.RepeatApplyIterator<T>).hasNext() line: 46 #### abortFlag == true #### com.hp.hpl.jena.tdb.solver.SolverLib$IterAbortable<T>.hasNext() line: 193 com.hp.hpl.jena.tdb.solver.StageMatchTuple(org.apache.jena.atlas.iterator.RepeatApplyIterator<T>).hasNext() line: 46 com.hp.hpl.jena.tdb.solver.SolverLib$IterAbortable<T>.hasNext() line: 193 org.apache.jena.atlas.iterator.Iter$4.hasNext() line: 293 com.hp.hpl.jena.tdb.solver.QueryIterTDB(com.hp.hpl.jena.sparql.engine.iterator.QueryIterPlainWrapper).hasNextBinding() line: 54 com.hp.hpl.jena.tdb.solver.QueryIterTDB(com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorBase).hasNext() line: 112 com.hp.hpl.jena.sparql.engine.iterator.QueryIterFilterExpr(com.hp.hpl.jena.sparql.engine.iterator.QueryIterProcessBinding).hasNextBinding() line: 60 com.hp.hpl.jena.sparql.engine.iterator.QueryIterFilterExpr(com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorBase).hasNext() line: 112 com.hp.hpl.jena.sparql.engine.iterator.QueryIterGroup$1.initializeIterator() line: 86 com.hp.hpl.jena.sparql.engine.iterator.QueryIterGroup$1(org.apache.jena.atlas.iterator.IteratorDelayedInitialization<T>).init() line: 40 com.hp.hpl.jena.sparql.engine.iterator.QueryIterGroup$1(org.apache.jena.atlas.iterator.IteratorDelayedInitialization<T>).hasNext() line: 50 com.hp.hpl.jena.sparql.engine.iterator.QueryIterGroup(com.hp.hpl.jena.sparql.engine.iterator.QueryIterPlainWrapper).hasNextBinding() line: 54 com.hp.hpl.jena.sparql.engine.iterator.QueryIterGroup(com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorBase).hasNext() line: 112 com.hp.hpl.jena.sparql.engine.iterator.QueryIterAssign(com.hp.hpl.jena.sparql.engine.iterator.QueryIterProcessBinding).hasNextBinding() line: 60 com.hp.hpl.jena.sparql.engine.iterator.QueryIterAssign(com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorBase).hasNext() line: 112 org.apache.jena.atlas.data.SortedDataBag<E>(org.apache.jena.atlas.data.AbstractDataBag<E>).addAll(java.util.Iterator<? extends E>) line: 74 com.hp.hpl.jena.sparql.engine.iterator.QueryIterSort$SortedBindingIterator.initializeIterator() line: 89 com.hp.hpl.jena.sparql.engine.iterator.QueryIterSort$SortedBindingIterator(org.apache.jena.atlas.iterator.IteratorDelayedInitialization<T>).init() line: 40 com.hp.hpl.jena.sparql.engine.iterator.QueryIterSort$SortedBindingIterator(org.apache.jena.atlas.iterator.IteratorDelayedInitialization<T>).hasNext() line: 50 com.hp.hpl.jena.sparql.engine.iterator.QueryIterSort(com.hp.hpl.jena.sparql.engine.iterator.QueryIterPlainWrapper).hasNextBinding() line: 54 com.hp.hpl.jena.sparql.engine.iterator.QueryIterSort(com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorBase).hasNext() line: 112 com.hp.hpl.jena.sparql.engine.iterator.QueryIterProject(com.hp.hpl.jena.sparql.engine.iterator.QueryIterConvert).hasNextBinding() line: 59 com.hp.hpl.jena.sparql.engine.iterator.QueryIterProject(com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorBase).hasNext() line: 112 com.hp.hpl.jena.sparql.engine.iterator.QueryIterSlice.hasNextBinding() line: 76 com.hp.hpl.jena.sparql.engine.iterator.QueryIterSlice(com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorBase).hasNext() line: 112 com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorCheck(com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorWrapper).hasNextBinding() line: 40 com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorCheck(com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorBase).hasNext() line: 112 com.hp.hpl.jena.tdb.solver.QueryEngineTDB$QueryIteratorMaterializeBinding(com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorWrapper).hasNextBinding() line: 40 com.hp.hpl.jena.tdb.solver.QueryEngineTDB$QueryIteratorMaterializeBinding(com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorBase).hasNext() line: 112 com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorCloseable(com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorWrapper).hasNextBinding() line: 40 com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorCloseable(com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorBase).hasNext() line: 112 com.hp.hpl.jena.sparql.engine.ResultSetStream.hasNext() line: 75 com.hp.hpl.jena.sparql.resultset.ResultSetMem.<init>(com.hp.hpl.jena.query.ResultSet) line: 97 com.hp.hpl.jena.query.ResultSetFactory.makeRewindable(com.hp.hpl.jena.query.ResultSet) line: 420 com.hp.hpl.jena.sparql.resultset.TextOutput.write(java.io.PrintWriter, com.hp.hpl.jena.query.ResultSet, java.lang.String, java.lang.String, java.lang.String) line: 149 com.hp.hpl.jena.sparql.resultset.TextOutput.write(java.io.OutputStream, com.hp.hpl.jena.query.ResultSet, java.lang.String, java.lang.String, java.lang.String) line: 132 com.hp.hpl.jena.sparql.resultset.TextOutput.write(java.io.OutputStream, com.hp.hpl.jena.query.ResultSet) line: 120 com.hp.hpl.jena.sparql.resultset.TextOutput.format(java.io.OutputStream, com.hp.hpl.jena.query.ResultSet) line: 67 com.hp.hpl.jena.query.ResultSetFormatter.out(java.io.OutputStream, com.hp.hpl.jena.query.ResultSet, com.hp.hpl.jena.sparql.core.Prologue) line: 135 com.hp.hpl.jena.query.ResultSetFormatter.out(com.hp.hpl.jena.query.ResultSet, com.hp.hpl.jena.query.Query) line: 83 Rogue.test() line: 67