[ https://issues.apache.org/jira/browse/JENA-546?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Mark Buquor updated JENA-546: ----------------------------- Affects Version/s: TDB 1.0.0 > 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