[
https://issues.apache.org/jira/browse/JENA-131?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13147977#comment-13147977
]
Simon Helsen commented on JENA-131:
-----------------------------------
Ok, so I verified the fix. The problem described in this defect is certainly
gone. My multi-client scale test went through, mostly. My log at some point
indicated the following
15:08:39,977 [jazz.jfs.indexer.jfs_tests_default_consumer_name.triple] ERROR
com.ibm.team.jfs - Originating Exception:
com.hp.hpl.jena.tdb.TDBException: Different ids for
https://localhost:9443/jazz/storage/RequirementsArea_356f61ce-2959-4100-a758-37e3fa82d1b0/requirement1065.xml:
allocated: expected [00000000003B594E], got [00000000003B4D08]
at
com.hp.hpl.jena.tdb.transaction.NodeTableTrans.append(NodeTableTrans.java:178)
at
com.hp.hpl.jena.tdb.transaction.NodeTableTrans.writeNodeJournal(NodeTableTrans.java:210)
at
com.hp.hpl.jena.tdb.transaction.NodeTableTrans.commitPrepare(NodeTableTrans.java:190)
at
com.hp.hpl.jena.tdb.transaction.Transaction.prepare(Transaction.java:109)
at
com.hp.hpl.jena.tdb.transaction.Transaction.commit(Transaction.java:93)
at com.hp.hpl.jena.tdb.DatasetGraphTxn.commit(DatasetGraphTxn.java:38)
at
com.ibm.team.jfs.rdf.internal.jena.tdb.JenaTdbTxProvider.storeOperation(JenaTdbTxProvider.java:321)
...
15:08:39,983 [jazz.jfs.indexer.jfs_tests_default_consumer_name.triple] ERROR
com.ibm.team.jfs -
com.hp.hpl.jena.tdb.transaction.TDBTransactionException: Transaction has
already committed or aborted
But only once and this test was running 10 clients who were performing both
queries and write actions (ration 7 to 1). I don't know under what
circumstances I might be able to reproduce this, but did Paolo also not see
something like this recently? Having said this, this should probably become a
separate issue
(I still have to check JENA-143)
> 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
> Attachments: patch.txt, patch.txt
>
>
> 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
