links for 2011-09-23

September 24, 2011

links for 2011-09-22

September 23, 2011

links for 2011-09-16

September 17, 2011

links for 2011-08-27

August 28, 2011

links for 2011-07-30

July 31, 2011

links for 2011-07-23

July 24, 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;

log4js.configure(
    {
        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) {
        usage.info("%d %d", i, process.memoryUsage().rss);
    }
    logger.info("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.

Follow

Get every new post delivered to your Inbox.