[Mulgara-dev] corrupted string-pool?

[Andrae Muys]

On 14/02/2007, at 10:33 PM, Life is hard, and then you die wrote:
>   ...
>   DEBUG 20:19 XAStringPoolImpl> findSPObject(15570) = <info:doi/ 
> 10.1371/journal.pone.0000146/category/5>
>   DEBUG 20:19 XAStringPoolImpl> findSPObject(15789) = Blank node
>   INFO 20:19 DatabaseSession> Rollback Transactional Block
>   DEBUG 20:19 DatabaseSession> Marking transaction for rollback
>   java.lang.NullPointerException
>           at org.mulgara.resolver.BackupOperation.backupDatabase 
> (BackupOperation.java:192)
>           at org.mulgara.resolver.BackupOperation.execute 
> (BackupOperation.java:145)
>           at org.mulgara.resolver.DatabaseSession.execute 
> (DatabaseSession.java:1339)
>           at org.mulgara.resolver.DatabaseSession.backup 
> (DatabaseSession.java:1290)
>           at org.mulgara.resolver.DatabaseSession.backup 
> (DatabaseSession.java:493)        at  
> org.mulgara.itql.ItqlInterpreter.outABackupCommand 
> (ItqlInterpreter.java:2325)
>           at  
> org.mulgara.itql.analysis.DepthFirstAdapter.caseABackupCommand 
> (DepthFirstAdapter.java:157)
>           at org.mulgara.itql.node.ABackupCommand.apply 
> (ABackupCommand.java:50)
>           at  
> org.mulgara.itql.analysis.DepthFirstAdapter.caseACommandStart 
> (DepthFirstAdapter.java:51)
>           at org.mulgara.itql.node.ACommandStart.apply 
> (ACommandStart.java:30)
>           at org.mulgara.itql.analysis.DepthFirstAdapter.caseStart 
> (DepthFirstAdapter.java:31)
>           at org.mulgara.itql.node.Start.apply(Start.java:33)
>           at org.mulgara.itql.ItqlInterpreter.executeCommand 
> (ItqlInterpreter.java:572)
>
> Has anybody seen something like this before?
>
> Btw., I've tried to reproduce this by taking an empty db and replaying
> all inserts in deletes in the same order they occurred, but the
> resulting db is fine.
>
> TIA for any info.

Well I just finished dinner, and as that included three glasses of  
wine I won't be doing any more debugging tonight than I've just  
done.  Still I took a look at that NPE stacktrace, and it is very  
interesting, looking at BackupOperation:192 we see:

     Tuples t = stringPool.findGNodes(null, null);
     assert t != null;
     try {
       t.beforeFirst();
       while (t.next()) {
         long localNode = t.getColumnValue(0);
         writer.write(Long.toString(localNode));
         writer.write(' ');

         SPObject spObject = stringPool.findSPObject(localNode);
         writer.write(spObject.getEncodedString());

That last line is 192 - and the NPE will be because findSPObject  
returned null - except that localNode was returned from a call to  
findGNodes().  Now only Literals and URIs are stored in the  
StringPool - in fact a localNode is a blank-node iff it is in the  
StatementStore but not in the StringPool!  So there should be *no*  
blank-nodes returned from a findGNodes (which returns the localNodes  
in the StringPool - ie. URIs and Literals only).

Well that explains the NPE, and it also explains why you are seeing a  
blank-node in the query result.  What it doesn't explain is why we  
suddenly have a NULL in your StringPool.

As near as I can tell the findGNodes() method being called is the 3  
argument call on Phase in XAStringPoolImpl:2112 (if you could confirm  
this it would be appreciated).

The findSPObject() method is ultimately a call on findSPObject/2 in  
XAStringPoolImpl:1820.  From there I see only two ways to return  
null, corresponding to line 1856 and 1837.  If you could identify  
which of these is the guilty party I will chase this down further in  
the morning.

Thanks,

Andrae

-- 
Andrae Muys
andrae at netymon.com
Principal Mulgara Consultant
Netymon Pty Ltd