NodeJS winston 记录大量写入陷入困境

NodeJS winston logging large number of writes bogs down

节点 JS - 12.7 温斯顿 - 1.0.1

我正在努力尝试生成代表许多 "devices" 的 "fake" 日志文件。基本上我将使用这些数据在 Kibana 中进行测试和可视化。

我将我的 Winston 设置为这样登录到文件:

var winston = require('winston');

var logger = new (winston.Logger)({
transports: [
    new (winston.transports.File)({
        filename: 'logs/dsm.log'
    })
  ]
});

所以我有一个设备数组,它只是一个 12 字节散列列表,例如:AB4576D4C6AC,等等

我正在遍历设备数组并像这样组装我的 "fake" 日志条目:

for (var i = 0; i < devices.length; i++) {
    var timeStmp = startDateTime.clone().add((i * config.dsmIntervalMinutes), "m");
    dsm = {
        deviceId: devices[i].deviceId,
        msg: "some log entry text",
        timeStmp: timeStmp
    };
    logger.info(dsm);
}

如您所见,在循环中创建每个 DSM 后,我将消息作为 info 记录到 Winston。

所以这似乎工作正常,除非我有大量设备。我想获得最多 1m 左右的设备。我目前正在努力做100k。

我看到的是节点进程没有将日志写入日志文件。它似乎将它们全部存储在内存中(如使用 top 所见),一旦达到 10k 左右,它就会缓慢地爬行并最终停止前进。永远不会写入日志文件。

所以我想知道是否有办法做到这一点?我可以以某种方式强制 node/winston 每隔一段时间停止并写入磁盘吗?喜欢刷新缓存?我在 winston 中看不到这方面的选项。

如有任何帮助,我们将不胜感激!

这是因为您正在使用 for 循环。 Node.js(JavaScript 层)是单线程的。您的 for 循环阻止进程实际进入写入阶段。

将其更改为类似这样的内容,这样您就可以遍历设备而不会阻碍进程:

function doLog (d, cb) {
    var timeStmp = startDateTime.clone().add((i * config.dsmIntervalMinutes), "m");
    dsm = {
        deviceId: d.deviceId,
        msg: "some log entry text",
        timeStmp: timeStmp
    };
    // Callback is fired once the write is complete
    logger.info(dsm, cb);
}

async.eachSeries(devices, doLog, function () {
  log.info('Finished!')
});

异步模块基本上 运行 每个操作一个接一个地执行 (eachSeries) 并在内部使用 setImmediate 延迟每个调用以允许 I/O 在开始下一个设备 doLog 调用之前。您还可以查看 async.parallelLimit 同时执行一些操作以获得更好的性能。

这里的问题并不完全在于循环是同步的,而是当它刷新到磁盘时您需要停止写入底层 fs.createWriteStream 实例。通过不等待,您会继续填满内部缓冲区,这就是您的内存使用量无限制增加的原因。

考虑到这一点,代码示例变为:

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

var stream = fs.createWriteStream('logs/dsm.log');
var file = new (winston.transports.File)({ stream: stream });
var logger = new (winston.Logger)({ transports: [file] });

//
// We'll store this for our position in all devices across
// `drain` events from the stream.
//
var curr = 0;

//
// function isFlushing()
// Returns a value if the file is flushing
//
function isFlushing() {
  var state = stream._writeableState;
  return state.length < state.highWaterMark;
}

//
// function logDevice()
// Logs a single device and returns a value
// indicating if the underlying filestream is full.
//
function logDevice(d) {
  var timeStmp = startDateTime.clone().add((i * config.dsmIntervalMinutes), 'm');  
  logger.info({
    deviceId: d.deviceId,
    msg: 'some log entry text',
    timeStmp: timeStmp
  });

  return isFlushing();
}

(function logAllDevices() {
  for (; curr < devices.length; curr++) {
    if (!logDevice(devices[curr])) {
      stream.once('drain', logAllDevices);
      break;
    }
  }
})();