Stampy

Dev Blog

Why We Patched node.js

At a company that relies on open source software, every day is an adventure. This week: how a memory fragmentation issue in node.js tempted me into the wilds of the V8 JavaScript Engine and C++.

As our fearless leader and CTO Aaron Quint mentioned in our previous blog post, we are completely addicted to metrics. One of the cornerstones of this new mindset is statsd, a node.js server for aggregating and sending information to a Graphite server. If you don’t know what statsd or Graphite are, read the above blog post. If you don’t know what node.js or V8 are, you should check them both out as they are very interesting projects!

As a consequence of a big push to automate our software infrastructure, we have tried to tie as many of our dependencies as possible to pre-compiled packages for our current deployment platform of choice, CentOS. The only available packages for our version of CentOS were for the 0.6.x stable branch of node. Even though we were running the 0.4.x branch (compiled by hand) up until that point, we decided to give it a shot.

After our upgrade, we noticed that the node statsd process on our isolated statsd box would balloon in memory usage, measured by resident set size, from a manageable number in the tens of megabytes to upwards of a gigabyte. Eventually, the process would consume so much memory that it would get shut down by the OS, and for the time that the process was down, we would miss out on our stats getting transmitted properly to Graphite. Besides making us aware that we should try to find a way to improve the availability of our statsd, we were very suspicious.

At first we assumed that we had accidentally created a memory leak in the statsd process, because we are actively maintaining our own fork at this point and we couldn’t find many other mentions of similar issues. After some serious head scratching and investigation, Aaron tracked it down to node itself, by stripping away the extraneous bits and observing how node handles sending and receiving UDP packets.

Here’s the client test code, commented for your convenience:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
// Require the necessary node modules
var util = require('util'),
    dgram  = require('dgram');

// Set up the UDP client, create a dummy message, and zero out a counter
var client = dgram.createSocket("udp4");
var message = new Buffer("stats.counters.test|1");
var sent = 0;

// Define a send function that will be executed in a timed loop.
function send() {
  process.nextTick(function() {
    client.send(message, 0, message.length, 8125, "localhost", function() {
      sent++;
    });
    send();
  });
};
send();

// Set up an interval timer that will periodically send the number of sent
// packets to the console
setInterval(function() {
  console.log('Sent ', sent);
}, 1000);

// Output the client start to the console
console.log('Started sending to', port);

And the server, equally simple but also commented:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
// Require the necessary node modules
var util = require('util'),
    dgram  = require('dgram');

// Set up the server and a counter for the number of received packets, and
// define a callback function to be executed when a packet is received.
var packets = 0;
var receive = function(msg, rinfo) {
  packets++;
};
var server = dgram.createSocket('udp4', receive);
server.bind(8125);
console.log("Listening for UDP packets on", port);

// Print out the process memory usage, the number of packets received,
// and force a GC run every 2 seconds
setInterval(function() {
  console.log("\n*** RSS: ", process.memoryUsage().rss / 1024 / 1024, "mb")
  console.log("packets:", packets);
  // A hook to force gc through V8's --expose_gc option
  if (gc) gc(true);
}, 2000);

This simple client/server set up lets us observe what happens when we throw a bunch of UDP packets at a node server, and do nothing else with them. When we ran the above client and server code against the 0.6.x stable version of node, we got the following output (note that this is a sample from the “middle” of the log, you can note by the number of packets sent):

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
*** RSS:  64.64453125 mb
packets: 95354

*** RSS:  93.68359375 mb
packets: 113610

*** RSS:  56.98046875 mb
packets: 114268

*** RSS:  55.50390625 mb
packets: 114278

*** RSS:  74.39453125 mb
packets: 131329

*** RSS:  60.00390625 mb
packets: 131329

*** RSS:  58.69140625 mb
packets: 132717

*** RSS:  100.3359375 mb
packets: 147266

This simple UDP client/server implementation leaked memory profusely. Even more damning is the fact that after the client was killed and packets stopped being transmitted to the server, the RSS did not drop significantly, even after many cycles. After we had proof of some memory weirdness in the node process and verified that this issue didn’t exist in the 0.4.x branch of node, we did the next natural thing: opened an issue on GitHub.

Thanks to the transparency and activeness of node’s development process, we were able to get the direct attention of the maintainers to explain our issues. It turns out that the 0.6.x branches introduced major changes in node’s entire networking layer via the adoption of a new library called libuv. Ryan Dahl described libuv on the node.js blog:

libuv’s purpose is to abstract platform-dependent code in Node into one place where it can be tested for correctness and performance before bindings to V8 are added. Since Node is totally non-blocking, libuv turns out to be a rather useful library itself: a BSD-licensed, minimal, high-performance, cross-platform networking library.

The 0.5.x branch of node.js had given the node community the opportunity to test these changes with an unstable release, but since UDP isn’t used as commonly as TCP by node.js users, its datagram functionality was sort of lost in the shuffle. More “important” and oft-used protocols were covered first, and first class memory management was one of the features that TCP got that datagrams didn’t.

It turned out that the node core team knew that datagrams needed some love, and they were happy to have some help. The TCP strategy for memory management made it much easier to avoid memory fragmentation because it used slab allocation. For an excellent, illustrative explanlation of memory fragmentation, see this Stackoverflow answer. Slab allocation solves fragmentation issues by allocating larger chunks of memory at once, to be used only by objects of the same type and size, alleviating memory gaps of different sizes being created by deallocation.

Because we had committed to using node in production, and we try as hard as possible to be good open source citizens, I decided to challenge myself to make this change. Mind you I haven’t touched C++ in years, I have zero familiarity with the V8 C++ interface, and I’m not an avid user of node.js, but I still really wanted to do it. If you’re wondering why, I was motivated by my desire to give back to the open source community, and by my dedication to keep Paperless Post’s operational overhead to a minimum. I was presented with a clear path, and was ready for the adventure. Plus, we needed our stats!

I started to dig in, read some materials online, and got a good sense at how the interactions worked between V8, libuv, and node.js. Because the Internet is awesome, I was able to continue the conversation from GitHub on Twitter and then on IRC with a few of the node and libuv maintainers. They patiently explained some of the crucial pieces I needed to know, and after some major head-banging, a lot of rubber duck programming, and some heavy testing, my patch was ready.

After all of that, it turns out that:

1
1 files changed, 59 insertions(+), 9 deletions(-)

could result in a change from the above log to:

1
2
3
4
5
6
7
8
*** RSS:  14.59375 mb
packets: 4074145

*** RSS:  17.60546875 mb
packets: 4081558

*** RSS:  17.64453125 mb
packets: 4081568

If you’re interested in the specifics of the patch, you can see them here along with the pull request. The patch isn’t that exciting - I simply ported the slab allocation code from libuv’s stream_wrap.cc file which handles streaming networking connections to the udp_wrap.cc file which specifically pertains to datagrams. I’m happy to report that the next stable version of node, v0.6.8 (changelog here) shipped with my patch, and that the memory usage of the node process under heavy datagram load shows a stable memory profile.

There have been many times where I have not bothered to get involved in a project, and instead settled for suboptimal performance or degraded functionality in a software library. I wanted to share this example of when I decided to step up, and I hope that reading this story reminds people like me who have made a career out of using open source software that it’s possible to get involved in projects of any size – you just need to be persistent, patient, and highly tolerant to pain.

Want to be patching, shipping, and learning every day? We’re hiring in NYC and SF.

Comments