Skip to content
On this page

基础篇-自定义日志


前言

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

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

开启默认 Logger

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

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

而我们为了框架的性能使用 Fastify 来替换底层框架之后,需要使用下述代码来开启 Fastify 的日志系统:

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

接下来,当我们访问 http://localhost:3000/ ,可以看到控制台已经在正常打印接口请求的日志了:

image.png

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

自定义 Logger

既然自带的日志功能不能满足我们的业务需求,那就需要对默认的日志功能进行拓展。

  1. 安装几个必要的依赖:
    
$ yarn add fast-json-parse // 格式化返回对象
$ yarn add pino-multi-stream // 替换输出流
$ yarn add split2 // 处理文本流
$ yarn add dayjs // 可选,如果自己写时间格式化函数可以不用 
  1. `Fastify` 作为一款专注于性能 `Http` 框架,使用 [pino](https://github.com/pinojs/pino) 作为内置日志工具,下面是自定义日志的参数配置:
    
const split = require('split2')
const stream = split(JSON.parse)

  logger: {
    level: 'info',
    file: '/path/to/file' // 将调用 pino.destination() 
    // stream: stream
  }

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

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

logStream

  1. 新建 `common/logger/logStream.ts` 文件:
    
ts
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}`
  }

}

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

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

在接入自定义日志后,可以看到控住台输出内容变成如下所示:

image.png

对比最开始的默认日志打印格式,现在可以很清晰的从控制台看出日志的类型与内容,方便我们快速定位问题。

fileStream

在接管了控制台输出日志后,我们接着开发日志的落库与轮转功能:

新建 common/logger/fileStream.ts 文件:

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)
  }
}

fileStream.ts 的主要功能是存储日志文件以及日志轮转。文件这块处理的内容比较多,但是从代码角度来看并不复杂,大家可以根据代码注释看完以及对应的功能来理解。

当接入 fileStream 之后,可以看到本地根路径的 logs 文件夹下有对应的日志文件生成:

image.png

自定义插件参考 fastify-logger 这个项目,原项目是 JS 的版本,在 NestJS 中使用有些麻烦,索性拉下来改成 TS 版本了,另外稍微修改了一些内容适配项目。

写在最后

本章是针对自定义日志的处理,如果项目并不是非常复杂的话,已经足够满足日常开发需求。

但实际上一个企业级的项目在日志处理方面可能会更加复杂,特别是使用 k8s 容器编排部署之后,日志会零散的落库在各个 pod 中,排查问题、恢复数据等操作需要聚合多个 pod 的日志才行,这就需要借助其他的工具例如 elk 等来处理日志.这块内容衍生性比较大,如果有需求的话,后期可以再拿出来单独讨论一下。

如果你有什么疑问,欢迎在评论区提出或者加群沟通。 👏