对 Node.js 日志系统进行基准测试——我是否遗漏了这方面的一些信息？

Question

我昨天意识到 Node.js 的大多数日志库似乎都使用阻塞/同步调用。日志记录通常是一种 I/O 操作，对于 Node.js，我们应该尽可能使用非阻塞/异步 I/O。

console.log (process.stdout.write) 从 Node.js 0.6 开始就是同步操作，TMK

我想到，对于执行大量日志记录语句的服务器，为这些语句使用阻塞 I/O 可能会造成很大的性能损失。

我使用 Redis、fs、Bunyan 和 Winston 运行“记录”语句，并在 Macbook Pro 上得到这些结果：

redis：16ms

fs-write-stream: 90ms

班扬：414 毫秒

温斯顿：491 毫秒

因此，似乎仅使用 Redis 客户端通过网络 I/O 发送消息是从 Node.js 事件循环中获取数据的最快方式。

这里是测试：

    // fs
    var fs = require('fs');

    // redis
    var redis = require('redis');
    var client = redis.createClient();  //connect to local redis db

    // bunyan
    var bunyan = require('bunyan');

    var bunyanLogger = bunyan.createLogger({
        name: 'benchmark',
        streams: [
            {
                level: 'info',
                path: '../bunyan_log.txt'  // log ERROR and above to this file
            }
        ]
    });

    // winston
    var winston = require('winston');

    var winstonLogger = new (winston.Logger)({
        transports: [
            new (winston.transports.File)({ filename: '../winston_log.txt' })
        ]
    });


    ////////////////////////////////////////////////////////////////////////////

    console.time('redis-time');

    for (var i = 0; i < 12000; i++) {

        client.set('key' + i, 'value' + i + 'aegeggaiojigfeijoagreoiraegioagrijogerawijogerwijogerijoegwoijegwijoegwjio');

    }

    console.timeEnd('redis-time');

    ////////////////////////////////////////////////////////////////////


    console.time('fs-write-stream-time');

    var wstream = fs.createWriteStream('../fs_log.txt');

    for (var i = 0; i < 12000; i++) {

        wstream.write('key' + i + 'value' + i + 'aegeggaiojigfeijoagreoiraegioagrijogerawijogerwijogerijoegwoijegwijoegwjio' + '\n');

    }

    wstream.end();

    console.timeEnd('fs-write-stream-time');


    ///////////////////////////////////////////////////////////////


    console.time('bunyan-time');

    for (var i = 0; i < 12000; i++) {

        bunyanLogger.info('bunyan' + i);

    }

    console.timeEnd('bunyan-time');


    /////////////////////////////////////////////////////////////


    console.time('winston-time');

    for (var i = 0; i < 12000; i++) {

        winstonLogger.info('bunyan' + i);

    }

    console.timeEnd('winston-time');


////////////////////////////////////////////////////////////////

我是在做某事还是我有什么问题？

理想情况下，对于 Node.js 服务器，您应该使用 Redis 将日志记录请求发送到某处的日志记录服务器，该服务器将处理一个队列。

Answer 1

我刚刚意识到我在基准测试中犯了一个错误 - 我需要将 Redis 调用包装在一个 on('ready') 回调中，如下所示：

client.on('ready',function(){

    console.time('redis-time');

    for (var i = 0; i < 12000; i++) {

        client.set('key' + i, 'value' + i + 'aegeggaiojigfeijoagreoiraegioagrijogerawijogerwijogerijoegwoijegwijoegwjio');

    }

    console.timeEnd('redis-time');

});

进行该更改后，Redis 实际上比 fs.createWriteStream 慢得多，但仍然是 Bunyan 和 Winston 的两倍，可能是因为它没有在输入上调用 JSON.stringify。

最重要的是 fs.createWriteStream 比 Bunyan 或 Winston 快得多……但我不确定它对于非常小的 I/O 操作是否那么重要。