Andy, Paolo, others,
first, thanks for the info. I obviously was not able to see any of this
from the JIRA work item since the last comments there related to a patch
which apparently was not relevant. So, for the record, yes, my ARQ is
aligned. I use TDB tx-tdb-0.9.0-20110831.124751-10 and the ARQ which was
packaged in the zip, which is arq-2.8.9-20110831.100801-30.
I also agree that the 2nd exception is likely another symptom of the same
problem (although it is not clear to me that one would cause the other) As
always, my test case is in a framework which I cannot easily share with
you, but I can give you more information on the context. The complete
stack trace is below, but the quad NPE happens on a read, not a write or
update. The code which goes into the jena next() statement in the trace
looks like this:
Model timestampModel = this.
dataset.getNamedModel(INDEX_INFO_SUBJECT);
StmtIterator statements =
timestampModel.listStatements();
try {
long timestamp = -1;
float indexVersion = 0; //
0 is the assumed version number for indexes before JFS 1.0.0.1
List<String> uris = new
ArrayList<String>(2);
while
(statements.hasNext()) {
Statement
statement = statements.next();
Line 1509 (as per stack trace below) is exactly the statements.next(). I
suspect the problem happens earlier when *writing* INDEX_INFO_SUBJECT.
Note that throughout our operations we regularly read and write this
particular graph with all sorts of meta-data using the Jena Model API.
Also, as before, I see this problem both when using the transaction API as
well as with old non-transactional API (where we conservatively
exclusively lock any write operation). Moreover, when I use the
transaction API, I keep getting tons of the following messages (without
any details), long before the quad NPE hits:
ERROR com.hp.hpl.jena.tdb.base.block.BlockMgrCache - write: Block in the
read cache
but I think this only happens in direct mode (although I suspect it is all
related to the same problem.
Simon
14:06:42,307
[jazz.jfs.resuming.indexer.jfs_tests_default_consumer_name.triple] ERROR
com.ibm.team.jfs - Originating
Exception:
java.lang.UnsupportedOperationException: Quad: object cannot be null
at com.hp.hpl.jena.sparql.core.Quad.<init>(Quad.java:50)
at com.hp.hpl.jena.tdb.lib.TupleLib.quad(TupleLib.java:127)
at com.hp.hpl.jena.tdb.lib.TupleLib.quad(TupleLib.java:118)
at com.hp.hpl.jena.tdb.lib.TupleLib.access$100(TupleLib.java:32)
at com.hp.hpl.jena.tdb.lib.TupleLib$4.convert(TupleLib.java:76)
at com.hp.hpl.jena.tdb.lib.TupleLib$4.convert(TupleLib.java:72)
at org.openjena.atlas.iterator.Iter$4.next(Iter.java:267)
at
com.hp.hpl.jena.tdb.store.GraphTDBBase$ProjectQuadsToTriples.next(
GraphTDBBase.java:183)
at
com.hp.hpl.jena.tdb.store.GraphTDBBase$ProjectQuadsToTriples.next(
GraphTDBBase.java:171)
at com.hp.hpl.jena.util.iterator.WrappedIterator.next(
WrappedIterator.java:68)
at com.hp.hpl.jena.util.iterator.Map1Iterator.next(
Map1Iterator.java:35)
at com.hp.hpl.jena.util.iterator.WrappedIterator.next(
WrappedIterator.java:68)
at com.hp.hpl.jena.rdf.model.impl.StmtIteratorImpl.next(
StmtIteratorImpl.java:33)
at com.hp.hpl.jena.rdf.model.impl.StmtIteratorImpl.next(
StmtIteratorImpl.java:21)
at
com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaTdbProvider.getLastProcessedTimestamp(
JenaTdbProvider.java:1509)
at
com.ibm.team.jfs.rdf.internal.jenatdbtx.JenaRdfService.findLastProcessedTimestamp(
JenaRdfService.java:180)
at sun.reflect.GeneratedMethodAccessor225.invoke(Unknown Source)
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 $Proxy307.findLastProcessedTimestamp(Unknown Source)
at
com.ibm.team.jfs.indexing.service.internal.task.TripleIndexAgent.findLastProcessedTimestamp(
TripleIndexAgent.java:282)
at
com.ibm.team.jfs.indexing.service.internal.task.AbstractIndexAgent.restoreTimestamp(
AbstractIndexAgent.java:896)
at
com.ibm.team.jfs.indexing.service.internal.task.AbstractIndexAgent.initialize(
AbstractIndexAgent.java:491)
at
com.ibm.team.jfs.indexing.service.internal.task.LiveIndexAgent.initialize(
LiveIndexAgent.java:400)
at
com.ibm.team.jfs.indexing.service.internal.task.LiveIndexAgent.resume(
LiveIndexAgent.java:1151)
at
com.ibm.team.jfs.indexing.service.internal.IndexingService$2.run(
IndexingService.java:1505)
at java.lang.Thread.run(Thread.java:736)
From:
Andy Seaborne <[email protected]>
To:
[email protected]
Date:
09/13/2011 12:52 PM
Subject:
Re: Jena-91 still an issue (?)
Hi Simon,
On 13/09/11 16:58, Simon Helsen wrote:
> Hi everyone,
>
> after my leave, I spent some time adopting the latest TDB-TX build
(August
> 31) and I noticed I kept seeing the same problems as before. After some
> messing around, I noticed that the patch Paolo attached to Jena-91 was
not
> actually applied to the sources in this latest TDB 0.9.0 snapshot (
> tx-tdb-0.9.0-20110831.124751-10). When I updated the tx-TDB component
from
> SVN and looked NodeTableTrans, it seemed that the patch was not applied
> there either, so perhaps it was not actually delivered ? Paolo, can you
> please verify this?
There is a fix in the Aug 31 build that addressed the Report_JENA91
tests - it's not that patch though. Further investigation found a
deeper problem that the patch perturbed, but did not necessarily fix.
> Anyhow, I manually applied the patch on this build, but I keep running
> into the same problems. The first exception that shows is :
Is your copy of ARQ in step with that TDB build?
>
> java.lang.UnsupportedOperationException: Quad: object cannot be null
> at com.hp.hpl.jena.sparql.core.Quad.<init>(Quad.java:50)
> at com.hp.hpl.jena.tdb.lib.TupleLib.quad(TupleLib.java:127)
> at com.hp.hpl.jena.tdb.lib.TupleLib.quad(TupleLib.java:118)
> at
com.hp.hpl.jena.tdb.lib.TupleLib.access$100(TupleLib.java:32)
> at com.hp.hpl.jena.tdb.lib.TupleLib$4.convert(TupleLib.java:76)
> at com.hp.hpl.jena.tdb.lib.TupleLib$4.convert(TupleLib.java:72)
> at org.openjena.atlas.iterator.Iter$4.next(Iter.java:267)
> at
> com.hp.hpl.jena.tdb.store.GraphTDBBase$ProjectQuadsToTriples.next(
> GraphTDBBase.java:183)
> at
> com.hp.hpl.jena.tdb.store.GraphTDBBase$ProjectQuadsToTriples.next(
> GraphTDBBase.java:171)
> at com.hp.hpl.jena.util.iterator.WrappedIterator.next(
> WrappedIterator.java:68)
> at com.hp.hpl.jena.util.iterator.Map1Iterator.next(
> Map1Iterator.java:35)
> at com.hp.hpl.jena.util.iterator.WrappedIterator.next(
> WrappedIterator.java:68)
> at com.hp.hpl.jena.rdf.model.impl.StmtIteratorImpl.next(
> StmtIteratorImpl.java:33)
> at com.hp.hpl.jena.rdf.model.impl.StmtIteratorImpl.next(
> StmtIteratorImpl.java:21)
>
> and after that I also see
>
> 11:40:43,857 [jazz.jfs.resuming.indexer.internal.triple] ERROR
> com.ibm.team.jfs - Originating
> Exception:
> com.hp.hpl.jena.tdb.base.file.FileException:
> ObjectFile.read(61)[361][361]: Impossibly large object : 1869495647
bytes
> at com.hp.hpl.jena.tdb.base.objectfile.ObjectFileStorage.read(
> ObjectFileStorage.java:282)
> at com.hp.hpl.jena.tdb.lib.NodeLib.fetchDecode(NodeLib.java:60)
> at
> com.hp.hpl.jena.tdb.nodetable.NodeTableNative.readNodeFromTable(
> NodeTableNative.java:164)
> at
> com.hp.hpl.jena.tdb.nodetable.NodeTableNative._retrieveNodeByNodeId(
> NodeTableNative.java:88)
> at
com.hp.hpl.jena.tdb.nodetable.NodeTableNative.getNodeForNodeId(
> NodeTableNative.java:59)
> at
> com.hp.hpl.jena.tdb.nodetable.NodeTableCache._retrieveNodeByNodeId(
> NodeTableCache.java:89)
> at
com.hp.hpl.jena.tdb.nodetable.NodeTableCache.getNodeForNodeId(
> NodeTableCache.java:60)
> at
> com.hp.hpl.jena.tdb.nodetable.NodeTableWrapper.getNodeForNodeId(
> NodeTableWrapper.java:44)
> at
com.hp.hpl.jena.tdb.nodetable.NodeTableInline.getNodeForNodeId(
> NodeTableInline.java:56)
> at com.hp.hpl.jena.tdb.lib.TupleLib.quad(TupleLib.java:125)
> at com.hp.hpl.jena.tdb.lib.TupleLib.quad(TupleLib.java:118)
> at
com.hp.hpl.jena.tdb.lib.TupleLib.access$100(TupleLib.java:32)
> at com.hp.hpl.jena.tdb.lib.TupleLib$4.convert(TupleLib.java:76)
> at com.hp.hpl.jena.tdb.lib.TupleLib$4.convert(TupleLib.java:72)
> at org.openjena.atlas.iterator.Iter$4.next(Iter.java:267)
> at
> com.hp.hpl.jena.tdb.store.GraphTDBBase$ProjectQuadsToTriples.next(
> GraphTDBBase.java:183)
> at
> com.hp.hpl.jena.tdb.store.GraphTDBBase$ProjectQuadsToTriples.next(
> GraphTDBBase.java:171)
> at com.hp.hpl.jena.util.iterator.WrappedIterator.next(
> WrappedIterator.java:68)
> at com.hp.hpl.jena.util.iterator.Map1Iterator.next(
> Map1Iterator.java:35)
> at com.hp.hpl.jena.util.iterator.WrappedIterator.next(
> WrappedIterator.java:68)
> at com.hp.hpl.jena.rdf.model.impl.StmtIteratorImpl.next(
> StmtIteratorImpl.java:33)
> at com.hp.hpl.jena.rdf.model.impl.StmtIteratorImpl.next(
> StmtIteratorImpl.java:21)
>
> This seems to be the same as what I saw before. It is possible I am
still
> messing something up by manually applying the patch, I'll definitely
keep
> looking at that. If I can get a new TDB 0.9.0 build with the patch
> applied, I will definitely check again
Let's break this down into smaller elements.
First exception first (because the second one may be caused by the first).
Do you have a test case for
java.lang.UnsupportedOperationException: Quad: object cannot be null
What's the operation causing it (the stacktrace does nto go back far
enough but I presume a SPARQL Update or something is being done.)
Andy
