NestJS学习08 - 自定义日志

前言

在所有后端的服务中，日志是必不可少的一个环节。毕竟日常中我们不可能随时盯着控制台，问题的出现也会有随机性，不可预见性。一旦出现问题，要追踪错误以及解决的话。需要知道错误发生的原因、时间等细节信息。

在之前的需求分析中，在网关基础代理的服务中。网关作为所有业务流量的入口也有统一的日志落库的需求。所以本章将实现一个自定义日志的插件。

开启默认的Logger

NestJS 框架自带了 log 插件，如果只是普通使用的话，直接开启日志功能即可：

const app = await NestFactory.create(ApplicationModule, { logger: true });

如果你使用了Fastify来替换底层架构，需要使用下述代码来开启fastify的日志系统。

const app = await NestFactory.create<NestFastifyApplication>(AppModule, new FastifyAdapter({
    logger: true
  }));

接下来，我们访问 http://localhost:3000/ 就可以在控制台看见我们的日志了。

虽然自带的日志功能开启之后，控制台能够正常的打印日志。但是Fastify默认日志的输出格式并没有满足业务需求。首先无法快速区分日志类型。打印日志能够参考的价值不大。另外logger并没有本地落库。后续查找也很麻烦，对于一个实战工程来说。快速定位日志问题以及有本地存储、日志轮换等功能还是必要的。

自定义Logger

既然自带的日志无法满足我们的业务需求，那就需要对日志的功能进行扩展。

1. 安装必要的依赖

$ cnpm install fast-json-parse // 格式化返回对象
$ cnpm install pino-multi-stream // 替换输出流
$ cnpm install split2 // 处理文本流
$ cnpm install dayjs // 可选，如果自己写时间格式化函数可以不用 

2. fastify作为一款专注于性能HTTP框架，使用pino作为内置日志工具。下面是自定义日志的参数配置。

const split = require('split2')
const stream = split(JSON.parse)

logger: {
    level: 'info',
    file: '/path/to/file'
}

开启file配置的话，日志会自动存储在本地。如果开启Stream配置的话，就需要自己自定义修改配置，这两者是互斥的，只能配置一个。

每个团队对日志的需求也并不相同。如果想对日志做更多的定制化的内容。可以选择开启Stream配置。自己开发需要的日志功能。

const chalk = require('chalk')
const dayjs = require('dayjs')
const split = require('split2')
const JSONparse = require('fast-json-parse')

const levels = {
  [60]: 'Fatal',
  [50]: 'Error',
  [40]: 'Warn',
  [30]: 'Info',
  [20]: 'Debug',
  [10]: 'Trace'
};

const colors = {
  [60]: 'magenta',
  [50]: 'red',
  [40]: 'yellow',
  [30]: 'blue',
  [20]: 'white',
  [10]: 'white'
}

interface ILogStream {
  format?: () => void
}

export class LogStream {
  public trans;
  private customFormat;

  constructor(opt?: ILogStream) {
    this.trans = split((data) => {
      this.log(data);
    });

    if (opt?.format && typeof opt.format === 'function') {
      this.customFormat = opt.format
    }
  }

  log(data) {
    data = this.jsonParse(data)
    const level = data.level
    data = this.format(data)
    console.log(chalk[colors[level]](data))
  }

  jsonParse(data) {
    return JSONparse(data).value;
  }

  format(data) {

    if (this.customFormat) {
      return this.customFormat(data)
    }

    const Level = levels[data.level];
    const DateTime = dayjs(data.time).format('YYYY-MM-DD HH:mm:ss.SSS A');
    const logId = data.reqId || '_logId_';

    let reqInfo = '[-]';

    if (data.req) {
      reqInfo = `[${data.req.remoteAddress || ""} - ${data.req.method} - ${data.req.url}]`
    }

    if (data.res) {
      reqInfo = JSON.stringify(data.res)
    }

    // 过滤 swagger 日志
    if (data?.req?.url && data?.req?.url.indexOf('/api/doc') !== -1) {
      return null
    }
    return `${Level} | ${DateTime} | ${logId} | ${reqInfo} | ${data.stack || data.msg}`
  }

}

level以及Colors分别是定义日志类型与控制台输出颜色。可以根据自己的习惯或者团队的规则进行配置。format是格式化Fastify的日志输出。也可以根据自己的习惯格式化日志格式。log则是将日志输出到控制台。

logStream.ts 整体比较简单易懂，主要的功能就是格式化日志以及打印日志。

import { dirname } from 'path'
import { createWriteStream, stat, rename } from 'fs'

const assert = require("assert")
const mkdirp = require("mkdirp")

import { LogStream } from "./logStream"

const defaultOptions = {
  maxBufferLength: 4096, // 日志写入缓存队列最大长度
  flushInterval: 1000, // flush间隔
  logRotator: {
    byHour: true,
    byDay: false,
    hourDelimiter: '_'
  }
}

const onError = (err) => {
  console.error(
    '%s ERROR %s [chair-logger:buffer_write_stream] %s: %s\n%s',
    new Date().toString(),
    process.pid,
    err.name,
    err.message,
    err.stack
  )
}

const fileExists = async (srcPath) => {
  return new Promise((resolve, reject) => {
    // 自运行返回Promise
    stat(srcPath, (err, stats) => {
      if (!err && stats.isFile()) {
        resolve(true);
      } else {
        resolve(false);
      }
    })
  })
}

const fileRename = async (oldPath, newPath) => {
  return new Promise((resolve, reject) => {
    rename(oldPath, newPath, (e) => {
      resolve(e ? false : true);
    })
  })
}

export class FileStream extends LogStream {
  private options: any = {};
  private _stream = null;
  private _timer = null;
  private _bufSize = 0;
  private _buf = [];
  private lastPlusName = '';
  private _RotateTimer = null;

  constructor(options) {
    super(options)
    assert(options.fileName, 'should pass options.fileName')
    this.options = Object.assign({}, defaultOptions, options)
    this._stream = null
    this._timer = null
    this._bufSize = 0
    this._buf = []
    this.lastPlusName = this._getPlusName();
    this.reload()
    this._RotateTimer = this._createRotateInterval();
  }

  log(data) {
    data = this.format(this.jsonParse(data))
    if (data) this._write(data + '\n')
  }

  /**
   * 重新载入日志文件
   */
  reload() {
    // 关闭原来的 stream
    this.close()
    // 新创建一个 stream
    this._stream = this._createStream()
    this._timer = this._createInterval()
  }

  reloadStream() {
    this._closeStream()
    this._stream = this._createStream()
  }
  /**
   * 关闭 stream
   */
  close() {
    this._closeInterval() // 关闭定时器
    if (this._buf && this._buf.length > 0) {
      // 写入剩余内容
      this.flush()
    }
    this._closeStream() //关闭流
  }

  /**
   * @deprecated
   */
  end() {
    console.log('transport.end() is deprecated, use transport.close()')
    this.close()
  }

  /**
   * 覆盖父类，写入内存
   * @param {Buffer} buf - 日志内容
   * @private
   */
  _write(buf) {
    this._bufSize += buf.length
    this._buf.push(buf)
    if (this._buf.length > this.options.maxBufferLength) {
      this.flush()
    }
  }

  /**
   * 创建一个 stream
   * @return {Stream} 返回一个 writeStream
   * @private
   */
  _createStream() {
    mkdirp.sync(dirname(this.options.fileName))
    const stream = createWriteStream(this.options.fileName, { flags: 'a' })
    stream.on('error', onError)
    return stream
  }

  /**
   * 关闭 stream
   * @private
   */
  _closeStream() {
    if (this._stream) {
      this._stream.end()
      this._stream.removeListener('error', onError)
      this._stream = null
    }
  }

  /**
   * 将内存中的字符写入文件中
   */
  flush() {
    if (this._buf.length > 0) {
      this._stream.write(this._buf.join(''))
      this._buf = []
      this._bufSize = 0
    }
  }

  /**
   * 创建定时器，一定时间内写入文件
   * @return {Interval} 定时器
   * @private
   */
  _createInterval() {
    return setInterval(() => {
      this.flush()
    }, this.options.flushInterval)
  }

  /**
   * 关闭定时器
   * @private
   */
  _closeInterval() {
    if (this._timer) {
      clearInterval(this._timer)
      this._timer = null
    }
  }

  /**
   * 分割定时器
   * @private
   */
  _createRotateInterval() {
    return setInterval(() => {
      this._checkRotate()
    }, 1000)
  }

  /**
   * 检测日志分割
   */
  _checkRotate() {
    let flag = false

    const plusName = this._getPlusName()
    if (plusName === this.lastPlusName) {
      return
    }
    this.lastPlusName = plusName;
    this.renameOrDelete(this.options.fileName, this.options.fileName + plusName)
      .then(() => {
        this.reloadStream()
      })
      .catch(e => {
        console.log(e)
        this.reloadStream()
      })
  }

  _getPlusName() {
    let plusName
    const date = new Date()
    if (this.options.logRotator.byHour) {
      plusName = `${date.getFullYear()}-${date.getMonth() +
        1}-${date.getDate()}${this.options.logRotator.hourDelimiter}${date.getHours()}`
    } else {
      plusName = `${date.getFullYear()}-${date.getMonth() +
        1}-${date.getDate()}`
    }
    return `.${plusName}`;
  }

  /**
   * 重命名文件
   * @param {*} srcPath 
   * @param {*} targetPath 
   */
  async renameOrDelete(srcPath, targetPath) {
    if (srcPath === targetPath) {
      return
    }
    const srcExists = await fileExists(srcPath);
    if (!srcExists) {
      return
    }
    const targetExists = await fileExists(targetPath)

    if (targetExists) {
      console.log(`targetFile ${targetPath} exists!!!`)
      return
    }
    await fileRename(srcPath, targetPath)
  }
}

//index.ts
import { resolve, join } from 'path'

import { fastLogger } from './logger'

let logOpt = {
  console: process.env.NODE_ENV !== 'production', // 是否开启 console.log 
  level: 'info',
  serializers: { // 需要的额外数据
    req: (req) => {
      return {
        method: req.method,
        url: req.url
      }
    },
  },
  fileName: join(process.cwd(), 'logs/fast-gateway.log'), // 文件路径  
  maxBufferLength: 4096, // 日志写入缓存队列最大长度
  flushInterval: 1000, // flush间隔
  logRotator: { // 分割配置
    byHour: true,
    byDay: false,
    hourDelimiter: '_'
  }
}

export const FastifyLogger = fastLogger(logOpt)

//logger.ts

import { join } from 'path'
import { FileStream } from './fileStream';
import { LogStream } from './logStream';

const multiStream = require('pino-multi-stream').multistream;

function asReqValue(req) {
  if (req.raw) {
    req = req.raw;
  }
  let device_id, tt_webid;
  if (req.headers.cookie) {
    device_id = req.headers.cookie.match(/device_id=([^;&^\s]+)/);
    tt_webid = req.headers.cookie.match(/tt_webid=([^;&^\s]+)/);
  }
  device_id && (device_id = device_id[1]);
  tt_webid && (tt_webid = tt_webid[1]);

  return {
    id: req.id,
    method: req.method,
    url: req.url,
    remoteAddress: req.connection ? req.connection.remoteAddress : '',
    remotePort: req.connection ? req.connection.remotePort : '',
    device_id,
    tt_webid
  };
};

const reqIdGenFactory = () => {
  let maxInt = 2147483647
  let nextReqId = 0
  return (req) => {
    return req.headers['X-TT-logId'] || req.headers['x-tt-logId'] || (nextReqId = (nextReqId + 1) & maxInt)
  }
}

export const fastLogger = (opt) => {
  const reOpt = {
    console: !process.env.NODE_ENV || process.env.NODE_ENV === 'development',
    level: 'info',
    fileName: join(process.cwd(), 'logs/fastify.log'),
    genReqId: reqIdGenFactory(),
    serializers: {
      req: asReqValue
    },
    formatOpts: {
      lowres: true
    },
    ...opt
  }

  // 添加落库日志
  const allStreams = [{
    stream: new FileStream(reOpt).trans
  }]

  // 开发环境打印控制台日志
  if (reOpt.console) {
    allStreams.push({
      stream: new LogStream().trans
    })
  }

  reOpt.stream = multiStream(allStreams)

  return reOpt
};

在NestJS中使用自定义日志

  const fastifyInstance = fastify({
  logger: FastifyLogger
})
  const app = await NestFactory.create<NestFastifyApplication>(
    AppModule,
    new FastifyAdapter(fastifyInstance)
  );

效果