jankotek / blueprints

A Property Graph Model Interface
http://blueprints.tinkerpop.com
Other
2 stars 1 forks source link

NullPointerException with asyncWrite enabled #5

Open ncolomer opened 10 years ago

ncolomer commented 10 years ago

Hi Jan,

When I initialize a MapDBGraph as following:

DBMaker dbMaker = DBMaker.newFileDB(file);
//dbMaker.transactionDisable(); // EDIT: finally not necessary to make the issue appear
MapDBGraph graph = new MapDBGraph(dbMaker, false);

I face the following NPE under massive write load (~25k node/s & ~50k edge/s):

java.lang.RuntimeException: Writer thread failed
    at org.mapdb.AsyncWriteEngine.checkState(AsyncWriteEngine.java:263)
    at org.mapdb.AsyncWriteEngine.update(AsyncWriteEngine.java:354)
    at org.mapdb.Caches$HashTable.compareAndSwap(Caches.java:253)
    at org.mapdb.EngineWrapper.compareAndSwap(EngineWrapper.java:62)
    at org.mapdb.SnapshotEngine.compareAndSwap(SnapshotEngine.java:64)
    at org.mapdb.Atomic$Long.compareAndSet(Atomic.java:335)
    at org.mapdb.Atomic$Long.incrementAndGet(Atomic.java:391)
    at org.mapdb.Bind$1.update(Bind.java:136)
    at org.mapdb.BTreeMap.notify(BTreeMap.java:2713)
    at org.mapdb.BTreeMap.put2(BTreeMap.java:686)
    at org.mapdb.BTreeMap.put(BTreeMap.java:566)
    at org.mapdb.BTreeMap$KeySet.add(BTreeMap.java:1669)
    at com.tinkerpop.blueprints.impls.mapdb.MapDBGraph.addVertex(MapDBGraph.java:530)
    at me.test.core.graph.MapDBGeoGraph.addVertex(MapDBGeoGraph.java:32)
    at me.test.builder.dao.GraphWriter.saveNode(GraphWriter.java:64)
    at me.test.builder.dao.GraphWriter.save(GraphWriter.java:55)
    at me.test.builder.GraphWriterTask.process(GraphWriterTask.java:39)
    at java.lang.Thread.run(Thread.java:744)
Caused by: java.lang.NullPointerException
    at com.tinkerpop.blueprints.impls.mapdb.MapDBGraph$MVertex.equals(MapDBGraph.java:192)
    at org.mapdb.Fun$Tuple2.equals(Fun.java:104)
    at org.mapdb.LongConcurrentHashMap$Segment.remove(LongConcurrentHashMap.java:476)
    at org.mapdb.LongConcurrentHashMap.remove(LongConcurrentHashMap.java:829)
    at org.mapdb.AsyncWriteEngine.runWriter(AsyncWriteEngine.java:208)
    at org.mapdb.AsyncWriteEngine$WriterRunnable.run(AsyncWriteEngine.java:155)
    ... 1 more

I am using the 2.5.0-SNAPSHOT blueprints artifact (that pulls org.mapdb:mapdb:0.9.5).

Any idea?

ncolomer commented 10 years ago

Actually it seems the issue appears with the default configuration (no DBMaker modification). I wrote a unit test that reproduces the issue (it closely reflects my use case). The test was run on JDKs Hot Spot 1.7.u25 and 1.7 u45 and it always throws a NullPointerException.

Here is the unit test:

@Test
public void npe() throws Exception {
    // Given
    DBMaker dbMaker = DBMaker.newTempFileDB();
    MapDBGraph graph = new MapDBGraph(dbMaker, false);
    Map<Long, Object> index = DBMaker.newTempHashMap();

    final int MAX_VERTICES = 1320163;
    final int MAX_EDGES = 2320163;

    // When
    for (long customId = 0; customId < MAX_VERTICES; customId++) {
        Object vertexId = graph.addVertex(null).getId();
        index.put(customId, vertexId);
    }

    for (long e = 0; e < MAX_EDGES; e++) {
        Object tailId = index.get(ThreadLocalRandom.current().nextLong(MAX_VERTICES));
        Vertex tail = graph.getVertex(tailId);
        Object headId = index.get(ThreadLocalRandom.current().nextLong(MAX_VERTICES));
        Vertex head = graph.getVertex(headId);
        graph.addEdge(null, tail, head, "label"); // Issue is thrown here
    }
}

And the stacktrace:

java.lang.RuntimeException: Writer thread failed
    at org.mapdb.AsyncWriteEngine.checkState(AsyncWriteEngine.java:263)
    at org.mapdb.AsyncWriteEngine.get(AsyncWriteEngine.java:319)
    at org.mapdb.Caches$HashTable.get(Caches.java:212)
    at org.mapdb.EngineWrapper.get(EngineWrapper.java:50)
    at org.mapdb.BTreeMap.put2(BTreeMap.java:599)
    at org.mapdb.BTreeMap.put(BTreeMap.java:566)
    at org.mapdb.BTreeMap$KeySet.add(BTreeMap.java:1669)
    at com.tinkerpop.blueprints.impls.mapdb.MapDBGraph.addEdge(MapDBGraph.java:604)
    at it.cartrack.conflation.builder.LauncherTest.npe(LauncherTest.java:48)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:45)
    at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
    at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:42)
    at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
    at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:263)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:68)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:47)
    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:231)
    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:60)
    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:229)
    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:50)
    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:222)
    at org.junit.runners.ParentRunner.run(ParentRunner.java:300)
    at org.junit.runner.JUnitCore.run(JUnitCore.java:157)
    at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:74)
    at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:202)
    at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:65)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at com.intellij.rt.execution.application.AppMain.main(AppMain.java:120)
Caused by: java.lang.NullPointerException
    at com.tinkerpop.blueprints.impls.mapdb.MapDBGraph$MEdge.equals(MapDBGraph.java:340)
    at org.mapdb.Fun$Tuple2.equals(Fun.java:104)
    at org.mapdb.LongConcurrentHashMap$Segment.remove(LongConcurrentHashMap.java:476)
    at org.mapdb.LongConcurrentHashMap.remove(LongConcurrentHashMap.java:829)
    at org.mapdb.AsyncWriteEngine.runWriter(AsyncWriteEngine.java:208)
    at org.mapdb.AsyncWriteEngine$WriterRunnable.run(AsyncWriteEngine.java:155)
    at java.lang.Thread.run(Thread.java:744)

Following, the line in org.mapdb.AsyncWriteEngine that is invoked and causes the issue. In this case, item.a.id is null, causing a NPE when equals() is called deeper in the trace.

207: //record has been written to underlying Engine, so remove it from cache with CAS
208: writeCache.remove(recid, item); 

This item is retrieved from writeCache.longMapIterator(). There is probably a problem inside the LongConcurrentHashMap class, when new HashEntry are instanciated.

I may be totally wrong but I guess that vertices (that were added) were not totally flushed or something like that. When I retrieve them in the second loop, some of them may not be fully loaded causing the missing id. Maybe kind of commit or force flush could help? Or it's juste a bug :)

ncolomer commented 10 years ago

I also tried to run this test with MapDB v0.9.7 (the last stable v0.9.8 introduces API breaking changes). The result is the same and the same NPE issue is thrown (missing entry's id). I'm quite stuck from this point... do you have any hint/idea on this?