Skip to content

Instantly share code, notes, and snippets.

@blalor
Last active December 19, 2015 10:59
Show Gist options
  • Select an option

  • Save blalor/5944538 to your computer and use it in GitHub Desktop.

Select an option

Save blalor/5944538 to your computer and use it in GitHub Desktop.
Vert.x SockJS memory leak diagnosis

Vert.x 1.3.1.final SockJS memory leak reproduction

This gist contains code to reproduce a memory leak in Vert.x when a SockJS client fails to disconnect cleanly. Also provided is a heap dump generated by the JVM on my laptop.

overview

Vert.x has a memory leak in its SockJS implementation. If a SockJS client connects, subscribes to EventBus messages (via the EventBus bridge), and then disappears without closing its connection, Vert.x will continue to accumulate pending writes until memory is exhausted. I have reproduced this with multiple transports. This scenario can happen in the real world if the client has a flaky network connection, or perhaps if the user merely puts their laptop to sleep.

requirements

steps to reproduce (PhantomJS)

First, clone this gist: git clone https://gist.github.com/5944538.git

Open two terminal windows. In the first, execute ./run.sh 2>&1 | fgrep -v ', sending frame'. Once it's running, every 3 seconds you'll see a summary of the JVM's heap usage output to the console.

heap -- used: 7079328, committed: 8060928, max: 8060928, free: 12.18

In the second terminal window, run phantomjs phantom_diag.js. You'll see the following as it connects and start receiving EventBus messages:

=> http://localhost:9191/diag.html
=> http://cdn.sockjs.org/sockjs-0.2.1.min.js
=> http://localhost:9191/vertxbus.js
initial page load completed
=> http://localhost:9191/eventbus/info
CONSOLE: Opening transport: iframe-htmlfile  url:http://localhost:9191/eventbus/272/299q210v  RTO:235
=> http://localhost:9191/eventbus/iframe.html#qo42kuv9
=> http://cdn.sockjs.org/sockjs-0.2.1.min.js
=> http://localhost:9191/eventbus/272/299q210v/htmlfile?c=_jp.aczjbif
=> http://localhost:9191/eventbus/272/299q210v/xhr_send
=> http://localhost:9191/eventbus/272/299q210v/htmlfile?c=_jp.aimonuw

In the first terminal window you'll see activity related to this client (heap info removed for clarity):

Got request in sockjs server: /diag.html 
Got request in sockjs server: /vertxbus.js 
Got request in sockjs server: /eventbus/info 
In Info handler 
Got request in sockjs server: /eventbus/iframe.html 
In Iframe handler 
Got request in sockjs server: /eventbus/272/299q210v/htmlfile?c=_jp.aczjbif 
HtmlFile, get: /eventbus/272/299q210v/htmlfile?c=_jp.aczjbif 
Got request in sockjs server: /eventbus/272/299q210v/xhr_send 
XHR send, post, /eventbus/272/299q210v/xhr_send 
XHR send processed ok 
More than maxBytes sent so closing connection 
Got request in sockjs server: /eventbus/272/299q210v/htmlfile?c=_jp.aimonuw 
HtmlFile, get: /eventbus/272/299q210v/htmlfile?c=_jp.aimonuw 

Back in the PhantomJS terminal window, suspend the process:

=> http://localhost:9191/eventbus/272/299q210v/htmlfile?c=_jp.akqulnu
^Z
[1]+  Stopped                 phantomjs phantom_diag.js

In the first terminal window you'll see the free heap steadily decrease (with an occasional bump as the garbage collector tries in vain to free up memory), and eventually an OutOfMemoryError will be raised:

More than maxBytes sent so closing connection 
Got request in sockjs server: /eventbus/272/299q210v/htmlfile?c=_jp.akqulnu 
HtmlFile, get: /eventbus/272/299q210v/htmlfile?c=_jp.akqulnu 
heap -- used: 7409512, committed: 8060928, max: 8060928, free: 8.08
heap -- used: 7716920, committed: 8060928, max: 8060928, free: 4.27
heap -- used: 7280408, committed: 8060928, max: 8060928, free: 9.68
heap -- used: 7555264, committed: 8060928, max: 8060928, free: 6.27
More than maxBytes sent so closing connection 
heap -- used: 7348456, committed: 8060928, max: 8060928, free: 8.84
heap -- used: 7644936, committed: 8060928, max: 8060928, free: 5.16
heap -- used: 7429472, committed: 8060928, max: 8060928, free: 7.83
heap -- used: 7623248, committed: 8060928, max: 8060928, free: 5.43
…
heap -- used: 7727136, committed: 8060928, max: 8060928, free: 4.14
java.lang.OutOfMemoryError: GC overhead limit exceeded
Dumping heap to java_pid48809.hprof ...
Heap dump file created [14496158 bytes in 0.185 secs]
Exception in Java verticle script 
java.lang.OutOfMemoryError: GC overhead limit exceeded
    at […]

Note that a heap dump is generated by the JVM.

steps to reproduce (virtual machine)

Start the Vert.x server as above. In a web browser on the VM, open http://host.ip.address:9191/diag.html. Once the server shows activity, disconnect the network interface of your VM. In VMware Fusion, you do this from the "Virtual Machine" menu: Virtual Machine → Network Adapter → Disconnect Network Adapter. The same behavior will be exhibited by the server.

analysis

This example purposely uses a ridiculously small allocated heap (8mb) in order to make this problem reproducible in a short period of time. Our production application generally exhibits memory exhaustion after 4-6 hours of heavy use.

Open the provided or generated heap dump in MemoryAnalyzer. In the overview, open the Dominator Tree to view the biggest objects. The largest instance is consistently the HashedWheelTimer, and it does take up the majority of the memory, in excess of 2/3rds in this heap-restricted example. Also notable is the instance of org.vertx.java.core.sockjs.impl.Session which has nearly 3,000 items in its pendingWrites LinkedList.

Our experience with this situation in our production application shows that there are often multiple Session instances, each with thousands of pending writes. MemoryAnalyzer consistently flags those as leak suspects.

screenshots

Pie chart of largest objects
The dominator tree showing the largest objects
Details of the Session instance
Details of Session.pendingWrites' LinkedList

/*jshint globalstrict: true */
/*global load:true, async:true, java:true, vertx:true, console:true */
"use strict";
load('vertx.js');
vertx.deployModule(
'vertx.web-server-v1.0',
{
port: 9191,
bridge: true,
web_root: ".",
inbound_permitted: [ {} ],
outbound_permitted: [ {} ]
},
1
);
// eventbus message generator
var count = 0;
vertx.setPeriodic(10, function() {
var msg = {
count: count++,
timestamp: (new Date()).getTime()
};
vertx.eventBus.publish("message", msg);
});
// jvm heap logger
var memoryBean = java.lang.management.ManagementFactory.getMemoryMXBean();
vertx.setPeriodic(3000, function() {
var heapUsage = memoryBean.getHeapMemoryUsage();
console.log(
"heap -- used: " + heapUsage.getUsed() +
", committed: " + heapUsage.getCommitted() +
", max: " + heapUsage.getMax() +
", free: " + ((heapUsage.getMax() - heapUsage.getUsed()) * 100 / heapUsage.getMax()).toFixed(2)
);
heapUsage = null;
});
<!DOCTYPE html>
<html lang="en">
<head>
<meta charset="utf-8">
<title></title>
</head>
<body>
<p>nothing to see here. open up the console!</p>
<!-- sockjs is required for vert.x's EventBus -->
<script type="text/javascript" src="http://cdn.sockjs.org/sockjs-0.2.1.min.js"></script>
<!-- vert.x support -->
<script type="text/javascript" src="vertxbus.js"></script>
<script type="text/javascript">
// <!--
window.onload = function() {
var eb = new vertx.EventBus(
window.location.protocol + '//' +
window.location.hostname + ':' +
window.location.port + '/eventbus',
{
"debug": true,
"protocols_whitelist": [
// "websocket"
// , "xdr-streaming"
// , "xhr-streaming"
// , "iframe-eventsource"
, "iframe-htmlfile"
// , "xdr-polling"
// , "xhr-polling"
// , "iframe-xhr-polling"
// , "jsonp-polling"
]
}
);
// when the EventBus opens it'll invoke the callback, which will
// tell async to perform the next step
eb.onopen = function() {
eb.registerHandler("message", function(msg) {
// console.log(JSON.stringify(msg));
});
};
eb.onclose = function() {
console.log("closed");
eb = null;
};
};
// -->
</script>
</body>
</html>
This file has been truncated, but you can view the full file.
View raw

(Sorry about that, but we can’t show files that are this big right now.)

View raw

(Sorry about that, but we can’t show files that are this big right now.)

View raw

(Sorry about that, but we can’t show files that are this big right now.)

View raw

(Sorry about that, but we can’t show files that are this big right now.)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment