Memory usage of fs.write vs WriteStream

July 17, 2011

We recently ran into a problem where our node.js process was running out of memory very rapidly. We tracked it down to a couple of debug log lines that, when removed, reduced the memory problem considerably. The problem was that because all i/o is asynchronous in node.js we were generating log messages faster than they could be written to the file system. They were getting buffered, piling up until the process ran out of memory.

As an attempt to ameliorate this I wanted to see if changing log4js‘s fileAppender from using fs.write to using a WriteStream would make any difference. My test program looked like this:

var log4js = require('./lib/log4js')
, logger
, usage
, i;

        appenders: [
                category: "memory-test"
              , type: "file"
              , filename: "memory-test.log"
                type: "console"
              , category: "memory-usage"
                type: "file"
              , filename: "memory-usage.log"
              , category: "memory-usage"
              , layout: {
                  type: "messagePassThrough"
logger = log4js.getLogger("memory-test");
usage = log4js.getLogger("memory-usage");

for (i=0; i < 1000000; i++) {
    if ( (i % 5000) === 0) {"%d %d", i, process.memoryUsage().rss);
    }"Doing something.");

It writes one million log lines to a file, and every 5000 it records the memory usage to another file for processing later. I ran two versions of log4js, one with the original fileAppender (using fs.write) and one using a rewritten fileAppender that used a WriteStream. The graph below shows the results.

graph of memory usage by fs.write and writestream

It is pretty obvious that WriteStream is the better implementation for this application, and the unstable branch of log4js now contains the rewritten fileAppender. I hope to release this within the next couple of days.


Leave a Reply

Fill in your details below or click an icon to log in: Logo

You are commenting using your account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

%d bloggers like this: