Node 中如何更好地打日志

本文收录于 GitHub 山月行博客: shfshanyue/blog，内含我在理论工作中碰到的问题、对于业务的思考及在全栈方向上的学习

• 前端工程化系列
• Node 进阶系列

在服务器利用 (后端我的项目) 中，欠缺并结构化的日志不仅能够更好地帮忙定位问题及复现，也可能发现性能问题的端倪，甚至可能帮忙用来解决线上 CPU 及内存爆掉的问题。

本篇文章将解说如何应用 Node 在服务端更好地打日志

• 哪里应该打日志: AccessLog、SQLLog、BusinessLog
• 应该打什么日志: server_name、timestamp 以及相干类型日志
• 用什么去打日志: winston、log4j、bunyan

产生日志后，将在下一章解说日志的收集解决及检索

日志类型

在一个服务器利用中，或作为生产者，或作为消费者，须要与各方数据进行交互。除了最常见的与客户端交互外，还有数据库、缓存、音讯队列、第三方服务。对于重要的数据交互须要打日志记录。

除了外界交互外，本身产生的异样信息、要害业务逻辑及定时工作信息，也须要打日志。

以下简述须要打日志的类型及波及字段

• AccessLog: 这是最常见的日志类型，个别在 nginx 等方向代理中也有日志记录，但在业务零碎中有时须要更具体的日志记录，如 API 耗时，具体的 request body 与 response body
• SQLLog: 对于数据库查问的日志，记录 SQL、波及到的 table、以及执行工夫，从此能够筛选出执行过慢的 SQL，也能够筛选出某条 API 对应的 SQL 条数
• RequestLog: 申请第三方服务产生的日志
• Exception: 异样
• RedisLog: 缓存，也有一些非缓存的操作如 zset 及分布式锁等
• Message Queue Log: 记录生产音讯及生产音讯的日志
• CronLog: 记录定时工作执行的工夫以及是否胜利
• 要害业务逻辑

日志的根本字段

对于所有的日志，都会有一些共用的根本字段，如在那台服务器，在那个点产生的日志

app

即以后我的项目的命名，在生产环境有可能多个我的项目的日志聚合在一起，通过 app 容易定位到以后我的项目

serverName

即服务器的 hostname，通过它很容易定位到出问题的服务器 / 容器。

现已有相当多公司的生产环境利用应用 kubernetes 进行编排，而在 k8s 中每个 POD 的 hostname 如下所示，因而很容易定位到

1. Deployment: 哪一个利用 / 我的项目
2. ReplicaSet: 哪一次上线
3. Pod: 哪一个 Pod

# shanyue-production 指 Deployment name
# 69d9884864 指某次降级时 ReplicaSet 对应的 hash
# vt22t 指某个 Pod 对应的 hash
$ hostname
shanyue-production-69d9884864-vt22t

timestamp

即该条日志产生的工夫，应用 ISO 8601 格局有更好的人可读性与机器可读性

{"timestamp": "2020-04-24T04:50:57.651Z",}

requestId/traceId

及全链路式日志中的惟一 id，通过 requestId，能够把相干的微服务同一条日志链接起来、包含前端、后端、上游微服务、数据库及 redis

全链路式日志平台能够更好地剖析一条申请在各个微服务的生命周期，目前风行的有以下几种，以下使他们的官网介绍

• zipkin: Zipkin is a distributed tracing system. It helps gather timing data needed to troubleshoot latency problems in service architectures. Features include both the collection and lookup of this data.
• jaeger: open source, end-to-end distributed tracing

label

即日志的类型，如 SQL、Request、Access、Corn 等

userId

即用户信息，当然有的服务可能没有用户信息，这个要视后端服务的性质而定。当用户未登录时，以 -1 代替，不便索引。

{
  "userId": 10086,
  // 当用户在未状态时，以 -1 代替
  "userId": -1,
}

Node 中如何打日志: winston

winston 是 Node 中最为风行的日志工具，反对各种各样的 Transport，可能让你定义各种存储地位及日志格局

当然还有其它可选的计划：如 []

{
  defaultMeta: {
    app: 'shici-service',
    serverName: os.hostname(),
    label
  }
}

import winston, {format} from 'winston'
import os from 'os'
import {session} from './session'

const requestId = format((info) => {
  // 对于 CLS 中的 requestId
  info.requestId = session.get('requestId')
  return info
})

function createLogger (label: string) {
  return winston.createLogger({
    defaultMeta: {serverName: os.hostname(),
      // 指定日志类型，如 SQL / Request / Access
      label
    },
    format: format.combine(
      // 打印工夫戳
      format.timestamp(),
      // 打印 requestId
      requestId(),
      // 以 json 格局进行打印
      format.json()),
    transports: [
      // 存储在文件中
      new winston.transports.File({
        dirname: './logs',
        filename: `${label}.log`,
      })
    ]
  })
}

const accessLogger = createLogger('access')

日志结构化

结构化的日志不便索引，而 JSON 是最容易被解析的格局，因而生产环境日志常被打印为 JSON 格局。

那其它格局能够吗，能够，就是解析有点麻烦。当然 JSON 也有毛病，即数据冗余太多，会造成带宽的节约。

http {
    include       mime.types;
    default_type  application/octet-stream;

    json_log_fields main 'remote_addr'
                         'remote_user'
                         'request'
                         'time_local'
                         'status'
                         'body_bytes_sent'
                         'http_user_agent'
                         'http_x_forwarded_for';
}

npm scripts: 优化本地日志及筛选

在 morgan 中能够优化日志的可读性并打印在终端

morgan(':method :url :status :res[content-length] - :response-time ms')

而以上无论生产环境还是测试环境本地环境，都应用了 json 格局，并输入到了文件中，此时的可读性是不很差？

别急，这里用 npm scripts 解决一下，不仅有更好的可读性，而且更加灵便

{"log": "tail -f logs/api-$(date +'%Y-%m-%d').log | jq",
  "log:db": "tail -f logs/db-$(date +'%Y-%m-%d').log | jq"
}

通过命令行 tail 及 jq，做一个更棒的可视化。jq 是一款 json 解决的命令行工具，需提前下载

$ brew install jq

因为打印日志是基于 jq 的，因而你也能够写 jq script 对日志进行筛选

$ npm run log  '. | {message, req}' 

申请日志: AccessLog

AccessLog 简直是一个后端我的项目中最重要的日志，在传统 Node 我的项目中罕用 morgan，然而它对机器读并不是很敌对。

以下是基于 koa 的日志中间件:

1. 对于 Options、健康检查及一些不重要申请不打日志
2. 应用 duration 字段记录该响应的执行工夫
3. 对于申请的 body 及 query 须要做序列化 (stringify) 解决，防止在 EliticSearch 或一些日志平台中索引过多及错乱
4. 记录全局的上下文信息，如 User 及一些业务相关联的数据

// 创立一个 access 的 log，并存储在 ./logs/access.log 中
const accessLogger = createLogger('access')

app.use(async (ctx, next) => {
  if (
    // 如果是 Options 及健康检查或不重要 API，则跳过日志
    ctx.req.method === 'OPTIONS' ||
    _.includes(['/healthCheck', '/otherApi'], ctx.req.url)
  ) {await next()
  } else {const now = Date.now()
    const msg = `${ctx.req.method} ${ctx.req.url}`
    await next()
    apiLogger.info(msg, {
      req: {..._.pick(ctx.request, ['url', 'method', 'httpVersion', 'length']),
        // body/query 进行序列化，防止索引过多
        body: JSON.stringify(ctx.request.body),
        query: JSON.stringify(ctx.request.query)
      },
      res: _.pick(ctx.response, ['status']),

      // 用户信息
      userId: ctx.user.id || -1,

      // 一些重要的业务相干信息
      businessId: ctx.business.id || -1,
      duration: Date.now() - now})
  }
})

数据库日志: SQLLog

对于风行的服务器框架而言，操作数据库个别应用 ORM 操作，对于 Node，这里抉择 sequelize

以下是基于 sequelize 的数据库日志及代码解释:

1. 绑定 CLS (Continues LocalStorage)，即可通过 requestId 查得每条 API 对应的查库次数，不便定位性能问题
2. 应用 duration 字段记录该查问的执行工夫，可过滤 1s 以上数据库操作，不便发现性能问题
3. 应用 tableNames 字段记录该查问波及的表，不便发现性能问题

// 创立一个 access 的 log，并存储在 ./logs/sql.log 中
const sqlLogger = createLogger('sql')

// 绑定 Continues LocalStorage
Sequelize.useCLS(session)

const sequelize = new Sequelize({
  ...options,
  benchmark: true,
  logging (msg, duration, context) {
    sqlLogger.info(msg, {
      // 记录波及到的 table 与 type
      ...__.pick(context, ['tableNames', 'type']),
      // 记录 SQL 执行的工夫
      duration
    })
  },
})

Redis 日志: RedisLog

redis 日志一般来说不是很重要，如果有必要也能够记录。

如果应用 ioredis 作为 redis 操作库，可侵入 Redis.prototype.sendCommand 来打印日志，对 redis 进行封装如下

import Redis from 'ioredis'
import {redisLogger} from './logger'

const redis = new Redis()

const {sendCommand} = Redis.prototype
Redis.prototype.sendCommand = async function (...options: any[]) {const response = await sendCommand.call(this, ...options);
  // 记录查问日志
  redisLogger.info(options[0].name, {...options[0],
    // 对于后果，可思考不打印，有时数据可能过大
    response
  })
  return response
}

export {redis}

微服务申请日志: RequestLog

第三方申请能够通过 axios 发送申请，并在 axios.interceptors 中拦挡申请打印日志。

次要，此时不仅注入了日志，而且注入了 requestId，传递给下一个微服务

import {requestLogger} from './logger'

axios.interceptors.request.use(function (config) {
  // Do something before request is sent
  const message = `${config.method} ${config.url}`
  requestLogger.info(message, config)
  // 从 CLS 中获取 RequestId，传递给微服务，组成全链路
  config.headers['X-Request-Id'] = session.requestId
  return config
}, function (error) {return Promise.reject(error)
})

总结

本文收录于 GitHub 山月行博客: shfshanyue/blog，内含我在理论工作中碰到的问题、对于业务的思考及在全栈方向上的学习

• 前端工程化系列
• Node 进阶系列

在一个后端我的项目中，以下类型须要打日志记录，本篇文章介绍了如何应用 Node 来做这些解决并附有代码

• AccessLog: 这是最常见的日志类型，个别在 nginx 等方向代理中也有日志记录，但在业务零碎中有时须要更具体的日志记录，如 API 耗时，具体的 request body 与 response body
• SQLLog: 对于数据库查问的日志，记录 SQL、波及到的 table、以及执行工夫，从此能够筛选出执行过慢的 SQL，也能够筛选出某条 API 对应的 SQL 条数
• RequestLog: 申请第三方服务产生的日志
• Exception: 异样
• RedisLog: 缓存，也有一些非缓存的操作如 zset 及分布式锁等
• Message Queue Log: 记录生产音讯及生产音讯的日志
• CronLog: 记录定时工作执行的工夫以及是否胜利
• 要害业务逻辑

关注我

扫码增加我的微信，备注进群，退出高级前端进阶群

<figure>
<img width=”240″ src=”https://user-gold-cdn.xitu.io/2020/6/29/172fe14e18d2b38c?w=430&h=430&f=jpeg&s=38173″ alt=” 加我微信拉你进入面试交换群 ”>
<figcaption> 加我微信拉你进入面试交换群 </figcaption>
</figure>

欢送关注公众号【全栈成长之路】，定时推送 Node 原创及全栈成长文章

<figure>
<img width=”240″ src=”https://shanyue.tech/qrcode.jpg” alt=” 欢送关注 ”>
<figcaption> 欢送关注全栈成长之路 </figcaption>
</figure>