You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@jena.apache.org by "Simon Helsen (JIRA)" <ji...@apache.org> on 2011/08/12 22:45:27 UTC

[jira] [Created] (JENA-96) transactional behavior not sound

transactional behavior not sound
--------------------------------

                 Key: JENA-96
                 URL: https://issues.apache.org/jira/browse/JENA-96
             Project: Jena
          Issue Type: Bug
         Environment: tx-tdb-0.9.0-20110809.130753-7
            Reporter: Simon Helsen
            Priority: Critical


TDB-TX tx-tdb-0.9.0-20110809.130753-7 has transactionality issues. I am seeing the following stack trace:

com.hp.hpl.jena.tdb.transaction.TDBTransactionException: Transaction has already committed or aborted
	at com.hp.hpl.jena.tdb.transaction.Transaction.abort(Transaction.java:107)
	at com.hp.hpl.jena.tdb.DatasetGraphTxn.abort(DatasetGraphTxn.java:31)
	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaTdbProvider.storeOperation(JenaTdbProvider.java:208)
	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaTdbProvider.replace(JenaTdbProvider.java:2411)
	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaRdfService.replace(JenaRdfService.java:265)
	... 14 more

 I use the following bit of code to execute writes:

	DatasetGraphTxn dsGraph = null;
		try {
			dsGraph = this.store.begin(ReadWrite.WRITE);
			Dataset ds = dsGraph.toDataset();
			Model m = ds.getNamedModel(graphName);
			E e = modelWriteActivity.run(m);
			dsGraph.commit();
			return e;
		} catch (Exception e) {
			if (dsGraph != null) {
				dsGraph.abort();
			}
			// TODO handle better
			throw new RuntimeException(e);
		} finally {
			if (dsGraph != null) {
				dsGraph.close();
			}
			//System.out.println("ModelWriteActivity: " + (System.currentTimeMillis() - t) + "ms"); //$NON-NLS-1$ //$NON-NLS-2$
		}

The only thing I do in the ModelWriteActivity is 

	model.removeAll();
	model.add(graph);

As you can see, there is nothing in here which could have made it possible that the transaction has committed before. Moreover I only see this happening when I am executing massive concurrent reads/writes. Sequential operations do not expose this problem.


--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

[jira] [Commented] (JENA-96) transactional behavior not sound

Posted by "Simon Helsen (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/JENA-96?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13084365#comment-13084365 ] 

Simon Helsen commented on JENA-96:
----------------------------------

A little bit later, I also see

