[
https://issues.apache.org/jira/browse/JENA-546?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13778618#comment-13778618
]
Andy Seaborne commented on JENA-546:
------------------------------------
Simon - those are not optimizations suggestions (point 3 above). I was hoping
to get more information about what is going on. I can't run the query; all I
can do is ask questions and act on answers.
Can we focus on the current 1.0.1-SNAPSHOT please? I'll feed anything I
discover in any code review I do. However, even if something is found, I can't
know whether it is this issue.
A more minimal query example would be extremely helpful as would the converse -
knowing the essential features of the query needed to provoke the situation.
It is not clear to me whether the structural complexity of the query is part of
the issue, the bug being in that some part of the code used, or just adding to
the cost of the query and the bug can be seen in a simpler query, pointing to
elsewhere in the code. Even your CPU comment is new information; there are
only certain places where CPU-parallelism occurs. Are the total results from
the query quite large? How many ?req groups are there?
The {{NOT EXISTS}} is a potential clearer way of writing the filter. YMMV.
> 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, TDB 1.0.0
> Reporter: Mark Buquor
> Attachments: query1.txt
>
>
> 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
