apoc.import.graphml works from JUnit but hangs in the application

[szarnyasg]

We discovered an interesting issue with @marci543 about apoc.import.graphml. Load always works, but:

• When executed from JUnit tests, the tests terminates normally.
• The whole application hangs instead of terminating, when the entry point of the application is the main method.

We use the latest version of everything (Neo4j 3.3.1 and APOC 3.3.0.1), with the following code:

public void run() throws IOException, KernelException {
	FileUtils.deleteRecursively(databaseDirectory);
	GraphDatabaseService graphDb = new GraphDatabaseFactory().newEmbeddedDatabaseBuilder(databaseDirectory)
			.setConfig("apoc.import.file.enabled", "true")
			.newGraphDatabase();
	Procedures proceduresService = ((GraphDatabaseAPI) graphDb).getDependencyResolver()
			.resolveDependency(Procedures.class);
	proceduresService.registerProcedure(ExportGraphML.class);

	try (Transaction t = graphDb.beginTx()) {
		graphDb.execute("CALL apoc.import.graphml('my.graphml', {batchSize: 1000, useTypes: true})");
		t.success();
	}

	System.out.println("Shutting down database ...");
	graphDb.shutdown();
}

We tried various workarounds:

• committing transaction t or not
• using YIELD ... RETURN or not
• iterating through results or not
• adding a shutdown hook or not

However, they made no difference. We also tried to suspend execution with the debugger, but all our code was already executed:

To allow reproducibility, I fired up a repo with an example project @ https://github.com/szarnyasg/neo4j-apoc-shutdown. I am using the latest IntelliJ IDEA.

[szarnyasg]

Btw, this actually reminded me of an issue from 2015, that required me to turn off the reference clearing queue for EMF models as it made JDK8 hang during execution. Details are at ftsrg/trainbenchmark-ttc#7. Not sure about whether it's applicable here.

[jexp]

Is that run method also inside a thread?
Can you just try this:

public void run() throws IOException, KernelException {
	FileUtils.deleteRecursively(databaseDirectory);
	GraphDatabaseService graphDb = new GraphDatabaseFactory().newEmbeddedDatabaseBuilder(databaseDirectory)
			.setConfig("apoc.import.file.enabled", "true")
			.newGraphDatabase();
	Procedures proceduresService = ((GraphDatabaseAPI) graphDb).getDependencyResolver()
			.resolveDependency(Procedures.class);
	proceduresService.registerProcedure(ExportGraphML.class);


        graphDb.execute("CALL apoc.import.graphml('my.graphml', {batchSize: 1000, useTypes: true})").close();

	System.out.println("Shutting down database ...");
	graphDb.shutdown();
}

[szarnyasg]

@jexp No, it's a single threaded application, and run is called directly from the main method. I tried your code now but it made no difference (https://github.com/szarnyasg/neo4j-apoc-shutdown/commit/ed3fac81b2af3d812e607ca6b82ebe7865ee74d7).

[jexp]

Can you get a full thread dump when it hangs?

AFAIK the graphml export does nothing special not even multi-threading.

[szarnyasg]

Sure:

"pool-1-thread-1@2847" daemon prio=5 tid=0x11 nid=NA waiting
  java.lang.Thread.State: WAITING
	  at sun.misc.Unsafe.park(Unsafe.java:-1)
	  at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
	  at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
	  at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
	  at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
	  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1073)
	  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
	  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	  at java.lang.Thread.run(Thread.java:748)

"pool-3-thread-1@6238" prio=5 tid=0x1d nid=NA waiting
  java.lang.Thread.State: WAITING
	  at sun.misc.Unsafe.park(Unsafe.java:-1)
	  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
	  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
	  at java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:403)
	  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
	  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
	  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	  at java.lang.Thread.run(Thread.java:748)

"ForkJoinPool.commonPool-worker-1@4589" daemon prio=5 tid=0x1c nid=NA waiting
  java.lang.Thread.State: WAITING
	  at sun.misc.Unsafe.park(Unsafe.java:-1)
	  at java.util.concurrent.ForkJoinPool.awaitWork(ForkJoinPool.java:1824)
	  at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1693)
	  at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:157)

"Finalizer@456" daemon prio=8 tid=0x3 nid=NA waiting
  java.lang.Thread.State: WAITING
	  at java.lang.Object.wait(Object.java:-1)
	  at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)
	  at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164)
	  at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)

"Reference Handler@457" daemon prio=10 tid=0x2 nid=NA waiting
  java.lang.Thread.State: WAITING
	  at java.lang.Object.wait(Object.java:-1)
	  at java.lang.Object.wait(Object.java:502)
	  at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
	  at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)

"DestroyJavaVM@6692" prio=5 tid=0x1e nid=NA runnable
  java.lang.Thread.State: RUNNABLE

"Signal Dispatcher@455" daemon prio=9 tid=0x4 nid=NA runnable
  java.lang.Thread.State: RUNNABLE

[jexp]

I'm missing main() somehow.

[szarnyasg]

It is missing. main() finishes, it's something else that gets stuck.

[szarnyasg]

[jexp]

Can you do just jstack ? (or the "camera" icon in IDEA.

[szarnyasg]

It seems it gives the same dumps:

[szarnyasg]

I added a Travis build for my project. This demonstrates the issue:

• gradle test works fine
• gradle run hangs (and the build is subsequently terminated for timing out)

https://travis-ci.org/szarnyasg/neo4j-apoc-shutdown

[jexp]

Seems to be related to pool shutdown.

I.e. the pool-3-thread-1, which is not a daemon thread.

I add an explicit pool shutdown on JVM shutdown. Usually Neo4j-server would just exit.

[jexp]

Fixed manually.

[marci543]

I came across this issue again.

I updated the example repo (https://github.com/szarnyasg/neo4j-apoc-shutdown/commit/ddcbc8f254b5d46490cba52ddf6558d572a82e89) to include the fix by @jexp (d6fd3c0), but it made no difference. It still doesn't terminate if it is run from main method:
https://travis-ci.org/szarnyasg/neo4j-apoc-shutdown/builds/584114732

Another issue I found is that org.neo4j.procedure:apoc should have dependency on commons-io:commons-io, but it is missing. (https://github.com/szarnyasg/neo4j-apoc-shutdown/commit/4d37963b2c67c5db3a4b0c9c48fdbc2112cc06cc)

Exception in thread "main" java.lang.NoClassDefFoundError: org/apache/commons/io/output/WriterOutputStream
	at apoc.util.ApocUrlStreamHandlerFactory.createURLStreamHandler(ApocUrlStreamHandlerFactory.java:13)
...
Caused by: java.lang.ClassNotFoundException: org.apache.commons.io.output.WriterOutputStream

https://travis-ci.org/szarnyasg/neo4j-apoc-shutdown/builds/584114536#L529