[
https://issues.apache.org/jira/browse/JENA-546?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Mark Buquor updated JENA-546:
-----------------------------
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.
{noformat}
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
{noformat}
was:
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
> Query timeout not observed in OPTIONAL eval
> -------------------------------------------
>
> Key: JENA-546
> URL: https://issues.apache.org/jira/browse/JENA-546
> Project: Apache Jena
> Issue Type: Bug
> Components: TDB
> Affects Versions: TDB 0.10.1
> Reporter: Mark Buquor
> Priority: Critical
>
> 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.
> {noformat}
> 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
> {noformat}
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
