[Mulgara-dev] corrupted statement store?

Life is hard, and then you die ronald at innovation.ch
Mon Aug 20 04:29:43 UTC 2007


On Mon, Aug 20, 2007 at 12:01:54PM +1000, Andrae Muys wrote:
> 
> On 19/08/2007, at 9:12 PM, Life is hard, and then you die wrote:
> 
> >We just hit a problem while doing a whole bunch of updates ( 'delete
> >select's followed by 'insert') which looks like a data corruption
> >issue. The command
> >
> >  delete select $s $p $o from <local:///topazproject#ri> where $s  
> >$p $o and $s <mulgara:is> <info:doi/10.1371/journal.pone. 
> >0000278.t004> from <local:///topazproject#ri>;
> >
> >is failing with a StatementStoreException. Here's an excerpt of the
> >log at level debug:
> >
> >  WARN 43:09 StatementStoreResolver> Failed to modifyModel:  
> >[info:doi/10.1371/journal.pone.0000278.t004 http://purl.org/dc/ 
> >elements/1.1/date "2007-03-13"^^<http://www.w3.org/2001/ 
> >XMLSchema#date> local:///topazproject#ri]
> >  org.mulgara.store.statement.StatementStoreException: Attempt to  
> >remove a triple with node number out of range: 85026 337 -1 48
> >          at org.mulgara.store.statement.xa.XAStatementStoreImpl 
> >$Phase.removeTriple(XAStatementStoreImpl.java:1631)
> >          at  
> >org.mulgara.store.statement.xa.XAStatementStoreImpl.removeTriples 
> >(XAStatementStoreImpl.java:482)
> >          at  
> >org.mulgara.resolver.store.StatementStoreResolver.modifyModel 
> >(StatementStoreResolver.java:369)
> >          at org.mulgara.resolver.InternalResolver.modifyModel 
> >(InternalResolver.java:161)
> >
> >Now the next log message is interesting:
> >
> >  WARN 43:09 StatementStoreResolver> Note: if any of the query  
> >nodes are negative this is a known bug [ 1089540 ] INSERT/SELECT  
> >regression in sourceforge
> >
> >Well, I looked at that bug and it was closed almost 2 years ago:
> >http://sourceforge.net/tracker/? 
> >group_id=89874&atid=591704&aid=1089540&func=detail
> >
> >Unfortunately there's no indication in there of how it was fixed. So,
> >my question (I guess mainly to Andrae, since he closed it) is: is that
> >fix in the current code base, i.e. is this a new bug or the old one?
> >And if the latter, what was the fix?
> 
> Ok well the reference to the sourceforge bug isn't quite correct - it  
> only strictly applies to INSERT/SELECT not DELETE/SELECT - however  
> the bug is going to be similar.

Ok.

> The specific problem is that I suspect that <info:doi/10.1371/ 
> journal.pone.0000278.t004> doesn't exist in the store anywhere, if  
> you think it should then the fact that we aren't finding it is the  
> problem.
> 
> The bug is that any URI/Literal that doesn't exist already in the  
> store is assigned a temporary (negative) node number - these numbers  
> are only valid for the duration of a transaction and cannot be  
> persisted.  One bug you have uncovered here is that because the  
> insert and delete code paths are almost identical they share a lot of  
> common code and this check is in that common code.  In the case of an  
> insert it is an error, in the case of a delete it should be short- 
> circuited silently, the statement cannot exist in the store.
> 
> If you can reassure yourself that the URI above doesn't exist in the  
> store then submit a bug report, and I'll fix it ASAP - if not then we  
> have a slightly longer chase on our hands.

The URI does exist. Here's some more from the log at level debug (I'll
send you a complete log privately):

  DEBUG 10:44 TuplesWrapperStatements> Getting subject
  DEBUG 10:44 WrappedTuples> Getting column 0 from wrapped class org.mulgara.resolver.spi.LocalizedTuples
  DEBUG 10:44 SubqueryAnswer> Getting object 0 from variableList [$s, $p, $o]
  DEBUG 10:44 AppendAggregateTuples> AppendAggregateTuples 1634052921: getting column 0
  DEBUG 10:44 XAStringPoolImpl> findSPObject(85026) = <info:doi/10.1371/journal.pone.0000278.t004>
  DEBUG 10:44 XAStringPoolImpl> findGNode(<info:doi/10.1371/journal.pone.0000278.t004>) = 85026
  DEBUG 10:44 XAStringPoolImpl> findSPObject(85026) = <info:doi/10.1371/journal.pone.0000278.t004>
  DEBUG 10:44 TuplesWrapperStatements> Getting predicate
  DEBUG 10:44 WrappedTuples> Getting column 1 from wrapped class org.mulgara.resolver.spi.LocalizedTuples
  DEBUG 10:44 SubqueryAnswer> Getting object 1 from variableList [$s, $p, $o]
  DEBUG 10:44 AppendAggregateTuples> AppendAggregateTuples 1634052921: getting column 1
  DEBUG 10:44 XAStringPoolImpl> findSPObject(337) = <http://purl.org/dc/elements/1.1/date>
  DEBUG 10:44 XAStringPoolImpl> findGNode(<http://purl.org/dc/elements/1.1/date>) = 337
  DEBUG 10:44 XAStringPoolImpl> findSPObject(337) = <http://purl.org/dc/elements/1.1/date>
  DEBUG 10:44 TuplesWrapperStatements> Getting object
  DEBUG 10:44 WrappedTuples> Getting column 2 from wrapped class org.mulgara.resolver.spi.LocalizedTuples
  DEBUG 10:44 SubqueryAnswer> Getting object 2 from variableList [$s, $p, $o]
  DEBUG 10:44 AppendAggregateTuples> AppendAggregateTuples 1634052921: getting column 2
  DEBUG 10:44 XAStringPoolImpl> findSPObject(484278) = "2007-03-13"^^<http://www.w3.org/2001/XMLSchema#date>
  DEBUG 10:44 XAStringPoolImpl> findGNode("2007-03-13"^^<http://www.w3.org/2001/XMLSchema#date>) = 0
  DEBUG 10:44 XAStringPoolImpl> findSPObject(48) = <#ri>
  WARN 10:44 StatementStoreResolver> Failed to modifyModel: [info:doi/10.1371/journal.pone.0000278.t004 http://purl.org/dc/elements/1.1/date "2007-03-13"^^<http://www.w3.org/2001/XMLSchema#date> local:///topazproject#ri]

The problem seems to be with the literal "2007-03-13", and I guess
this may really be a string-pool corruption?


  Cheers,

  Ronald




More information about the Mulgara-dev mailing list