[
https://issues.apache.org/jira/browse/JENA-131?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13123701#comment-13123701
]
Andy Seaborne commented on JENA-131:
------------------------------------
This looks like symptom rather than cause.
"QueryIteratorCheck - Open iterator" warnings often happen when things go
wrong. It's only if they occur without other errors that they provide useful
informatiom. Even then, the condition they test for is more one of style than
an internal error.
Is it possible that a transaction is being accessed concurrently? This
includes multiple reader access to the same transaction. That's the only way I
can see that this can happen but it's tricky to be sure without a test case.
The "iterators" is a list tracking iterators for internal checking but itself
is not integral to the action of transactions. protecting the .remove and just
logging a warning is possibly better.
Otherwise T_TransSystem (it was called TestSystemTrans) should find this - it
only have singe threaded access to each transaction, which is the only level of
guarantee transactional TDB makes at the moment. It's also the more usual
application access pattern.
> TxTDB problem during concurrent execution
> -----------------------------------------
>
> Key: JENA-131
> URL: https://issues.apache.org/jira/browse/JENA-131
> Project: Jena
> Issue Type: Bug
> Components: TDB
> Environment: arq-2.8.9-20111001.145524-39 and
> tx-tdb-0.9.0-20111006.082548-13 on IBM JRE 6
> Reporter: Simon Helsen
>
> In a massive concurrent test with many reads and writes, I am running into
> the problems shown below. I suspect the problem only occurs if a read and
> write are trying to operate on the same data at the same time, i.e. the
> transactions don't isolate enough. My test case is inside the framework. I
> currently have no test case for you to try, but I am hoping you can see
> something by inspecting the stack trace
> ModelWriteActivity: 1579ms
> 17:46:27,183 [1948218399@qtp-533667791-14] WARN
> hpl.jena.sparql.engine.iterator.QueryIteratorCheck - Open iterator:
> QueryIterConcat/55657
> 17:46:27,254 [1948218399@qtp-533667791-14] WARN
> hpl.jena.sparql.engine.iterator.QueryIteratorCheck - Open iterator:
> QueryIterSingleton/55658
> 17:46:27,257 [1948218399@qtp-533667791-14] WARN
> hpl.jena.sparql.engine.iterator.QueryIteratorCheck - Open iterator:
> QueryIterPeek/55659
> 17:46:27,261 [1948218399@qtp-533667791-14] WARN
> hpl.jena.sparql.engine.iterator.QueryIteratorCheck - Open iterator:
> QueryIterTDB/55660
> 17:46:27,264 [1948218399@qtp-533667791-14] WARN
> hpl.jena.sparql.engine.iterator.QueryIteratorCheck - Open iterator:
> QueryIterOptionalIndex/55661
> 17:46:27,335 [1948218399@qtp-533667791-14] WARN
> hpl.jena.sparql.engine.iterator.QueryIteratorCheck - Open iterator:
> QueryIterOptionalIndex/55662
> 17:46:27,338 [1948218399@qtp-533667791-14] WARN
> hpl.jena.sparql.engine.iterator.QueryIteratorCheck - Open iterator:
> QueryIterDefaulting/55803
> 17:46:27,395 [1948218399@qtp-533667791-14] WARN
> hpl.jena.sparql.engine.iterator.QueryIteratorCheck - Open iterator:
> QueryIterDefaulting/55807
> 17:46:27,399 [1948218399@qtp-533667791-14] WARN
> hpl.jena.sparql.engine.iterator.QueryIteratorCheck - Open iterator:
> QueryIterPeek/55808
> 17:46:27,403 [1948218399@qtp-533667791-14] WARN
> hpl.jena.sparql.engine.iterator.QueryIteratorCheck - Open iterator:
> QueryIterTDB/55809
> 17:46:27,406 [1948218399@qtp-533667791-14] WARN
> hpl.jena.sparql.engine.iterator.QueryIteratorCheck - Open iterator:
> QueryIterAssign/55810
> 17:46:27,410 [1948218399@qtp-533667791-14] WARN
> hpl.jena.sparql.engine.iterator.QueryIteratorCheck - Open iterator:
> QueryIterSingleton/55811
> 17:46:27,490 [1948218399@qtp-533667791-14] WARN
> hpl.jena.sparql.engine.iterator.QueryIteratorCheck - Open iterator:
> QueryIterPeek/55812
> 17:46:27,493 [1948218399@qtp-533667791-14] WARN
> hpl.jena.sparql.engine.iterator.QueryIteratorCheck - Open iterator:
> QueryIterTDB/55813
> 17:46:27,497 [1948218399@qtp-533667791-14] WARN
> hpl.jena.sparql.engine.iterator.QueryIteratorCheck - Open iterator:
> QueryIterOptionalIndex/55814
> 17:46:27,502 [1948218399@qtp-533667791-14] WARN
> hpl.jena.sparql.engine.iterator.QueryIteratorCheck - Open iterator:
> QueryIterOptionalIndex/55815
> 17:46:27,507 [1948218399@qtp-533667791-14] ERROR com.ibm.team.jfs
> - Originating Exception:
> java.lang.IndexOutOfBoundsException: Index: 20, Size: 18
> at java.util.ArrayList.remove(ArrayList.java:552)
> at java.util.ArrayList.remove(ArrayList.java:572)
> at
> com.hp.hpl.jena.tdb.transaction.Transaction.removeIterator(Transaction.java:188)
> at
> com.hp.hpl.jena.tdb.transaction.BlockMgrJournal.endIterator(BlockMgrJournal.java:312)
> at
> com.hp.hpl.jena.tdb.transaction.BlockMgrJournal.endIterator(BlockMgrJournal.java:313)
> at
> com.hp.hpl.jena.tdb.base.block.BlockMgrWrapper.endIterator(BlockMgrWrapper.java:134)
> at
> com.hp.hpl.jena.tdb.base.recordbuffer.RecordRangeIterator.close(RecordRangeIterator.java:155)
> at
> com.hp.hpl.jena.tdb.base.recordbuffer.RecordRangeIterator.hasNext(RecordRangeIterator.java:112)
> at org.openjena.atlas.iterator.Iter$4.hasNext(Iter.java:274)
> at
> com.hp.hpl.jena.tdb.sys.DatasetControlMRSW$IteratorCheckNotConcurrent.hasNext(DatasetControlMRSW.java:119)
> at org.openjena.atlas.iterator.Iter$3.hasNext(Iter.java:164)
> at org.openjena.atlas.iterator.Iter$6.hasNext(Iter.java:359)
> at org.openjena.atlas.iterator.Iter$3.hasNext(Iter.java:164)
> at org.openjena.atlas.iterator.Iter$4.hasNext(Iter.java:274)
> at org.openjena.atlas.iterator.Iter$3.hasNext(Iter.java:164)
> at org.openjena.atlas.iterator.Iter.hasNext(Iter.java:742)
> at
> org.openjena.atlas.iterator.RepeatApplyIterator.hasNext(RepeatApplyIterator.java:58)
> at
> org.openjena.atlas.iterator.RepeatApplyIterator.hasNext(RepeatApplyIterator.java:46)
> at
> org.openjena.atlas.iterator.RepeatApplyIterator.hasNext(RepeatApplyIterator.java:46)
> at
> org.openjena.atlas.iterator.RepeatApplyIterator.hasNext(RepeatApplyIterator.java:46)
> at
> org.openjena.atlas.iterator.RepeatApplyIterator.hasNext(RepeatApplyIterator.java:46)
> at org.openjena.atlas.iterator.Iter$4.hasNext(Iter.java:274)
> at
> com.hp.hpl.jena.sparql.engine.iterator.QueryIterPlainWrapper.hasNextBinding(QueryIterPlainWrapper.java:54)
> at
> com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorBase.hasNext(QueryIteratorBase.java:107)
> at
> com.hp.hpl.jena.sparql.engine.iterator.QueryIterRepeatApply.makeNextStage(QueryIterRepeatApply.java:106)
> at
> com.hp.hpl.jena.sparql.engine.iterator.QueryIterRepeatApply.hasNextBinding(QueryIterRepeatApply.java:65)
> at
> com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorBase.hasNext(QueryIteratorBase.java:107)
> at
> com.hp.hpl.jena.sparql.engine.iterator.QueryIterRepeatApply.makeNextStage(QueryIterRepeatApply.java:106)
> at
> com.hp.hpl.jena.sparql.engine.iterator.QueryIterRepeatApply.hasNextBinding(QueryIterRepeatApply.java:65)
> at
> com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorBase.hasNext(QueryIteratorBase.java:107)
> at
> com.hp.hpl.jena.tdb.solver.OpExecutorTDB.optimizeExecuteQuads(OpExecutorTDB.java:215)
> at
> com.hp.hpl.jena.tdb.solver.OpExecutorTDB.execute(OpExecutorTDB.java:152)
> at
> com.hp.hpl.jena.sparql.engine.main.ExecutionDispatch.visit(ExecutionDispatch.java:63)
> at
> com.hp.hpl.jena.sparql.algebra.op.OpQuadPattern.visit(OpQuadPattern.java:97)
> at
> com.hp.hpl.jena.sparql.engine.main.ExecutionDispatch.exec(ExecutionDispatch.java:43)
> at
> com.hp.hpl.jena.sparql.engine.main.OpExecutor.executeOp(OpExecutor.java:119)
> at
> com.hp.hpl.jena.sparql.engine.main.OpExecutor.execute(OpExecutor.java:208)
> at
> com.hp.hpl.jena.sparql.engine.main.ExecutionDispatch.visit(ExecutionDispatch.java:105)
> at
> com.hp.hpl.jena.sparql.algebra.op.OpSequence.visit(OpSequence.java:73)
> at
> com.hp.hpl.jena.sparql.engine.main.ExecutionDispatch.exec(ExecutionDispatch.java:45)
> at
> com.hp.hpl.jena.sparql.engine.main.OpExecutor.executeOp(OpExecutor.java:119)
> at
> com.hp.hpl.jena.sparql.engine.main.OpExecutor.execute(OpExecutor.java:464)
> at
> com.hp.hpl.jena.sparql.engine.main.ExecutionDispatch.visit(ExecutionDispatch.java:246)
> at com.hp.hpl.jena.sparql.algebra.op.OpAssign.visit(OpAssign.java:116)
> at
> com.hp.hpl.jena.sparql.engine.main.ExecutionDispatch.exec(ExecutionDispatch.java:45)
> at
> com.hp.hpl.jena.sparql.engine.main.OpExecutor.executeOp(OpExecutor.java:119)
> at
> com.hp.hpl.jena.sparql.engine.main.OpExecutor.execute(OpExecutor.java:92)
> at com.hp.hpl.jena.sparql.engine.main.QC.execute(QC.java:52)
> at
> com.hp.hpl.jena.sparql.engine.main.iterator.QueryIterUnion.nextStage(QueryIterUnion.java:55)
> at
> com.hp.hpl.jena.sparql.engine.iterator.QueryIterRepeatApply.makeNextStage(QueryIterRepeatApply.java:113)
> at
> com.hp.hpl.jena.sparql.engine.iterator.QueryIterRepeatApply.hasNextBinding(QueryIterRepeatApply.java:65)
> at
> com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorBase.hasNext(QueryIteratorBase.java:107)
> at
> com.hp.hpl.jena.sparql.engine.iterator.QueryIterConvert.hasNextBinding(QueryIterConvert.java:65)
> at
> com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorBase.hasNext(QueryIteratorBase.java:107)
> at
> com.hp.hpl.jena.sparql.engine.iterator.QueryIterSlice.hasNextBinding(QueryIterSlice.java:76)
> at
> com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorBase.hasNext(QueryIteratorBase.java:107)
> at
> com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorWrapper.hasNextBinding(QueryIteratorWrapper.java:40)
> at
> com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorBase.hasNext(QueryIteratorBase.java:107)
> at
> com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorWrapper.hasNextBinding(QueryIteratorWrapper.java:40)
> at
> com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorBase.hasNext(QueryIteratorBase.java:107)
> at
> com.hp.hpl.jena.sparql.engine.ResultSetStream.hasNext(ResultSetStream.java:70)
> at
> com.hp.hpl.jena.sparql.engine.QueryExecutionBase.execDescribe(QueryExecutionBase.java:278)
> at
> com.hp.hpl.jena.sparql.engine.QueryExecutionBase.execDescribe(QueryExecutionBase.java:256)
> <snip>
> DataSetReadActivity: 1249ms
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators:
https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira
