[CURATOR-167] All registered watchers should be cleared on close

• Type: Bug
• Status: Closed
• Priority: Critical
• Resolution: Fixed
• Affects Version/s: 2.6.0
• Fix Version/s: 2.9.0
• Component/s: Client
• Labels: heap memory-leak node-cache

Environment

Linux 3.13.0-37-generic #64~precise1-Ubuntu SMP Wed Sep 24 21:39:43 UTC 2014 i686 i686 i386 GNU/Linux

java version "1.7.0_13"
Java(TM) SE Runtime Environment (build 1.7.0_13-b20)
Java HotSpot(TM) Server VM (build 23.7-b01, mixed mode)

• Assignee: Cam McKenzie
• Reporter: Craig McNally
• Created: 18/Nov/14 16:12
• Updated: 26/Aug/15 17:58
• Resolved: 26/Aug/15 05:34

Description

There's a memory leak in NodeCache. I was able to reliably reproduce the problem using a very simple test that performs the following:

1) Creates a CuratorFramework instance and starts it.
2) in a loop: Creates a NodeCache and starts it, then closes it.

Eventually you get a java.lang.OutOfMemoryError: Java heap space. This happens regardless of the heap size, though it happens much faster with a small heap.

Upon furher investigation w/ a profiler, I can see that each NodeCache is being referenced by the NamespaceWatcherMap.

Here's the test code:

NodeCacheLeakTest.java

import java.util.Date;

import org.apache.curator.framework.CuratorFramework;
import org.apache.curator.framework.CuratorFrameworkFactory;
import org.apache.curator.framework.recipes.cache.NodeCache;
import org.apache.curator.retry.ExponentialBackoffRetry;

public class NodeCacheLeakTest {

	public static void main(String[] args) throws Exception {

		String zkConnect;
		if (args.length > 0 && args[0] != null)
			zkConnect = args[0];
		else
			zkConnect = "localhost:2181/test";

		CuratorFramework curator = CuratorFrameworkFactory.newClient(zkConnect,
				new ExponentialBackoffRetry(500, 10));
		curator.start();

		int count = 0;
		while (true) {
			String nodePath = "/foo/node-" + (count);

			NodeCache cache = new NodeCache(curator, nodePath);
			cache.start(true);
			cache.close();

			count++;

			if (count % 1000 == 0)
				System.out.println(new Date() + " Started and Closed " + count
						+ " NodeCache instances");
		}
	}
}

And here's the output/OOM Error when using (-Xms10m -Xmx10m -XX:+UseG1GC):

log4j:WARN No appenders could be found for logger (org.apache.curator.framework.imps.CuratorFrameworkImpl).
log4j:WARN Please initialize the log4j system properly.
log4j:WARN See http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info.
Tue Nov 18 15:59:12 GMT+00:00 2014 Started and Closed 1000 NodeCache instances
Tue Nov 18 15:59:16 GMT+00:00 2014 Started and Closed 2000 NodeCache instances
Tue Nov 18 15:59:20 GMT+00:00 2014 Started and Closed 3000 NodeCache instances
Tue Nov 18 15:59:23 GMT+00:00 2014 Started and Closed 4000 NodeCache instances
Tue Nov 18 15:59:27 GMT+00:00 2014 Started and Closed 5000 NodeCache instances
Tue Nov 18 15:59:31 GMT+00:00 2014 Started and Closed 6000 NodeCache instances
Tue Nov 18 15:59:36 GMT+00:00 2014 Started and Closed 7000 NodeCache instances
Tue Nov 18 15:59:40 GMT+00:00 2014 Started and Closed 8000 NodeCache instances
Tue Nov 18 15:59:45 GMT+00:00 2014 Started and Closed 9000 NodeCache instances
Tue Nov 18 15:59:49 GMT+00:00 2014 Started and Closed 10000 NodeCache instances
Tue Nov 18 16:00:01 GMT+00:00 2014 Started and Closed 11000 NodeCache instances
java.lang.OutOfMemoryError: Java heap space
	at java.io.BufferedWriter.<init>(BufferedWriter.java:105)
	at java.io.BufferedWriter.<init>(BufferedWriter.java:88)
	at java.io.PrintStream.<init>(PrintStream.java:112)
	at java.io.PrintStream.<init>(PrintStream.java:175)
	at org.apache.jute.CsvOutputArchive.<init>(CsvOutputArchive.java:57)
	at org.apache.zookeeper.proto.RequestHeader.toString(RequestHeader.java:62)
	at java.lang.String.valueOf(String.java:2854)
	at java.lang.StringBuilder.append(StringBuilder.java:128)
	at org.apache.zookeeper.ClientCnxn$Packet.toString(ClientCnxn.java:308)
	at java.lang.String.valueOf(String.java:2854)
	at java.lang.StringBuilder.append(StringBuilder.java:128)
	at org.apache.zookeeper.ClientCnxn$SendThread.readResponse(ClientCnxn.java:815)
	at org.apache.zookeeper.ClientCnxnSocketNIO.doIO(ClientCnxnSocketNIO.java:94)
	at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:355)
	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1068)
java.lang.OutOfMemoryError: Java heap space
	at java.io.BufferedWriter.<init>(BufferedWriter.java:105)
	at java.io.BufferedWriter.<init>(BufferedWriter.java:88)
	at java.io.PrintStream.<init>(PrintStream.java:112)
	at java.io.PrintStream.<init>(PrintStream.java:175)
	at org.apache.jute.CsvOutputArchive.<init>(CsvOutputArchive.java:57)
	at org.apache.zookeeper.proto.RequestHeader.toString(RequestHeader.java:62)
	at java.lang.String.valueOf(String.java:2854)
	at java.lang.StringBuilder.append(StringBuilder.java:128)
	at org.apache.zookeeper.ClientCnxn$Packet.toString(ClientCnxn.java:308)
	at java.lang.String.valueOf(String.java:2854)
	at java.lang.StringBuilder.append(StringBuilder.java:128)
	at org.apache.zookeeper.ClientCnxn$SendThread.readResponse(ClientCnxn.java:815)
	at org.apache.zookeeper.ClientCnxnSocketNIO.doIO(ClientCnxnSocketNIO.java:94)
	at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:355)
	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1068)
java.lang.OutOfMemoryError: Java heap space
	at java.io.BufferedWriter.<init>(BufferedWriter.java:105)
	at java.io.BufferedWriter.<init>(BufferedWriter.java:88)
	at java.io.PrintStream.<init>(PrintStream.java:112)
	at java.io.PrintStream.<init>(PrintStream.java:175)
	at org.apache.jute.CsvOutputArchive.<init>(CsvOutputArchive.java:57)
	at org.apache.zookeeper.proto.RequestHeader.toString(RequestHeader.java:62)
	at java.lang.String.valueOf(String.java:2854)
	at java.lang.StringBuilder.append(StringBuilder.java:128)
	at org.apache.zookeeper.ClientCnxn$Packet.toString(ClientCnxn.java:308)
	at java.lang.String.valueOf(String.java:2854)
	at java.lang.StringBuilder.append(StringBuilder.java:128)
	at org.apache.zookeeper.ClientCnxn$SendThread.readResponse(ClientCnxn.java:815)
	at org.apache.zookeeper.ClientCnxnSocketNIO.doIO(ClientCnxnSocketNIO.java:94)
	at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:355)
	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1068)
java.lang.OutOfMemoryError: Java heap space
	at java.io.BufferedWriter.<init>(BufferedWriter.java:105)
	at java.io.BufferedWriter.<init>(BufferedWriter.java:88)
	at java.io.PrintStream.<init>(PrintStream.java:112)
	at java.io.PrintStream.<init>(PrintStream.java:175)
	at org.apache.jute.CsvOutputArchive.<init>(CsvOutputArchive.java:57)
	at org.apache.zookeeper.proto.RequestHeader.toString(RequestHeader.java:62)
	at java.lang.String.valueOf(String.java:2854)
	at java.lang.StringBuilder.append(StringBuilder.java:128)
	at org.apache.zookeeper.ClientCnxn$Packet.toString(ClientCnxn.java:308)
	at java.lang.String.valueOf(String.java:2854)
	at java.lang.StringBuilder.append(StringBuilder.java:128)
	at org.apache.zookeeper.ClientCnxn$SendThread.readResponse(ClientCnxn.java:815)
	at org.apache.zookeeper.ClientCnxnSocketNIO.doIO(ClientCnxnSocketNIO.java:94)
	at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:355)
	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1068)

Exception: java.lang.OutOfMemoryError thrown from the UncaughtExceptionHandler in thread "main"

Additional Notes:

• When I don't specify the G1 collector I still get OutOfMemoryErrors, only the cause is "GC overhead limit exceeded".

  java.lang.OutOfMemoryError: GC overhead limit exceeded
  	at java.io.BufferedWriter.<init>(BufferedWriter.java:105)
  	at java.io.BufferedWriter.<init>(BufferedWriter.java:88)
  	at java.io.PrintStream.<init>(PrintStream.java:112)
  	at java.io.PrintStream.<init>(PrintStream.java:175)
  	at org.apache.jute.CsvOutputArchive.<init>(CsvOutputArchive.java:57)
  	at org.apache.zookeeper.proto.GetDataRequest.toString(GetDataRequest.java:62)
  	at java.lang.String.valueOf(String.java:2854)
  	at java.lang.StringBuilder.append(StringBuilder.java:128)
  	at org.apache.zookeeper.ClientCnxn$Packet.toString(ClientCnxn.java:310)
  	at java.lang.String.valueOf(String.java:2854)
  	at java.lang.StringBuilder.append(StringBuilder.java:128)
  	at org.apache.zookeeper.ClientCnxn$SendThread.readResponse(ClientCnxn.java:815)
  	at org.apache.zookeeper.ClientCnxnSocketNIO.doIO(ClientCnxnSocketNIO.java:94)
  	at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:355)
  	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1068)

• This has been around for a while as I first noticed it with v1.3.3. I upgraded to v2.6.0 and re-ran the test, but as you can see this still appears to be an issue.
• I ran this test on a x86_64 Ubuntu 10.043 system and observed the same behavior

Issue Links

• relates to: CURATOR-217 Use new Watcher Removal APIs in Curator Recipes