Node.js 日志规范：基于 ELK 的字段、级别与场景设计

Node.js 日志规范背景与目标

前端开发者通常对日志关注度较低，因前端多依赖第三方统计工具（如百度统计）。在 Node.js 推进过程中，发现团队日志记录随意：该记录的未记录，关键日志缺乏必要上下文，导致线上问题定位困难。

本文梳理 Node.js 开发中日志存在的问题，并通过统一日志规范，明确期望达到的效果。

当前存在的主要问题如下：

• Node 日志不规范，打印随意。
• 缺乏良好的日志格式和约定字段，导致在 ELK 中无法有效解析和检索。
• Node 对接后端服务化后，调用链不清晰，增加了问题定位难度。
• 数据部门对 Node 日志使用无明确记录，Node 修改日志格式导致统计数据异常。

规范目标包括：

• 规范日志打印字段和格式，便于 ELK 检索。
• 增强 Node 上下游（Nginx/后端）日志格式，加入唯一 requestId，方便微服务下定位问题。
• 统计应用运行情况和性能数据。
• 维护数据部门对 Node 日志的使用情况。

日志类型与级别规范

具体实现方案如下：

日志类型定义

参考日志最佳实践，将 Node 日志分为以下四种类型（scope）：

• desc：系统启动及运行过程中的日志，包含启动日志、启动参数等。在无法捕获 HTTP 上下文时打印此类日志。
• stat：系统性能统计日志，应用定时收集性能信息，便于查询应用当前状态。
• visit：每个 HTTP 请求相关的日志，包含唯一 requestId，用于定位该请求相关的所有日志。
• biz：业务数据相关日志，主要提供给数据统计使用。

日志级别定义

仅使用 FATAL、ERROR、WARN、INFO 和 DEBUG 五个级别。

• FATAL：导致程序退出的严重系统级错误，不可恢复。发生时需系统管理员立即介入，一般应用代码不使用此级别。
• ERROR：运行时异常及预期之外的错误，需立即处理，紧急程度低于 FATAL。此类错误影响程序正确执行。注意：这两种级别属于服务自身错误，需管理员介入；用户输入错误不属于此类。请求后端、读文件、数据库超时或返回错误结构属于 ERROR。
• WARN：预期之外的运行时状况，表示系统可能出现问题。对于目前非错误但处理不当会演变为错误的情况，也可记为 WARN，如磁盘空间过低。
• INFO：有意义的事件信息，记录程序正常运行状态，如收到请求、成功执行。通过查看 INFO 可快速定位 WARN、ERROR、FATAL。INFO 不宜过多，通常不超过 DEBUG 的 10%。
• DEBUG：与程序运行时流程相关的详细信息及当前变量状态。

日志格式与字段定义

日志格式与字段规范

• 日志格式统一采用 JSON，便于 ELK 解析处理。
• 日志中的各个字段的值，应尽量使用英文，不使用中文。
• 日志具体字段分为基础数据和扩展数据。基础数据由底层日志框架自带，所有日志均包含；扩展数据针对不同日志类型包含不同字段。

日志基础数据

目前使用的 node-bunyan 日志库，官方文档规定基础字段包含如下：

• v：integer。bunyan 的日志版本号。
• level：integer。日志级别对应的数字。
• name：string。服务名。
• hostname：string。主机名。
• pid：integer。进程号。
• time：string。UTC 格式的日期。
• msg：string。日志主体信息。

日志扩展数据

下文定义的各种数据类型的扩展数据并非全部字段，仅包含该日志类型下必需的字段。这些必需的扩展字段需在 ELK 中建立索引，方便定位各种问题。

• desc 类型日志，扩展字段：TODO
• stat 类型日志，扩展字段：{ perf: {rss: xxxx, cpu: xxx} }
• visit 类型日志，扩展字段：
• biz 类型日志，扩展字段见代码示例。

{
  ///////////// 基础数据 ////////
  v: 1,
  level: 20,
  ///////////// 扩展字段 ////////
  // 标志日志类型
  scope: "visit",
  //事件类型：在 visit 的日志类型下，还会细分不同的事件，比如 client-req、client-res、 普通trace、请求后端service-start, service-end, service-err等。
  event: "trace",
  //客户端ID，追踪用户、设备会话。在web端，可以是长期的cookie；在APP端，可以是device-id等
  rrdid: "",
  //本次请求的惟一ID，串联本次请求的所有相关日志
  req_id: "some-uuid-for-request",
  //本次请求的用户ID
  uid: "",
  //本次请求的客户端相关数据，通过 ctx.logger 打日志时，自动加上
  d: {
    url: "/some/path?include-query",
    //客户端ip
    ip: "10.138.10.1",
    //客户端的 userAgent
    ua: ""
  },
  //本次node请求的处理时间，毫秒
  tm: 500,
  //该日志相关的上下文数据，尽量拼成一个字符串，放在 extra 里
  extra: "",

  //ERROR 级别日志，最好包含error相关信息，比如请求后端相关参数等
  err: {
    msg: "",
    stack: ""
  },

  //调用后端服务相关参数和响应
  service_req: {
    host: "",
    path: "",
    payload: ""
  },
  service_res: {
    //http状态码
    http_code: 200,
    //响应时间
    tm: 100,
    //响应的body
    body: "",
    //异常信息
    err: ""
  }
}

visit 类型日志与链路追踪

什么时候打日志

开发者目前只关心 visit 类型的日志，即和某一次 HTTP 请求相关联的日志。desc 和 stat 类型的日志，统一由开发框架封装后实现，业务开发不用关心。下面讲的，都是针对 visit 类型的日志。 一次 HTTP 请求，会打出一系列相关联的日志。在 Node 层，通常一次请求，会进一步转发给 N 个后端服务，然后对后端数据进行一些处理、合并等操作，最后渲染页面或是输出 JSON。因此，一次请求相关的日志，大体分为以下几种 event：

• client-req：client 请求到达 Node 层，统一由框架打日志，开发不关心。
• service-start：Node 对某个后端服务发起请求，由通用请求库负责打日志，开发不关心。
• service-end：Node 请求某个后端服务结束，由通用请求库负责打日志，开发不关心。
• service-err：Node 请求后端服务异常，由通用请求库负责打日志，开发不关心。调用后端服务异常，日志级别为 WARN，不是 ERROR。
• trace：Node 中业务层打的日志，如果异常，能帮助定位本次请求相关问题。
• client-res：结束 client 的请求，打印本次请求的 HTTP code，本次请求处理时间等，由框架统一打，开发不关心。

开发同学在打日志时，应该谨慎的选择级别，INFO(含)级别以上，都应该能对定位问题、具体业务统计需求有要求，才能使用。大部分情况下，可以使用 DEBUG 级别，线上不会开启 DEBUG 级别。

日志打印方法与实践

具体方法调用

针对打印 visit 类型的日志，调用 ctx.logger(基于 Koa 的框架) 属性打日志，推荐参数都传递 JSON，具体方法如下：

ctx.logger.debug({msg: "", "extra": "a=1 b=2 c=value"});
ctx.logger.info({msg: "xxx", "extra": "其他的额外字段"});
ctx.logger.warn({msg: "xxx", "extra": "额外上下文数据"});
//ERROR级别日志，应该提供 Error 对象
ctx.logger.error({msg: 'xxx', err: error, extra: ""});

注意 1，额外的参数，推荐存放在 extra 字段中，统一拼成 string；如果确实有必要单独出每个字段，禁止额外的参数占用上述通用字段名！！

注意 2，基础数据中的 msg 字段，禁止包含具体的上下文数据，和该日志相关的上下文数据，应该拼成字符串，放在单独的 extra 字段中。比如，某个用户登录接口，希望统计调用次数，可以这样打印:

ctx.logger.info({msg: "user login", "extra": 'mobile=18712387101 code=xxxx k3=value3'});

以上就是本文的全部内容，希望对大家的学习有所帮助，也希望大家多多支持本站。