java.lang.IndexOutOfBoundsException: Index: 6, Size: 6
	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:177)
	at com.hp.hpl.jena.tdb.transaction.BlockMgrJournal.endIterator(BlockMgrJournal.java:300)
	at com.hp.hpl.jena.tdb.base.block.BlockMgrWrapper.endIterator(BlockMgrWrapper.java:123)
	at com.hp.hpl.jena.tdb.base.recordbuffer.RecordRangeIterator.close(RecordRangeIterator.java:144)
	at com.hp.hpl.jena.tdb.base.recordbuffer.RecordRangeIterator.hasNext(RecordRangeIterator.java:101)
	at org.openjena.atlas.iterator.Iter$4.hasNext(Iter.java:262)
	at com.hp.hpl.jena.tdb.sys.DatasetControlMRSW$IteratorCheckNotConcurrent.hasNext(DatasetControlMRSW.java:107)
	at org.openjena.atlas.iterator.Iter$3.hasNext(Iter.java:150)
	at org.openjena.atlas.iterator.Iter$4.hasNext(Iter.java:262)
	at org.openjena.atlas.iterator.Iter$3.hasNext(Iter.java:152)
	at org.openjena.atlas.iterator.Iter.hasNext(Iter.java:674)
	at org.openjena.atlas.iterator.RepeatApplyIterator.hasNext(RepeatApplyIterator.java:30)
	at org.openjena.atlas.iterator.Iter$4.hasNext(Iter.java:262)
	at com.hp.hpl.jena.sparql.engine.iterator.QueryIterPlainWrapper.hasNextBinding(QueryIterPlainWrapper.java:43)
	at com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorBase.hasNext(QueryIteratorBase.java:86)
	at com.hp.hpl.jena.sparql.engine.iterator.QueryIterConcat.hasNextBinding(QueryIterConcat.java:71)
	at com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorBase.hasNext(QueryIteratorBase.java:86)
	at com.hp.hpl.jena.sparql.engine.iterator.QueryIterRepeatApply.hasNextBinding(QueryIterRepeatApply.java:67)
	at com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorBase.hasNext(QueryIteratorBase.java:86)
	at com.hp.hpl.jena.sparql.engine.iterator.QueryIterProcessBinding.hasNextBinding(QueryIterProcessBinding.java:49)
	at com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorBase.hasNext(QueryIteratorBase.java:86)
	at com.hp.hpl.jena.sparql.engine.iterator.QueryIterPeek.hasNextBinding(QueryIterPeek.java:46)
	at com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorBase.hasNext(QueryIteratorBase.java:86)
	at org.openjena.atlas.iterator.Iter$4.hasNext(Iter.java:262)
	at org.openjena.atlas.iterator.RepeatApplyIterator.hasNext(RepeatApplyIterator.java:34)
	at org.openjena.atlas.iterator.Iter$4.hasNext(Iter.java:262)
	at com.hp.hpl.jena.sparql.engine.iterator.QueryIterPlainWrapper.hasNextBinding(QueryIterPlainWrapper.java:43)
	at com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorBase.hasNext(QueryIteratorBase.java:86)
	at com.hp.hpl.jena.sparql.engine.iterator.QueryIterConvert.hasNextBinding(QueryIterConvert.java:54)
	at com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorBase.hasNext(QueryIteratorBase.java:86)
	at com.hp.hpl.jena.sparql.engine.iterator.QueryIterSlice.hasNextBinding(QueryIterSlice.java:65)
	at com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorBase.hasNext(QueryIteratorBase.java:86)
	at com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorWrapper.hasNextBinding(QueryIteratorWrapper.java:30)
	at com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorBase.hasNext(QueryIteratorBase.java:86)
	at com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorWrapper.hasNextBinding(QueryIteratorWrapper.java:30)
	at com.hp.hpl.jena.sparql.engine.iterator.QueryIteratorBase.hasNext(QueryIteratorBase.java:86)
	at com.hp.hpl.jena.sparql.engine.ResultSetStream.hasNext(ResultSetStream.java:57)
	at com.ibm.team.jfs.rdf.internal.jenatdbtx.InternalResultSet.retrieveFirstPage(InternalResultSet.java:72)
	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaTdbProvider.renderSelect(JenaTdbProvider.java:2363)
	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaTdbProvider.performSelect(JenaTdbProvider.java:1954)
	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaTdbProvider$9.run(JenaTdbProvider.java:2174)
	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaTdbProvider$9.run(JenaTdbProvider.java:1)
	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaTdbProvider.storeOperation(JenaTdbProvider.java:163)
	... 56 more

but I am not sure if this is related or a different issue. I also only observe this problem in a massive concurrent environment.

> transactional behavior not sound
> --------------------------------
>
>                 Key: JENA-96
>                 URL: https://issues.apache.org/jira/browse/JENA-96
>             Project: Jena
>          Issue Type: Bug
>         Environment: tx-tdb-0.9.0-20110809.130753-7
>            Reporter: Simon Helsen
>            Priority: Critical
>
> TDB-TX tx-tdb-0.9.0-20110809.130753-7 has transactionality issues. I am seeing the following stack trace:
> com.hp.hpl.jena.tdb.transaction.TDBTransactionException: Transaction has already committed or aborted
> 	at com.hp.hpl.jena.tdb.transaction.Transaction.abort(Transaction.java:107)
> 	at com.hp.hpl.jena.tdb.DatasetGraphTxn.abort(DatasetGraphTxn.java:31)
> 	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaTdbProvider.storeOperation(JenaTdbProvider.java:208)
> 	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaTdbProvider.replace(JenaTdbProvider.java:2411)
> 	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaRdfService.replace(JenaRdfService.java:265)
> 	... 14 more
>  I use the following bit of code to execute writes:
> 	DatasetGraphTxn dsGraph = null;
> 		try {
> 			dsGraph = this.store.begin(ReadWrite.WRITE);
> 			Dataset ds = dsGraph.toDataset();
> 			Model m = ds.getNamedModel(graphName);
> 			E e = modelWriteActivity.run(m);
> 			dsGraph.commit();
> 			return e;
> 		} catch (Exception e) {
> 			if (dsGraph != null) {
> 				dsGraph.abort();
> 			}
> 			// TODO handle better
> 			throw new RuntimeException(e);
> 		} finally {
> 			if (dsGraph != null) {
> 				dsGraph.close();
> 			}
> 			//System.out.println("ModelWriteActivity: " + (System.currentTimeMillis() - t) + "ms"); //$NON-NLS-1$ //$NON-NLS-2$
> 		}
> The only thing I do in the ModelWriteActivity is 
> 	model.removeAll();
> 	model.add(graph);
> As you can see, there is nothing in here which could have made it possible that the transaction has committed before. Moreover I only see this happening when I am executing massive concurrent reads/writes. Sequential operations do not expose this problem.

--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

[jira] [Commented] (JENA-96) transactional behavior not sound

Posted by "Simon Helsen (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/JENA-96?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13086587#comment-13086587 ] 

Simon Helsen commented on JENA-96:
----------------------------------

I should mention though that even though there could be a relation to JENA-91, this particular problem can be reproduced without ever running into the messages which I see in JENA-91. Just the massive concurrency seems to cause this. Also, here is the full stack trace

16:53:37,487 [jazz.jfs.indexer.jfs_tests_default_consumer_name.triple] ERROR com.ibm.team.jfs                                    - Originating Exception:
com.hp.hpl.jena.tdb.TDBException: Different ids allocated: expected [0000000000199AA9], got [0000000000199B52]

	at com.hp.hpl.jena.tdb.transaction.NodeTableTrans.append(NodeTableTrans.java:149)
	at com.hp.hpl.jena.tdb.transaction.NodeTableTrans.writeNodeJournal(NodeTableTrans.java:176)
	at com.hp.hpl.jena.tdb.transaction.NodeTableTrans.commitPrepare(NodeTableTrans.java:161)
	at com.hp.hpl.jena.tdb.transaction.Transaction.prepare(Transaction.java:94)
	at com.hp.hpl.jena.tdb.transaction.Transaction.commit(Transaction.java:77)
	at com.hp.hpl.jena.tdb.DatasetGraphTxn.commit(DatasetGraphTxn.java:26)
	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaTdbProvider.storeOperation(JenaTdbProvider.java:207)
        ...

> transactional behavior not sound
> --------------------------------
>
>                 Key: JENA-96
>                 URL: https://issues.apache.org/jira/browse/JENA-96
>             Project: Jena
>          Issue Type: Bug
>          Components: TDB
>         Environment: tx-tdb-0.9.0-20110809.130753-7
>            Reporter: Simon Helsen
>            Priority: Critical
>
> TDB-TX tx-tdb-0.9.0-20110809.130753-7 has transactionality issues. I am seeing the following stack trace:
> com.hp.hpl.jena.tdb.transaction.TDBTransactionException: Transaction has already committed or aborted
> 	at com.hp.hpl.jena.tdb.transaction.Transaction.abort(Transaction.java:107)
> 	at com.hp.hpl.jena.tdb.DatasetGraphTxn.abort(DatasetGraphTxn.java:31)
> 	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaTdbProvider.storeOperation(JenaTdbProvider.java:208)
> 	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaTdbProvider.replace(JenaTdbProvider.java:2411)
> 	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaRdfService.replace(JenaRdfService.java:265)
> 	... 14 more
>  I use the following bit of code to execute writes:
> 	DatasetGraphTxn dsGraph = null;
> 		try {
> 			dsGraph = this.store.begin(ReadWrite.WRITE);
> 			Dataset ds = dsGraph.toDataset();
> 			Model m = ds.getNamedModel(graphName);
> 			E e = modelWriteActivity.run(m);
> 			dsGraph.commit();
> 			return e;
> 		} catch (Exception e) {
> 			if (dsGraph != null) {
> 				dsGraph.abort();
> 			}
> 			// TODO handle better
> 			throw new RuntimeException(e);
> 		} finally {
> 			if (dsGraph != null) {
> 				dsGraph.close();
> 			}
> 			//System.out.println("ModelWriteActivity: " + (System.currentTimeMillis() - t) + "ms"); //$NON-NLS-1$ //$NON-NLS-2$
> 		}
> The only thing I do in the ModelWriteActivity is 
> 	model.removeAll();
> 	model.add(graph);
> As you can see, there is nothing in here which could have made it possible that the transaction has committed before. Moreover I only see this happening when I am executing massive concurrent reads/writes. Sequential operations do not expose this problem.

--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

[jira] [Closed] (JENA-96) transactional behavior not sound

