History | Log In     View a printable version of the current page. Get help!  
Issue Details [XML]

Key: SES-631
Type: Bug Bug
Status: Closed Closed
Resolution: Fixed
Priority: Critical Critical
Assignee: Arjohn Kampman
Reporter: Jan Stette
Votes: 0
Watchers: 1
Operations

If you were logged in you would be able to see more operations.
Sesame

NativeStore statement index corruption

Created: 04/Nov/08 01:26 PM   Updated: 17/Dec/08 02:05 PM
Component/s: Native Sail
Affects Version/s: 2.2, 2.2.1
Fix Version/s: 2.2.2


 Description   
We have seen an assertion error at the following point:

WARN 13:37:05,929 [thread] nativerdf.NativeStoreConnection Rolling back transaction due to connection close
java.lang.Throwable
at org.openrdf.sail.helpers.SailConnectionBase.close(SailConnectionBase.java:172)
at org.openrdf.repository.sail.SailRepositoryConnection.close(SailRepositoryConnection.java:104)
at org.openrdf.repository.base.RepositoryConnectionWrapper.close(RepositoryConnectionWrapper.java:225)
at org.openrdf.repository.event.base.NotifyingRepositoryConnectionWrapper.close(NotifyingRepositoryConnectionWrapper.java:147)
at org.openrdf.repository.base.RepositoryConnectionWrapper.close(RepositoryConnectionWrapper.java:225)
at org.openrdf.repository.event.base.InterceptingRepositoryConnectionWrapper.close(InterceptingRepositoryConnectionWrapper.java:133)
at org.openrdf.repository.base.RepositoryConnectionWrapper.close(RepositoryConnectionWrapper.java:225)

This is in the code which in BTree which says:

public void deregister(NodeListener listener) {
synchronized (listeners) {
assert listeners.contains(listener);
listeners.remove(listener);
}
}

This is not easily reproducable, we have only seen this happen once.


 All   Comments   Change History      Sort Order:
Comment by Jan Stette [04/Nov/08 03:54 PM]
We've also seen the following IllegalArgumentException. I don't know if it's the same problem, but it also occurs in BTree when closing a Sail connection, so I've reported it here for now.

We can't easily reproduce this case either. Given the intermittent nature of these, could they be race condition due to multiple threads accessing the repository?

java.lang.IllegalArgumentException: id must be larger than 0, is: 0
at org.openrdf.sail.nativerdf.btree.BTree.readNode(BTree.java:1162)
at org.openrdf.sail.nativerdf.btree.BTree.access$700(BTree.java:42)
at org.openrdf.sail.nativerdf.btree.BTree$Node.getChildNode(BTree.java:1472)
at org.openrdf.sail.nativerdf.btree.BTree$RangeIterator.findNext(BTree.java:2018)
at org.openrdf.sail.nativerdf.btree.BTree$RangeIterator.next(BTree.java:1934)
at org.openrdf.sail.nativerdf.TripleStore.discardTriples(TripleStore.java:746)
at org.openrdf.sail.nativerdf.TripleStore.rollback(TripleStore.java:857)
at org.openrdf.sail.nativerdf.NativeStoreConnection.rollbackInternal(NativeStoreConnection.java:370)
at org.openrdf.sail.helpers.SailConnectionBase.close(SailConnectionBase.java:176)
at org.openrdf.repository.sail.SailRepositoryConnection.close(SailRepositoryConnection.java:104)
at org.openrdf.repository.base.RepositoryConnectionWrapper.close(RepositoryConnectionWrapper.java:225)
at org.openrdf.repository.event.base.NotifyingRepositoryConnectionWrapper.close(NotifyingRepositoryConnectionWrapper.java:147)
at org.openrdf.repository.base.RepositoryConnectionWrapper.close(RepositoryConnectionWrapper.java:225)
org.openrdf.repository.event.base.InterceptingRepositoryConnectionWrapper.close(InterceptingRepositoryConnectionWrapper.java:133)
at org.openrdf.repository.base.RepositoryConnectionWrapper.close(RepositoryConnectionWrapper.java:225)

Comment by Jan Stette [07/Nov/08 12:11 PM]
We are now seeing this more frequently. Also, these cases seem to be preceded by the following:

- We call commit() on a repository connection
- We then close the connection.
- For some reason, this starts to roll back a transaction (I'm pretty sure there shouldn't be a remaining transaction at this point)
- There's a NullPointerException in BTree$Node.setValue()

Then the above IllegalArgumentException happens.

INFO 10:52:54,853 [thread] repository.RepositoryConnectionWrapper Commit called on repository xxxx
WARN 10:52:59,903 [thread] nativerdf.NativeStoreConnection Rolling back transaction due to connection close
java.lang.Throwable
at org.openrdf.sail.helpers.SailConnectionBase.close(SailConnectionBase.java:172)
at org.openrdf.repository.sail.SailRepositoryConnection.close(SailRepositoryConnection.java:104)
at org.openrdf.repository.base.RepositoryConnectionWrapper.close(RepositoryConnectionWrapper.java:225)
at org.openrdf.repository.event.base.NotifyingRepositoryConnectionWrapper.close(NotifyingRepositoryConnectionWrapper.java:147)
at org.openrdf.repository.base.RepositoryConnectionWrapper.close(RepositoryConnectionWrapper.java:225)
at org.openrdf.repository.event.base.InterceptingRepositoryConnectionWrapper.close(InterceptingRepositoryConnectionWrapper.java:133)
at org.openrdf.repository.base.RepositoryConnectionWrapper.close(RepositoryConnectionWrapper.java:225)
<...>
WARN 10:53:02,069 [thread] repository.RepositoryUtils Exception while closing connection
java.lang.NullPointerException
at info.aduna.io.ByteArrayUtil.put(ByteArrayUtil.java:21)
at org.openrdf.sail.nativerdf.btree.BTree$Node.setValue(BTree.java:1395)
at org.openrdf.sail.nativerdf.btree.BTree.removeFromTree(BTree.java:999)
at org.openrdf.sail.nativerdf.btree.BTree.removeFromTree(BTree.java:1010)
at org.openrdf.sail.nativerdf.btree.BTree.removeFromTree(BTree.java:1010)
at org.openrdf.sail.nativerdf.btree.BTree.remove(BTree.java:932)
at org.openrdf.sail.nativerdf.TripleStore.discardTriples(TripleStore.java:756)
at org.openrdf.sail.nativerdf.TripleStore.rollback(TripleStore.java:857)
at org.openrdf.sail.nativerdf.NativeStoreConnection.rollbackInternal(NativeStoreConnection.java:370)
at org.openrdf.sail.helpers.SailConnectionBase.close(SailConnectionBase.java:176)
at org.openrdf.repository.sail.SailRepositoryConnection.close(SailRepositoryConnection.java:104)
at org.openrdf.repository.base.RepositoryConnectionWrapper.close(RepositoryConnectionWrapper.java:225)
at org.openrdf.repository.event.base.NotifyingRepositoryConnectionWrapper.close(NotifyingRepositoryConnectionWrapper.java:147)
at org.openrdf.repository.base.RepositoryConnectionWrapper.close(RepositoryConnectionWrapper.java:225)
at org.openrdf.repository.event.base.InterceptingRepositoryConnectionWrapper.close(InterceptingRepositoryConnectionWrapper.java:133)
at org.openrdf.repository.base.RepositoryConnectionWrapper.close(RepositoryConnectionWrapper.java:225)
<...>

Then the IllegalArgumentException above happens.

Comment by James Leigh [11/Nov/08 10:21 PM]
Jan, could any of the connections be modifying more than 10% of the total triples?
What version of Java are you using (java -version)?
How many processes (or cores) are on the host machine? What architecture is it (x86)?

Comment by Jan Stette [12/Nov/08 12:13 PM]
James, I've had a look at some of the cases where we see this, and this does seem to happen when we are deleting a relatively large number of triples. In one case, it happened when calling clear() on a repository. In another, it happened while committing a transaction that included a large number of deletions.

This problem has been seen on both Windows and Linux boxes. The Linux boxes are using the following versions:

Ubuntu 64 bit server:
Linux <...> 2.6.22-14-server #1 SMP Tue Feb 12 03:10:53 UTC 2008 x86_64 GNU/Linux

Java 1.6
java version "1.6.0_03"
Java(TM) SE Runtime Environment (build 1.6.0_03-b05)
Java HotSpot(TM) 64-Bit Server VM (build 1.6.0_03-b05, mixed mode)

Comment by Arjohn Kampman [13/Nov/08 01:53 PM]
The actual exception that occurred on commit was hidden because close() was called in a finally-block. The actual exception was:

java.lang.NullPointerException
       at info.aduna.io.ByteArrayUtil.put(ByteArrayUtil.java:21)
       at org.openrdf.sail.nativerdf.btree.BTree$Node.setValue(BTree.java:1395)
       at org.openrdf.sail.nativerdf.btree.BTree.removeFromTree(BTree.java:999)
       at org.openrdf.sail.nativerdf.btree.BTree.remove(BTree.java:932)
       at org.openrdf.sail.nativerdf.TripleStore.discardTriples(TripleStore.java:756)
       at org.openrdf.sail.nativerdf.TripleStore.commit(TripleStore.java:785)
       at org.openrdf.sail.nativerdf.NativeStoreConnection.commitInternal(NativeStoreConnection.java:344)
       at org.openrdf.sail.helpers.SailConnectionBase.commit(SailConnectionBase.java:294)
       at org.openrdf.repository.sail.SailRepositoryConnection.commit(SailRepositoryConnection.java:81)
       at org.openrdf.repository.event.base.NotifyingRepositoryConnectionWrapper.commit(NotifyingRepositoryConnectionWrapper.java:160)
       at org.openrdf.repository.event.base.InterceptingRepositoryConnectionWrapper.commit(InterceptingRepositoryConnectionWrapper.java:151)
       at org.openrdf.repository.base.RepositoryConnectionWrapper.commit(RepositoryConnectionWrapper.java:232)

Comment by Arjohn Kampman [20/Nov/08 01:30 PM]
This issue is now reproducable, scheduling it for a fix in 2.2.2.
This issue seems to cause data file corruption, raising prority to Critical.

Comment by Arjohn Kampman [26/Nov/08 10:14 AM]
A bug has been found (and fixed) in the code that restores the info from disk about which nodes are being used by the BTree underlying the statement indexes. This bug potentially caused specific nodes to be erroneously flagged as unused. As a result of this, the BTree would reuse these nodes for new data, overwriting the existing data, or truncate the data file in cases where these nodes were at the end of the file.