Hi,
I am not yet opening a bug because I don't have an isolated test case yet,
but within our own suite and product I am noticing that some data which is
written by a write transaction is not found via the read transaction (this
is all on 2.7.4 from HEAD -> I rebuild myself. We don't have this problem
with 2.7.1). I enabled transactional logging, and I am seeing for each
write transaction "Txn[8]/W: Add to pending queue". I assume this is ok?
17:44:05,327 [1889890469@qtp-1827958004-10] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[1]/R: begin$
17:44:05,334 [1889890469@qtp-1827958004-10] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[1]/R: start
17:44:05,437 [1889890469@qtp-1827958004-10] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[1]/R: finish
17:44:05,885 [1889890469@qtp-1827958004-10] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[2]/R: begin$
17:44:05,892 [1889890469@qtp-1827958004-10] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[2]/R: start
17:44:05,896 [1889890469@qtp-1827958004-10] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[2]/R: finish
17:44:05,899 [1889890469@qtp-1827958004-10] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[3]/R: begin$
17:44:05,901 [1889890469@qtp-1827958004-10] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[3]/R: start
17:44:05,905 [1889890469@qtp-1827958004-10] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[3]/R: finish
17:44:06,980 [1889890469@qtp-1827958004-10] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[4]/R: begin$
17:44:06,983 [1889890469@qtp-1827958004-10] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[4]/R: start
17:44:06,987 [1889890469@qtp-1827958004-10] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[4]/R: finish
17:44:08,304 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[5]/R: begin$
17:44:08,306 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[5]/R: start
17:44:08,323 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[5]/R: finish
17:44:08,326 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[6]/R: begin$
17:44:08,328 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[6]/R: start
17:44:08,333 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[6]/R: finish
17:44:08,335 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[7]/R: begin$
17:44:08,337 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[7]/R: start
17:44:08,343 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[7]/R: finish
17:44:08,347 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[8]/W: begin$
17:44:08,363 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[8]/W: begin
17:44:08,447 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[8]/W: commit
17:44:08,449 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[8]/W: Add to
pending queue
17:44:08,459 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[9]/W: begin$
17:44:08,463 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[9]/W: begin
17:44:08,517 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[9]/W: commit
17:44:08,519 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[9]/W: Add to
pending queue
17:44:18,636 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[10]/W: begin$
17:44:18,641 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[10]/W: begin
17:44:18,671 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[10]/W: commit
17:44:18,673 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[10]/W: Add to
pending queue
17:44:26,784 [638461454@qtp-1827958004-17] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[11]/R: begin$
17:44:26,787 [638461454@qtp-1827958004-17] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[11]/R: start
17:44:26,989 [638461454@qtp-1827958004-17] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[11]/R: finish
17:44:28,608 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[12]/R: begin$
17:44:28,611 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[12]/R: start
17:44:28,616 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[12]/R: finish
17:44:28,619 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[13]/R: begin$
17:44:28,620 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[13]/R: start
17:44:28,633 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[13]/R: finish
17:44:28,636 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[14]/R: begin$
17:44:28,638 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[14]/R: start
17:44:28,643 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[14]/R: finish
17:44:28,650 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[15]/W: begin$
17:44:28,653 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[15]/W: begin
17:44:28,672 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[15]/W: commit
17:44:28,675 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[15]/W: Add to
pending queue
17:44:28,688 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[16]/W: begin$
17:44:28,692 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[16]/W: begin
17:44:28,785 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[16]/W: commit
17:44:28,788 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[16]/W: Add to
pending queue
17:44:29,099 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[17]/R: begin$
17:44:29,102 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[17]/R: start
17:44:29,108 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[17]/R: finish
17:44:29,110 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[18]/R: begin$
17:44:29,112 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[18]/R: start
17:44:29,117 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[18]/R: finish
17:44:29,120 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[19]/R: begin$
17:44:29,122 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[19]/R: start
17:44:29,127 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[19]/R: finish
17:44:29,132 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[20]/W: begin$
17:44:29,136 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[20]/W: begin
17:44:29,230 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[20]/W: commit
17:44:29,232 [jazz.jfs.indexer.internal.triple] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[20]/W: Add to
pending queue
17:44:29,683 [638461454@qtp-1827958004-17] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[21]/R: begin$
17:44:29,686 [638461454@qtp-1827958004-17] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[21]/R: start
17:44:29,693 [638461454@qtp-1827958004-17] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[21]/R: finish
Then, when I kill the process and start again, I have the following
sequence, leading to the Quad: predicate cannot be null
17:49:59,611 [678045802@qtp-316412636-5] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[1]/R: begin$
17:49:59,617 [678045802@qtp-316412636-5] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[1]/R: start
17:49:59,766 [678045802@qtp-316412636-5] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[1]/R: finish
17:49:59,810 [678045802@qtp-316412636-5] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[2]/R: begin$
17:49:59,813 [678045802@qtp-316412636-5] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[2]/R: start
17:49:59,818 [678045802@qtp-316412636-5] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[2]/R: finish
17:49:59,832 [678045802@qtp-316412636-5] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[3]/R: begin$
17:49:59,844 [678045802@qtp-316412636-5] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[3]/R: start
17:49:59,850 [678045802@qtp-316412636-5] ERROR com.ibm.team.jfs -
@ID@E An unexpected problem occurred while processing a transactional
model read activity
java.lang.UnsupportedOperationException: Quad: predicate cannot be null
at com.hp.hpl.jena.sparql.core.Quad.<init>(Quad.java:61)
at com.hp.hpl.jena.tdb.lib.TupleLib.quad(TupleLib.java:162)
at com.hp.hpl.jena.tdb.lib.TupleLib.quad(TupleLib.java:153)
at com.hp.hpl.jena.tdb.lib.TupleLib.access$100(TupleLib.java:45)
at com.hp.hpl.jena.tdb.lib.TupleLib$4.convert(TupleLib.java:87)
at com.hp.hpl.jena.tdb.lib.TupleLib$4.convert(TupleLib.java:83)
at org.openjena.atlas.iterator.Iter$4.next(Iter.java:301)
at
com.hp.hpl.jena.tdb.store.GraphTDBBase$ProjectQuadsToTriples.next(GraphTDBBase.java:178)
at
com.hp.hpl.jena.tdb.store.GraphTDBBase$ProjectQuadsToTriples.next(GraphTDBBase.java:166)
at
com.hp.hpl.jena.util.iterator.WrappedIterator.next(WrappedIterator.java:80)
at
com.hp.hpl.jena.util.iterator.Map1Iterator.next(Map1Iterator.java:47)
at
com.hp.hpl.jena.util.iterator.WrappedIterator.next(WrappedIterator.java:80)
at
com.hp.hpl.jena.rdf.model.impl.StmtIteratorImpl.next(StmtIteratorImpl.java:45)
at
com.hp.hpl.jena.rdf.model.impl.StmtIteratorImpl.next(StmtIteratorImpl.java:33)
at
com.ibm.team.jfs.rdf.internal.jena.tdb.JenaTxTdbProvider$7.run(JenaTxTdbProvider.java:950)
at
com.ibm.team.jfs.rdf.internal.jena.tdb.JenaTxTdbProvider$7.run(JenaTxTdbProvider.java:1)
at
com.ibm.team.jfs.rdf.internal.jena.tdb.JenaTxTdbProvider.storeOperation(JenaTxTdbProvider.java:208)
at
com.ibm.team.jfs.rdf.internal.jena.tdb.JenaTxTdbProvider.readAndSetCurrentIndexSize(JenaTxTdbProvider.java:941)
at
com.ibm.team.jfs.rdf.internal.jena.tdb.JenaTxTdbProvider.connect(JenaTxTdbProvider.java:488)
at
com.ibm.team.jfs.rdf.internal.jena.JenaRdfService.connect(JenaRdfService.java:284)
...
17:49:59,911 [678045802@qtp-316412636-5] DEBUG
com.hp.hpl.jena.tdb.transaction.TransactionManager - Txn[3]/R: finish
I am not sure what to make of it. I'll keep trying to produce a
reproducible test case which mimicks this behavior
Simon