Posted by "Andy Seaborne (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/JENA-96?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Andy Seaborne closed JENA-96.
-----------------------------


> transactional behavior not sound
> --------------------------------
>
>                 Key: JENA-96
>                 URL: https://issues.apache.org/jira/browse/JENA-96
>             Project: Jena
>          Issue Type: Bug
>          Components: TDB
>         Environment: tx-tdb-0.9.0-20110809.130753-7
>            Reporter: Simon Helsen
>            Assignee: Andy Seaborne
>            Priority: Critical
>
> TDB-TX tx-tdb-0.9.0-20110809.130753-7 has transactionality issues. I am seeing the following stack trace:
> com.hp.hpl.jena.tdb.transaction.TDBTransactionException: Transaction has already committed or aborted
> 	at com.hp.hpl.jena.tdb.transaction.Transaction.abort(Transaction.java:107)
> 	at com.hp.hpl.jena.tdb.DatasetGraphTxn.abort(DatasetGraphTxn.java:31)
> 	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaTdbProvider.storeOperation(JenaTdbProvider.java:208)
> 	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaTdbProvider.replace(JenaTdbProvider.java:2411)
> 	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaRdfService.replace(JenaRdfService.java:265)
> 	... 14 more
>  I use the following bit of code to execute writes:
> 	DatasetGraphTxn dsGraph = null;
> 		try {
> 			dsGraph = this.store.begin(ReadWrite.WRITE);
> 			Dataset ds = dsGraph.toDataset();
> 			Model m = ds.getNamedModel(graphName);
> 			E e = modelWriteActivity.run(m);
> 			dsGraph.commit();
> 			return e;
> 		} catch (Exception e) {
> 			if (dsGraph != null) {
> 				dsGraph.abort();
> 			}
> 			// TODO handle better
> 			throw new RuntimeException(e);
> 		} finally {
> 			if (dsGraph != null) {
> 				dsGraph.close();
> 			}
> 			//System.out.println("ModelWriteActivity: " + (System.currentTimeMillis() - t) + "ms"); //$NON-NLS-1$ //$NON-NLS-2$
> 		}
> The only thing I do in the ModelWriteActivity is 
> 	model.removeAll();
> 	model.add(graph);
> As you can see, there is nothing in here which could have made it possible that the transaction has committed before. Moreover I only see this happening when I am executing massive concurrent reads/writes. Sequential operations do not expose this problem.

--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

[jira] [Commented] (JENA-96) transactional behavior not sound

Posted by "Simon Helsen (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/JENA-96?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13086578#comment-13086578 ] 

Simon Helsen commented on JENA-96:
----------------------------------

ok, this is what I get when I fish out the exception which is obscured by the exception thrown on abort:

16:36:59,302 [jazz.jfs.indexer.jfs_tests_default_consumer_name.triple] ERROR com.ibm.team.jfs                                    - com.hp.hpl.jena.tdb.TDBException: Different ids allocated: expected [0000000000199A67], got [0000000000199B10]

Could be another corruption issue in the style of JENA-91. 

> transactional behavior not sound
> --------------------------------
>
>                 Key: JENA-96
>                 URL: https://issues.apache.org/jira/browse/JENA-96
>             Project: Jena
>          Issue Type: Bug
>          Components: TDB
>         Environment: tx-tdb-0.9.0-20110809.130753-7
>            Reporter: Simon Helsen
>            Priority: Critical
>
> TDB-TX tx-tdb-0.9.0-20110809.130753-7 has transactionality issues. I am seeing the following stack trace:
> com.hp.hpl.jena.tdb.transaction.TDBTransactionException: Transaction has already committed or aborted
> 	at com.hp.hpl.jena.tdb.transaction.Transaction.abort(Transaction.java:107)
> 	at com.hp.hpl.jena.tdb.DatasetGraphTxn.abort(DatasetGraphTxn.java:31)
> 	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaTdbProvider.storeOperation(JenaTdbProvider.java:208)
> 	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaTdbProvider.replace(JenaTdbProvider.java:2411)
> 	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaRdfService.replace(JenaRdfService.java:265)
> 	... 14 more
>  I use the following bit of code to execute writes:
> 	DatasetGraphTxn dsGraph = null;
> 		try {
> 			dsGraph = this.store.begin(ReadWrite.WRITE);
> 			Dataset ds = dsGraph.toDataset();
> 			Model m = ds.getNamedModel(graphName);
> 			E e = modelWriteActivity.run(m);
> 			dsGraph.commit();
> 			return e;
> 		} catch (Exception e) {
> 			if (dsGraph != null) {
> 				dsGraph.abort();
> 			}
> 			// TODO handle better
> 			throw new RuntimeException(e);
> 		} finally {
> 			if (dsGraph != null) {
> 				dsGraph.close();
> 			}
> 			//System.out.println("ModelWriteActivity: " + (System.currentTimeMillis() - t) + "ms"); //$NON-NLS-1$ //$NON-NLS-2$
> 		}
> The only thing I do in the ModelWriteActivity is 
> 	model.removeAll();
> 	model.add(graph);
> As you can see, there is nothing in here which could have made it possible that the transaction has committed before. Moreover I only see this happening when I am executing massive concurrent reads/writes. Sequential operations do not expose this problem.

--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

[jira] [Resolved] (JENA-96) transactional behavior not sound

Posted by "Andy Seaborne (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/JENA-96?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Andy Seaborne resolved JENA-96.
-------------------------------

    Resolution: Fixed
      Assignee: Andy Seaborne

JENA-91 is now closed (2011-08-31).  

Assuming this is due to that underlying problem, let's close this until we have evidence such as a concrete test case based on the post-JENA-91 build, 

> transactional behavior not sound
> --------------------------------
>
>                 Key: JENA-96
>                 URL: https://issues.apache.org/jira/browse/JENA-96
>             Project: Jena
>          Issue Type: Bug
>          Components: TDB
>         Environment: tx-tdb-0.9.0-20110809.130753-7
>            Reporter: Simon Helsen
>            Assignee: Andy Seaborne
>            Priority: Critical
>
> TDB-TX tx-tdb-0.9.0-20110809.130753-7 has transactionality issues. I am seeing the following stack trace:
> com.hp.hpl.jena.tdb.transaction.TDBTransactionException: Transaction has already committed or aborted
> 	at com.hp.hpl.jena.tdb.transaction.Transaction.abort(Transaction.java:107)
> 	at com.hp.hpl.jena.tdb.DatasetGraphTxn.abort(DatasetGraphTxn.java:31)
> 	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaTdbProvider.storeOperation(JenaTdbProvider.java:208)
> 	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaTdbProvider.replace(JenaTdbProvider.java:2411)
> 	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaRdfService.replace(JenaRdfService.java:265)
> 	... 14 more
>  I use the following bit of code to execute writes:
> 	DatasetGraphTxn dsGraph = null;
> 		try {
> 			dsGraph = this.store.begin(ReadWrite.WRITE);
> 			Dataset ds = dsGraph.toDataset();
> 			Model m = ds.getNamedModel(graphName);
> 			E e = modelWriteActivity.run(m);
> 			dsGraph.commit();
> 			return e;
> 		} catch (Exception e) {
> 			if (dsGraph != null) {
> 				dsGraph.abort();
> 			}
> 			// TODO handle better
> 			throw new RuntimeException(e);
> 		} finally {
> 			if (dsGraph != null) {
> 				dsGraph.close();
> 			}
> 			//System.out.println("ModelWriteActivity: " + (System.currentTimeMillis() - t) + "ms"); //$NON-NLS-1$ //$NON-NLS-2$
> 		}
> The only thing I do in the ModelWriteActivity is 
> 	model.removeAll();
> 	model.add(graph);
> As you can see, there is nothing in here which could have made it possible that the transaction has committed before. Moreover I only see this happening when I am executing massive concurrent reads/writes. Sequential operations do not expose this problem.

--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

[jira] [Commented] (JENA-96) transactional behavior not sound

Posted by "Simon Helsen (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/JENA-96?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13086564#comment-13086564 ] 

Simon Helsen commented on JENA-96:
----------------------------------

Paolo, as always, I understand your request, but you have to understand that we use TDB inside a complex framework and producing an independent piece of code which exhibits the issue is not simple.

1) The test case I am running first creates about 6000 graphs. Then I start 10 client threads which each execute 50 queries and perform a write every 7th action. In between each action, I wait about 500ms and the 50 queries cycle through about 27 different queries which do all sorts of different things on the data. (I can tweak any of these numbers to simulate different behaviors)

2) when I look at the first problematic stack trace, I have the following:

