testLoggerSpeed.js

/*jslint node: true, maxlen: 100 */
'use strict';

var fs = require('fs'),
    log4js = require('log4js'),
    async = require('async'),

    NB_ITERATION = 150000;

function fileStreamSpeedTest(callback) {
    console.log('---------- fileStreamSpeedTest ----------');

    var filename = 'fstream.log',
        counter = NB_ITERATION;

    fs.unlink(filename, function () {
        var d1,
            stream,
            toWrite;

        stream = fs.createWriteStream(
            filename,
            { encoding: 'utf8', mode: 420, flags: 'a' }
        );
        stream.on('close', function () {
            var diff3 = Date.now() - d1;
            console.log('onClose: Time elapsed in writing file: ' + diff3 + 'ms');

            // Now we are really done.
            callback(null);
        });

        stream.on('drain', function () {
            while (counter) {
                var toWrite = '[' + new Date() + '] ' +
                    '[INFO] server - Message[' + counter + ']\n';
                counter -= 1;
                if (!stream.write(toWrite)) {
                    break;
                }
            }
            if (!counter) {
                stream.end();
            }
        });

        d1 = Date.now();
        console.log('Starting: ' + (new Date().toISOString()));
        while (counter) {
            toWrite = '[' + new Date().toISOString() + '] ' +
                '[INFO] server - Message[' + counter + ']\n';
            counter -= 1;
            if (!stream.write(toWrite)) {
                break;
            }
        }
    });
}


function loggerSpeedTest(callback) {
    console.log('---------- loggerSpeedTest ----------');

    var filename = 'log4js.log',
        counter = NB_ITERATION;

    fs.unlink(filename, function () {
        log4js.configure({
            appenders: [
                {
                    type: 'console',
                    category: ["console"]
                },
                {
                    type: 'dateFile',
                    filename: filename,
                    pattern: "-yyyy-MM-dd",
                    category: 'server'
                }
            ]
        });

        var d1,
            diff,
            logger = log4js.getLogger('server'),
            watchLastModif,
            intervalLastModif,
            timer;

        console.log('Starting: ' + (new Date().toISOString()));

        d1 = Date.now();
        while (counter) {
            logger.info('Message[' + counter + ']');
            counter -= 1;
        }
        diff = Date.now() - d1;
        console.log('Time elapsed calling logger.info(): ' + diff + 'ms');

        fs.watchFile(filename, { interval: 5000 }, function (curr, prev) {
            prev = prev || null;
            watchLastModif = curr.mtime;
        });

        timer = setInterval(function () {
            if (watchLastModif) {
                if (watchLastModif === intervalLastModif) {
                    clearInterval(timer);

                    diff = watchLastModif.getTime() - d1;
                    console.log('Time elapsed to write the file: ' + diff + 'ms');

                    callback();
                } else {
                    console.log('File is still moving: ' + watchLastModif);
                }
                intervalLastModif = watchLastModif;
            }
        }, 5000);
    });
}

async.series([
    fileStreamSpeedTest,
    loggerSpeedTest
], function () {
    console.log('All done !');
});