Сравнительный анализ систем ведения журналов Node.js — мне не хватает информации об этом?

Вчера я понял, что большинство библиотек ведения журналов для Node.js, похоже, используют блокирующие/синхронные вызовы. Ведение журнала обычно является операцией ввода-вывода, и с Node.js мы должны использовать неблокирующий/асинхронный ввод-вывод везде, где это возможно.

console.log (process.stdout.write) является синхронной операцией, начиная с Node.js 0.6, TMK

Мне пришло в голову, что для серверов, которые выполняют множество операторов ведения журнала, использование блокирующего ввода-вывода для них может привести к значительному снижению производительности.

Я запустил операторы «логирования» с помощью Redis, fs, Bunyan и Winston и получил следующие результаты на Macbook Pro:

редис: 16 мс

fs-запись-поток: 90 мс

буньян: 414 мс

Уинстон: 491 мс

поэтому кажется, что просто использование клиента Redis для отправки сообщения через сетевой ввод-вывод — это самый быстрый способ получить данные из цикла событий 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 для отправки запросов ведения журнала куда-то на сервер ведения журнала, который будет обрабатывать очередь.


person Alexander Mills    schedule 03.11.2015    source источник
comment
Я также запустил его для системного журнала в /dev/null и получил время системного журнала: 54 мс, когда я зарегистрировал bunyan в /dev/null и winston в /dev/null, я получил те же результаты.   -  person Alexander Mills    schedule 04.11.2015


Ответы (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... но я не уверен, что это так важно для очень небольших операций ввода-вывода.

person Alexander Mills    schedule 04.11.2015
comment
Это звучит странно. Попробуйте запустить весь набор тестов несколько раз подряд, а затем вычислить медианы для каждого регистратора. - person matus; 05.02.2016
comment
попробуйте, скопируйте код с новым обработчиком redis on ready вместо оригинала, и вы должны увидеть те же результаты. - person Alexander Mills; 05.02.2016
comment
Не думаете ли вы, что тип используемых вами потоков также играет важную роль, поскольку файловый ввод-вывод может быть причиной более высоких накладных расходов, почему bunyan и winston занимают больше времени. - person JohnTheBeloved; 24.07.2017
comment
какие существуют виды потоков? все они доступны для записи, но помимо этого, не уверен, какая разница - person Alexander Mills; 25.07.2017
comment
моя гипотеза заключалась в том, что Bunyan и Winston медленнее, потому что они вызывают JSON.stringify - person Alexander Mills; 25.07.2017
comment
Я имею в виду, что время, необходимое для записи в файловый ввод-вывод, может больше отличаться от времени, затрачиваемого на ввод-вывод StdOut или сетевой ввод-вывод. - person JohnTheBeloved; 01.08.2017