thanks for the quick analysis. I am pretty sure there is no concurrent access inside one active transaction (Our code doesn't do that kind of thing). But we are using TDB's ability to insert a quad filter and during the query calculations, you escape to our registered filter which may on its turn perform a graph find action. This is what you can see in the stack trace, i.e. we enter ARQ in com.hp.hpl.jena.sparql.engine.ResultSetStream.hasNext and Jena jumps back in org.openjena.atlas.iterator.RepeatApplyIterator.hasNext, which then calls com.hp.hpl.jena.tdb.migrate.DatasetGraphTrackActive.find. However, it all happens in one and the same thread.
Can you tell me what classes I need to look at? I will probably have to backport and patch 2.7.1 for our earlier release based on that version. I would be able to provide a patch to our test team and have them restart a run Simon From: Andy Seaborne <[email protected]> To: [email protected] Date: 10/15/2012 05:21 PM Subject: Re: concurrent modification in BlockMgrJournal Simon, It's probably in 2.7.4 as well. I've improved the code based on the stacktrace and on code analysis. It'll be in tonight's build. It now tracks when the write transaction is active or is no longer subject to change (the latter is when the error is occuring) If it is what I think it is, then a test case will need one transaction committed and queued in the journal and then at least two transactions (2 read or 1 read, 1 write) concurrently active all on the same area of the graph. The stack trace has at least 2 write transactions committed and queued; either 2 and it's a writer or 3 and it's a reader. (Or there is concurrent access inside one active transaction in which case all bets are off.) It would be possible to remove the block tracking but I'd rather not. Such internal details as operations tracking can be useful and it is hard to retro fit later. Andy On 15/10/12 18:28, Simon Helsen wrote: > Hi everyone, > > in some of our testing, we are still working with 2.7.1, so I am trying to > figure out if the issue observed might be fixed in 2.7.4 or not, or, if we > are making a mistake ourselves. I don't have a test case right now because > the problem only surfaced in a heavy-duty (200+ clients) 5-day reliability > test. So, I currently have no idea about the circumstances or even a hint > on how to reproduce, but perhaps someone will recognize this issue. I > suspect the problem is caused by our usage of > > At some point in our code (this is in the SecuringFilter.getPropertyFor > you see below in the stack trace), we have this > > results = this.datasetGraphTransaction.find(graphNode, Node.ANY, property, > Node.ANY); > > where > > this.datasetGraphTransaction = (DatasetGraphTransaction) > (queryContext.getDataset().asDatasetGraph()); > > is created at the beginning of the transaction. Everything you see below > sits in a read transaction. > > I also looked at the code in BlockMgrJournal and I am not sure what the > purpose is of final private Set<Long> iteratorBlocks = new HashSet<Long>() > ; in which the concurrent mod seems to happen. Is it only for logging > purposes? > > thanks > > Simon > > > Caused by: java.util.ConcurrentModificationException > at > java.util.HashMap$AbstractMapIterator.checkConcurrentMod(HashMap.java:122) > at java.util.HashMap$AbstractMapIterator.makeNext(HashMap.java:127) > at java.util.HashMap$KeyIterator.next(HashMap.java:200) > at java.util.HashMap.analyzeMap(HashMap.java:724) > at java.util.HashMap.rehash(HashMap.java:710) > at java.util.HashMap.rehash(HashMap.java:743) > at java.util.HashMap.putImpl(HashMap.java:629) > at java.util.HashMap.put(HashMap.java:607) > at java.util.HashSet.add(HashSet.java:95) > at > com.hp.hpl.jena.tdb.transaction.BlockMgrJournal.getReadIterator(BlockMgrJournal.java:149) > at > com.hp.hpl.jena.tdb.transaction.BlockMgrJournal.getReadIterator(BlockMgrJournal.java:146) > at > com.hp.hpl.jena.tdb.base.block.BlockMgrWrapper.getReadIterator(BlockMgrWrapper.java:58) > at > com.hp.hpl.jena.tdb.base.recordbuffer.RecordBufferPageMgr.getReadIterator(RecordBufferPageMgr.java:53) > at com.hp.hpl.jena.tdb.base.recordbuffer.RecordRangeIterator.<init> > (RecordRangeIterator.java:82) > at > com.hp.hpl.jena.tdb.base.recordbuffer.RecordRangeIterator.iterator(RecordRangeIterator.java:40) > at > com.hp.hpl.jena.tdb.index.bplustree.BPlusTree.iterator(BPlusTree.java:383) > at > com.hp.hpl.jena.tdb.index.bplustree.BPlusTree.iterator(BPlusTree.java:366) > at > com.hp.hpl.jena.tdb.index.TupleIndexRecord.findWorker(TupleIndexRecord.java:164) > at > com.hp.hpl.jena.tdb.index.TupleIndexRecord.findOrScan(TupleIndexRecord.java:84) > at > com.hp.hpl.jena.tdb.index.TupleIndexRecord.performFind(TupleIndexRecord.java:78) > at > com.hp.hpl.jena.tdb.index.TupleIndexBase.find(TupleIndexBase.java:91) > at com.hp.hpl.jena.tdb.index.TupleTable.find(TupleTable.java:172) > at > com.hp.hpl.jena.tdb.nodetable.NodeTupleTableConcrete.find(NodeTupleTableConcrete.java:169) > at > com.hp.hpl.jena.tdb.nodetable.NodeTupleTableConcrete.find(NodeTupleTableConcrete.java:157) > at > com.hp.hpl.jena.tdb.nodetable.NodeTupleTableConcrete.findAsNodeIds(NodeTupleTableConcrete.java:146) > at com.hp.hpl.jena.tdb.store.QuadTable.find(QuadTable.java:87) > at > com.hp.hpl.jena.tdb.store.DatasetGraphTDB.findInSpecificNamedGraph(DatasetGraphTDB.java:108) > at > com.hp.hpl.jena.sparql.core.DatasetGraphBaseFind.findNG(DatasetGraphBaseFind.java:59) > at > com.hp.hpl.jena.sparql.core.DatasetGraphBaseFind.find(DatasetGraphBaseFind.java:48) > at > com.hp.hpl.jena.tdb.migrate.DatasetGraphTrackActive.find(DatasetGraphTrackActive.java:165) > at > com.ibm.team.jfs.rdf.internal.jena.SecuringFilter.getPropertyFor(SecuringFilter.java:156) > at > com.ibm.team.jfs.rdf.internal.jena.SecuringFilter.getContextFor(SecuringFilter.java:149) > at > com.ibm.team.jfs.rdf.internal.jena.SecuringFilter.checkContextFor(SecuringFilter.java:136) > at > com.ibm.team.jfs.rdf.internal.jena.SecuringFilter.accept(SecuringFilter.java:94) > at > com.ibm.team.jfs.rdf.internal.jena.SecuringFilter.accept(SecuringFilter.java:1) > at org.openjena.atlas.iterator.Iter$3.hasNext(Iter.java:187) > at org.openjena.atlas.iterator.Iter$6.hasNext(Iter.java:386) > at org.openjena.atlas.iterator.Iter$3.hasNext(Iter.java:181) > at org.openjena.atlas.iterator.Iter$4.hasNext(Iter.java:295) > at org.openjena.atlas.iterator.Iter$3.hasNext(Iter.java:181) > at org.openjena.atlas.iterator.Iter.hasNext(Iter.java:808) > at > org.openjena.atlas.iterator.RepeatApplyIterator.hasNext(RepeatApplyIterator.java:58) > at org.openjena.atlas.iterator.Iter$4.hasNext(Iter.java:295) > 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:108) > 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:108) > 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:108) > 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:108) > 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:108) > at > com.hp.hpl.jena.sparql.engine.ResultSetStream.hasNext(ResultSetStream.java:72) > at com.ibm.team.jfs.rdf.internal.jena.InternalResultSet.<init> > (InternalResultSet.java:26) > at > com.ibm.team.jfs.rdf.internal.jena.tdb.JenaTxTdbProvider.performSelect(JenaTxTdbProvider.java:1396) > at > com.ibm.team.jfs.rdf.internal.jena.tdb.JenaTxTdbProvider$15.run(JenaTxTdbProvider.java:1541) > at > com.ibm.team.jfs.rdf.internal.jena.tdb.JenaTxTdbProvider$15.run(JenaTxTdbProvider.java:1) > at > com.ibm.team.jfs.rdf.internal.jena.tdb.JenaTxTdbProvider.storeOperation(JenaTxTdbProvider.java:1968) >