com.ibm.team.repository.common.TeamRepositoryException: Transaction has already committed or aborted
	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaRdfService.replace(JenaRdfService.java:267)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:60)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
	at java.lang.reflect.Method.invoke(Method.java:611)
	at org.eclipse.soda.sat.core.internal.record.ExportProxyServiceRecord.invoke(ExportProxyServiceRecord.java:370)
	at org.eclipse.soda.sat.core.internal.record.ExportProxyServiceRecord.access$0(ExportProxyServiceRecord.java:356)
	at org.eclipse.soda.sat.core.internal.record.ExportProxyServiceRecord$ExportedServiceInvocationHandler.invoke(ExportProxyServiceRecord.java:56)
	at $Proxy234.replace(Unknown Source)
	at com.ibm.team.jfs.indexing.service.internal.task.TripleIndexAgent.updateIndex(TripleIndexAgent.java:383)
	at com.ibm.team.jfs.indexing.service.internal.task.LiveIndexAgent.refreshIndex(LiveIndexAgent.java:944)
	at com.ibm.team.jfs.indexing.service.internal.task.LiveIndexAgent.performConsistencyCheck(LiveIndexAgent.java:686)
	at com.ibm.team.jfs.indexing.service.internal.task.LiveIndexAgent.perform(LiveIndexAgent.java:453)
	at com.ibm.team.jfs.indexing.service.internal.task.AbstractIndexAgent.run(AbstractIndexAgent.java:1061)
	at java.lang.Thread.run(Thread.java:736)
Caused by: 
com.hp.hpl.jena.tdb.transaction.TDBTransactionException: Transaction has already committed or aborted
	at com.hp.hpl.jena.tdb.transaction.Transaction.abort(Transaction.java:107)
	at com.hp.hpl.jena.tdb.DatasetGraphTxn.abort(DatasetGraphTxn.java:31)
	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaTdbProvider.storeOperation(JenaTdbProvider.java:208)
	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaTdbProvider.replace(JenaTdbProvider.java:2411)
	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaRdfService.replace(JenaRdfService.java:265)
	... 14 more

3) Here is the bit of code which causes this:

private <E> E storeOperation(String graphName, ModelWriteActivity<E> modelWriteActivity) {
		long t = System.currentTimeMillis();
		DatasetGraphTxn dsGraph = null;
		try {
			dsGraph = this.store.begin(ReadWrite.WRITE);
			Dataset ds = dsGraph.toDataset();
			Model m = ds.getNamedModel(graphName);
			E e = modelWriteActivity.run(m);
			dsGraph.commit();
			return e;
		} catch (Exception e) {
			if (dsGraph != null) {
				dsGraph.abort();
			}
			// TODO handle better
			throw new RuntimeException(e);
		} finally {
			if (dsGraph != null) {
				dsGraph.close();
			}
			//System.out.println("ModelWriteActivity: " + (System.currentTimeMillis() - t) + "ms"); //$NON-NLS-1$ //$NON-NLS-2$
		}
	}


4) when I look at all of this, I can only conclude that the exception com.hp.hpl.jena.tdb.transaction.TDBTransactionException is thrown by the abort because the commit before threw an exception (which then disappears). I'll change my code to make sure to log the original exception (I guess I was not expecting the abort to throw an exception as well)



> transactional behavior not sound
> --------------------------------
>
>                 Key: JENA-96
>                 URL: https://issues.apache.org/jira/browse/JENA-96
>             Project: Jena
>          Issue Type: Bug
>          Components: TDB
>         Environment: tx-tdb-0.9.0-20110809.130753-7
>            Reporter: Simon Helsen
>            Priority: Critical
>
> TDB-TX tx-tdb-0.9.0-20110809.130753-7 has transactionality issues. I am seeing the following stack trace:
> com.hp.hpl.jena.tdb.transaction.TDBTransactionException: Transaction has already committed or aborted
> 	at com.hp.hpl.jena.tdb.transaction.Transaction.abort(Transaction.java:107)
> 	at com.hp.hpl.jena.tdb.DatasetGraphTxn.abort(DatasetGraphTxn.java:31)
> 	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaTdbProvider.storeOperation(JenaTdbProvider.java:208)
> 	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaTdbProvider.replace(JenaTdbProvider.java:2411)
> 	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaRdfService.replace(JenaRdfService.java:265)
> 	... 14 more
>  I use the following bit of code to execute writes:
> 	DatasetGraphTxn dsGraph = null;
> 		try {
> 			dsGraph = this.store.begin(ReadWrite.WRITE);
> 			Dataset ds = dsGraph.toDataset();
> 			Model m = ds.getNamedModel(graphName);
> 			E e = modelWriteActivity.run(m);
> 			dsGraph.commit();
> 			return e;
> 		} catch (Exception e) {
> 			if (dsGraph != null) {
> 				dsGraph.abort();
> 			}
> 			// TODO handle better
> 			throw new RuntimeException(e);
> 		} finally {
> 			if (dsGraph != null) {
> 				dsGraph.close();
> 			}
> 			//System.out.println("ModelWriteActivity: " + (System.currentTimeMillis() - t) + "ms"); //$NON-NLS-1$ //$NON-NLS-2$
> 		}
> The only thing I do in the ModelWriteActivity is 
> 	model.removeAll();
> 	model.add(graph);
> As you can see, there is nothing in here which could have made it possible that the transaction has committed before. Moreover I only see this happening when I am executing massive concurrent reads/writes. Sequential operations do not expose this problem.

--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

[jira] [Updated] (JENA-96) transactional behavior not sound

Posted by "Simon Helsen (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/JENA-96?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Simon Helsen updated JENA-96:
-----------------------------

    Component/s: TDB

> transactional behavior not sound
> --------------------------------
>
>                 Key: JENA-96
>                 URL: https://issues.apache.org/jira/browse/JENA-96
>             Project: Jena
>          Issue Type: Bug
>          Components: TDB
>         Environment: tx-tdb-0.9.0-20110809.130753-7
>            Reporter: Simon Helsen
>            Priority: Critical
>
> TDB-TX tx-tdb-0.9.0-20110809.130753-7 has transactionality issues. I am seeing the following stack trace:
> com.hp.hpl.jena.tdb.transaction.TDBTransactionException: Transaction has already committed or aborted
> 	at com.hp.hpl.jena.tdb.transaction.Transaction.abort(Transaction.java:107)
> 	at com.hp.hpl.jena.tdb.DatasetGraphTxn.abort(DatasetGraphTxn.java:31)
> 	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaTdbProvider.storeOperation(JenaTdbProvider.java:208)
> 	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaTdbProvider.replace(JenaTdbProvider.java:2411)
> 	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaRdfService.replace(JenaRdfService.java:265)
> 	... 14 more
>  I use the following bit of code to execute writes:
> 	DatasetGraphTxn dsGraph = null;
> 		try {
> 			dsGraph = this.store.begin(ReadWrite.WRITE);
> 			Dataset ds = dsGraph.toDataset();
> 			Model m = ds.getNamedModel(graphName);
> 			E e = modelWriteActivity.run(m);
> 			dsGraph.commit();
> 			return e;
> 		} catch (Exception e) {
> 			if (dsGraph != null) {
> 				dsGraph.abort();
> 			}
> 			// TODO handle better
> 			throw new RuntimeException(e);
> 		} finally {
> 			if (dsGraph != null) {
> 				dsGraph.close();
> 			}
> 			//System.out.println("ModelWriteActivity: " + (System.currentTimeMillis() - t) + "ms"); //$NON-NLS-1$ //$NON-NLS-2$
> 		}
> The only thing I do in the ModelWriteActivity is 
> 	model.removeAll();
> 	model.add(graph);
> As you can see, there is nothing in here which could have made it possible that the transaction has committed before. Moreover I only see this happening when I am executing massive concurrent reads/writes. Sequential operations do not expose this problem.

--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

[jira] [Commented] (JENA-96) transactional behavior not sound

Posted by "Simon Helsen (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/JENA-96?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13087718#comment-13087718 ] 

Simon Helsen commented on JENA-96:
----------------------------------

my last comment makes me think that the core problem is JENA-91, i.e. some sort of strange corruption

