node中间层日志方案选型

本文作者：黄伟

背景

node作为现在大前端团队中的利器，用它来做的事情非常多，目前比较多的就是用来作为前后端的中间层，那中间层我们通常具备很多能力，其中我们作为server使用，链接后端和前端，转发、聚合API等等相关操作，其实还有很多操作性，但这里不是重点，重点是作为server，那我们势必要有记录服务端的状态和行为，那状态我们通常称作监控，行为称作为日志

那日志部分到底怎么写？自己写还是第三方库？效率谁高？都支持什么特性？等等一系列问题都是我们需要衡量的指标

使用fs+stream来写日志，而且必须是同步写（对日志文件而言）
如果自己没把握或人力写，那就用第三方，毕竟第三方经过了很多项目的检验
至于效率谁高（下面会证明），这个需要介绍几个库 log4js、winston、bunyan，比较知名就这三个，还有另外一个pino，不过这个和bunyan很像。
支持特性方面，都支持文件和http，都有不同程度的自定义功能

框架对比

log4js

先说log4js，为什么先说log4js，因为笔者之前写过Java，Java中有一个叫log4j的日志库，所以觉得很亲切（）。

对于log4js本身的介绍，请大家查看官网

log4js支持多种格式（自定义）、压缩、编码、保留日志、日志级别。

本文基于自定义layout进行测试

import log4js from 'log4js'

// 其他配置省略，比如添加appender、filename、categorie等

// 这里我们写入固定的字符串
const resultLog = {a: `1234567890ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz`}

log4js.addLayout('json', config => event => JSON.stringify(resultLog))

上面自定义json名称的layout进行测试，我们需要写入json的字符串，方便我们做日志解析。

const Koa = require('koa')
const port = 3000
const addr = '0.0.0.0'
var log4js = require('log4js');

const resultLog = { a: `1234567890ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz` } // 62 char
const app = new Koa()

log4js.addLayout('json', config => event => JSON.stringify(event.data[0]))
log4js.configure({
  appenders: {
    'testapd': {
      filename: './log/test.log',
      type: 'dateFile',
      layout: { type: 'json' }, // 使用自定义layout格式
      pattern: '-yyyy-MM-dd',
      alwaysIncludePattern: false,
      maxSize: 10485760, // 10M
    }
  },
  categories: {
    default: { appenders: ['testapd'], level: 'info' }
  }
});
const logger = log4js.getLogger()

app.use(async (ctx, next) => {
  ctx.body = 'log4js test'
  logger.info(resultLog)
  next()
})

app.listen(port, addr, () => {
  console.log(`To see your app, visit http://${addr}:${port}\n`)
  console.log(`To shut down, press <CTRL> + C at any time.\n`)
})

从上面测试可以看出，我们qps平均值能在 14500。

winston

winston，作为第二个介绍的，因为他是和log4js最相似的（功能），下面我们会给出结论。

const winston_logger = createLogger({
  level: 'info',
  format: format.combine(format.json()),
  transports: [
    //
    // - Write to all logs with level `info` and below to `combined.log` 
    // - Write all logs error (and below) to `error.log`.
    //
    new transports.File({
      filename: 'error.log',
      level: 'error'
    }),
    new transports.File({
      filename: 'combined.log'
    })
  ]
});

app.use(async (ctx, next) => {
  ctx.body = 'log4js test'
  // logger.info(resultLog)
  winston_logger.log({
    level: 'info',
    message: JSON.stringify(resultLog)
  });
  next()
})

上面是大致的测试代码，也就是简单创建一个logger对象

从上面的测试来看，qps基本和log4js不相上下，平均值在14300，120s内和log4js``120内处理请求少了22k

bunyan

对于这个库，在使用方面和winston比较像，功能方面相比较上面两个就差多了，主要是在自定义格式方面差很多，甚至于不能自定义格式，但他可以很简单粗暴。

测试结果显示，qps能到12500左右，120s内处理请求大概在1500k左右

pino

还有最后一个pino，当一眼的看到官网的时候

Very low overhead Node.js logger, inspired by Bunyan.

In many cases, Pino is over 5x faster than alternatives.

首先这个库的灵感来自于bunyan，而且声称在多数情况下pino比bunyan快5倍，这我那忍得了，肯定得试一试。

结果在高并发下和bunyan差不了多少

注意：我们上面压测的四个库，只是简单的写文件，而且对于实际场景中还是有一些差别的，比如我们可能需要使用http、多个logger、多核cluster模式下，都是有一些影响的，笔者在写node中间层过程中，使用cluster实现多核（与pm的方式类似），而不是多实例。这里写日志也是需要通过主进程写，通过process监听/接收事件来进行日志数据通信。所以这里也是有性能消耗的，还有其他自有特定逻辑，所以这些运行中的中间件都是会对性能有或多或少的消耗。

压测方式：压力机、被压机都在笔者mac电脑上，电脑配置：内存8GB、2.9GHz i5、128GB disk，使用autocannon压测工具

这里简单压测结果为log4js>winston>pino>bunyan

经过最后的实际框架中测试，框架中实现了cluster多核模式，还有其他逻辑的中间件（如登录），性能依次为log4js>winston>bunyan>pino

最终综合四个框架的star、最近发布时间、下载次数等等维度，最终选择log4js比较稳妥。

关于日志的优化方案，会在后续「node中间层有哪些可做的优化？」中讲到