> transactional behavior not sound
> --------------------------------
>
>                 Key: JENA-96
>                 URL: https://issues.apache.org/jira/browse/JENA-96
>             Project: Jena
>          Issue Type: Bug
>          Components: TDB
>         Environment: tx-tdb-0.9.0-20110809.130753-7
>            Reporter: Simon Helsen
>            Priority: Critical
>
> TDB-TX tx-tdb-0.9.0-20110809.130753-7 has transactionality issues. I am seeing the following stack trace:
> com.hp.hpl.jena.tdb.transaction.TDBTransactionException: Transaction has already committed or aborted
> 	at com.hp.hpl.jena.tdb.transaction.Transaction.abort(Transaction.java:107)
> 	at com.hp.hpl.jena.tdb.DatasetGraphTxn.abort(DatasetGraphTxn.java:31)
> 	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaTdbProvider.storeOperation(JenaTdbProvider.java:208)
> 	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaTdbProvider.replace(JenaTdbProvider.java:2411)
> 	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaRdfService.replace(JenaRdfService.java:265)
> 	... 14 more
>  I use the following bit of code to execute writes:
> 	DatasetGraphTxn dsGraph = null;
> 		try {
> 			dsGraph = this.store.begin(ReadWrite.WRITE);
> 			Dataset ds = dsGraph.toDataset();
> 			Model m = ds.getNamedModel(graphName);
> 			E e = modelWriteActivity.run(m);
> 			dsGraph.commit();
> 			return e;
> 		} catch (Exception e) {
> 			if (dsGraph != null) {
> 				dsGraph.abort();
> 			}
> 			// TODO handle better
> 			throw new RuntimeException(e);
> 		} finally {
> 			if (dsGraph != null) {
> 				dsGraph.close();
> 			}
> 			//System.out.println("ModelWriteActivity: " + (System.currentTimeMillis() - t) + "ms"); //$NON-NLS-1$ //$NON-NLS-2$
> 		}
> The only thing I do in the ModelWriteActivity is 
> 	model.removeAll();
> 	model.add(graph);
> As you can see, there is nothing in here which could have made it possible that the transaction has committed before. Moreover I only see this happening when I am executing massive concurrent reads/writes. Sequential operations do not expose this problem.

--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

[jira] [Commented] (JENA-96) transactional behavior not sound

Posted by "Paolo Castagna (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/JENA-96?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13085621#comment-13085621 ] 

Paolo Castagna commented on JENA-96:
------------------------------------

Simon, first of all, thanks for the report.
However, it's not easy to investigate this issue without being able to replicate it first.
Any help in producing a small fragment of code which we can run and shows the issue is invaluable and it's the best thing to do to ensure bugs are identified and resolved quickly.



> transactional behavior not sound
> --------------------------------
>
>                 Key: JENA-96
>                 URL: https://issues.apache.org/jira/browse/JENA-96
>             Project: Jena
>          Issue Type: Bug
>          Components: TDB
>         Environment: tx-tdb-0.9.0-20110809.130753-7
>            Reporter: Simon Helsen
>            Priority: Critical
>
> TDB-TX tx-tdb-0.9.0-20110809.130753-7 has transactionality issues. I am seeing the following stack trace:
> com.hp.hpl.jena.tdb.transaction.TDBTransactionException: Transaction has already committed or aborted
> 	at com.hp.hpl.jena.tdb.transaction.Transaction.abort(Transaction.java:107)
> 	at com.hp.hpl.jena.tdb.DatasetGraphTxn.abort(DatasetGraphTxn.java:31)
> 	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaTdbProvider.storeOperation(JenaTdbProvider.java:208)
> 	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaTdbProvider.replace(JenaTdbProvider.java:2411)
> 	at com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaRdfService.replace(JenaRdfService.java:265)
> 	... 14 more
>  I use the following bit of code to execute writes:
> 	DatasetGraphTxn dsGraph = null;
> 		try {
> 			dsGraph = this.store.begin(ReadWrite.WRITE);
> 			Dataset ds = dsGraph.toDataset();
> 			Model m = ds.getNamedModel(graphName);
> 			E e = modelWriteActivity.run(m);
> 			dsGraph.commit();
> 			return e;
> 		} catch (Exception e) {
> 			if (dsGraph != null) {
> 				dsGraph.abort();
> 			}
> 			// TODO handle better
> 			throw new RuntimeException(e);
> 		} finally {
> 			if (dsGraph != null) {
> 				dsGraph.close();
> 			}
> 			//System.out.println("ModelWriteActivity: " + (System.currentTimeMillis() - t) + "ms"); //$NON-NLS-1$ //$NON-NLS-2$
> 		}
> The only thing I do in the ModelWriteActivity is 
> 	model.removeAll();
> 	model.add(graph);
> As you can see, there is nothing in here which could have made it possible that the transaction has committed before. Moreover I only see this happening when I am executing massive concurrent reads/writes. Sequential operations do not expose this problem.

--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira