📌 术语定义

运行日志/系统日志

开发人员为了方便定位错误而打的日志，该部分较为自由

追踪日志/调用链日志

分布式系统中为了追踪某个调用链流程相关的日志，该部分一般遵循一定的规范如 OpenTracing。

特殊日志

面向某特定领域，具有统一格式约束的日志，以在特定场景实现某一功能的日志。如操作日志/业务日志、审计日志。如：操作日志统一使用 JSON 格式，并且要求包含指定的字段。

日志级别

用于日志分类：描述日志重要程度、统一处理某一级别的日志（如控制输出路径、文件名、保存时间、是否输出等）。

日志服务

拥有处理日志的能力的软件系统，通常具有采集、存储、检索、分析日志的能力，典型如 ELK。

🔗 规范约束

日志文件规范

日志文件输出目录

  • 每种程序日志必须统一路径，通常以软件标识命名目录，如 order 服务的所有日志输出到 xxx/order 文件夹下

  • 一个的软件系统下的不同程序统一输出到特定目录，如 /logs/shoulder/

日志文件存留时间、切分、压缩

  • 该部分按照软件定义和日志级别来确定，如每天的日志压缩一次，最多保留十天或总大小最大允许200M。

日志文件命名

  • 按照日志级别区分，如包含 debug、error、other、dts 日志文件

    • debug 包含 debug 级别及以上的日志

    • error 包含 error 级别及以上的日志

    • other 非本软件代码打印的日志

    • dts 分布式链路追踪日志，而非单指 trace 级别

  • 当前日志文件命名

    • 软件标识.日志级别.log，如 xxx.debug.20200101.log

  • 压缩日志文件命名（历史日志文件）

    • 软件标识.日志级别.日期.log，如 xxx.debug.20200101.log.zip

通用日志输出格式规范

定义统一的日志格式可以统一进行日志分析，下举例统一格式

对日志做格式的目的是能够方便的追溯与排查问题，

 
日志时间SP日志级别SP程序标识SP[代码位置]SP[线程标识]SP<调用链标识>SP[错误码]SP-SP日志输出正文

格式说明

  • SP

    • 表示一个空格。

  • []、<>

    • 表示内容可选，并且需要输出到对应括号内，如果没有则使用字符 - 代替之。

  • 基本值特殊字符约束

    • 除了开发者在代码中写的 日志输出 不允许有 空格 、 [ 、 ] 、 < 、 >

  • 日志时间

    • 日志产生的时间，能够方便的追溯与排查问题。

    • 示例

      • 带时区 2020-01-01T00:00:00.000+08:00、2020-01-01T00:00:00.000Z。

      • 不带时区 2020-01-01 00:00:00.000。

  • 日志级别

    • 包含 6 个级别（TRACE、DEBUG、INFO、WARN、ERROR、FATAL）

    • [.line-through]统一按5个字符长度输出，以保持一致

  • 程序标识

    • 输出日志的代码所属程序标识，可为模块名称也可为服务名，目的便于区分哪里产生的，与类名、方法名组合定位到具体代码。

    • 示例

      • spring-aop、spring-boot-redis、shoulder-core、shoulder-crypto

  • 代码位置

    • 打印日志的代码位置，具体可为代码文件路径，类路径、方法名、代码行号等。

  • 线程标识

    • 由于获取堆栈信息较耗费性能，一般不打印该值，使用 - 来代替，但有时为了方便追踪，需要加上该内容，一般为线程名称/ID。

  • 调用链标识

    • 即 traceId ，用于快速定位一次调用链，没有则使用 - 来代替。

  • 错误码

    • 记录错误日志时（WARN 级别及以上），需要同时记录错误码，以 0x 开头，十六进制格式输出。没有则使用 - 来代替。

  • 日志输出正文

    • 开发人员自定义的日志内容，推荐使用英文（优化压缩率、避免乱码、避免歧义）；记录参数时推荐使用 [param1=value1,param2=value2..]其他内容 这种形式。

日志级别规范

  • 完整调用信息约束

    • 记录 WARN 级别及以上的日志时，需要记录触发端点（接口地址、定时任务标识、消息事件类型）参数、触发用户标识、若存在异常则需要包含调用栈信息，以便排查、复现问题。

  • TRACE

    • 一般不记录参数、变量值，仅用于调试、测试期间标记记录程序执行到此，在其他级别日志记录未开发或缺失时来判断程序是否执行至此，程序正常运行时一般不打印该级别日志。

    • 举例：发起远程调用、完成远程调用、收到调用请求、完成调用请求、方法开始前、方法完成后。

  • DEBUG

    • 记录出入参数值、关键变量值、接口响应值等。

  • INFO

    • 程序自身状态变更、配置参数值变更、意料之中的异常、定时任务、通知变更、API接口被调用、特殊数据的初始化、关键的数据变更等，一般用于调试、测试期间以及复现问题时打印。

  • WARN

    • 程序抛异常，导致一次功能失效，且容忍这类错误，设计了人性化的提示，单次发生不影响再次操作、后续流程、其他操作、其他用户。

    • 举例：程序启动无法读取到配置文件而使用默认值；调用其他服务接口失败且有不影响业务的容错处理；超出了需求范围&&可以放弃的业务:程序性能达到上限无法继续处理新的请求/识别出是爬虫；意料之中的特定异常(如由客户端传入参数有误引起的)。

  • ERROR

    • 程序触发意料之外的异常、状态，导致业务失败，可能导致后续相同功能失败或影响其他功能，程序无法自身解决该类问题，需要产生告警，告知维护人员解决该问题，常常是软件依赖的其他软件或基础设施不正常。

    • 举例：关键业务（功能、定时任务、通知处理）失败；出现程序功能部分不可用（关键配置项缺少、关键中间件连接失败、系统内存、硬盘等上限）。

  • FATAL

    • 程序崩溃，接近所有功能不能使用，后续操作无法进行，必须重启或由专人来排查，发生概率极低。

    • 举例：程序所占有资源被其他软件或工具篡改而导致的系统无法按照软件的指令继续执行（检测到非法外挂）、文件损坏无法启动；

🔍 追踪日志

记录远程调用和内部调用的日志，用于追踪业务流向，将一次业务流程在不同服务/系统中产生的系统日志相关联，为排查问题提供方便。

内容要求

该部分一般使用第三方等成熟的开源方案快速落地，如 Zipkin、SkyWalking、Cat 等。

Table 1. 字段与要求
字段名 填写类型 含义

node_id

必填

节点编号，用于确认唯一一个进程，必填。格式举例：<应用标识>.@<IP>、会员中心-用户资产-token模块-05@<IP>。

trace_id

必填

用于标识一笔业务的唯一序号。由 09、az 和 A~Z 构成，长度 32 字符。

span_id

必填

用于标识某一阶段调用序号。由 0~9 、 a~z 和 A~Z 构成，长度 32 字符。

parent_id

条件必填

用于标识某一阶段的父调用序号(span_id)，格式同 span_id，非 trace start。

action

必填

用于记录若干和调用轨迹有关的特定动作。动作是一个枚举列表。

span_name

条件必填

被调用的方法名称或接口名称，选填，当 action 字段值为 client send，server receive，invoke 时必填。

notation

选填

当action 表示为错误返回时，用来携带错误信息，选填。允许有换行和空格，长度不超过 200 字符，采用 UTF-8无BOM 格式编码。

code

选填

用来携带错误码。

记录时刻

Table 2. 记录时刻
使用场景 action 备注

业务发起方远程调用开始，产生trace id

trace start

业务发起方远程调用结束

trace end

配对trace start使用

请求端调用rpc前，发送网络请求

client send

请求端收到正常响应或者调用失败

client receive

配对client send使用

服务端接收到请求报文

server receive

服务端完成请求处理，发送响应

server send

配对server receive使用

方法开始调用

invoke

方法完成

return

配对invoke使用

HTTP 传输要求

在HTTP请求中需要传递追踪上下文信息，把追踪字段添加至请求头 Header

  • trace_id：同表2中的 trace_id 字段

  • span_id： 同表2中的 span_id 字段

附Zipkin使用：

  • X-B3-TraceId：全局跟踪ID，用它来标记一次完整服务调用，32位或16位十六进制小写字符

  • X-B3-SpanId：局部跟踪ID，用它来标记一次子调用，16位小写十六进制字符

  • X-B3-ParentSpanId：某次调用的父调用的跟踪ID

  • X-B3-Sampled：“1”代表采样，“0”代表不采样，如果无此key，即由服务端自行判断

  • X-B3-Flag：调试标记，如果此值设置为“1”，采样率固定为100%

🕒 操作日志

记录目的

给使用软件的管理员看的，方便快速了解系统因 哪个用户 在 什么时刻 用 哪个终端 的 什么操作 ，操作了 什么类型 的 哪个对象 ， 操作结果 如何， 操作详情 是怎样的， 关联的上下文 是什么。

sonatype 网站就是一个例子，简单的展示了上述的内容。

内容要求

有的系统将日志直接放进数据库，故须要有一定的长度限制，下表中列出了推荐最大长度，实际中可以灵活调整，也有的系统选择放入 ES 中，长度限制就显得没那么大必要了。

Table 3. 操作日志格式
字段名称 长度 必填 说明

操作者相关信息

userId

128

是

用户标识（如用户名、userId）；为系统内部操作时（如定时任务、接收消息通知），填写执行操作的服务实例名，格式为 system.应用标识.实例标识

userName

128

否

用户昵称

personId

64

否

用户对应人员标识

userOrgId

128

否

用户所属 用户组 或 群组 或 部门 的编号。

userOrgName

255

否

用户组名称。

terminalType

1

是

操作者所使用终端的类别 0 表示 系统内部、1 表示 浏览器、2 表示 APP、3 表示 PC客户端

ip

255

否

操作者所在机器 IP；系统内部操作时，填写服务所在机器 IP。

terminalId

128

否

操作者所使用终端的唯一标识：如 MAC 地址。

terminalInfo

256

否

操作者所使用终端详情信息，如浏览器中的 UserAgent。

操作动作相关信息

operation

255

是

操作动作标识。

operationTime

128

是

操作时间，格式为 年-月-日T时:分:秒.毫秒时区，如 2017-09-20T13:42:38.349+08:00。

params

-

否

操作对应业务方法/接口的入参，一般关键/特殊业务才会使用。JSON 形式，见下方 操作日志参数格式

result

1

是

业务操作结果：0 表示 成功、正确、1 表示 失败、不正确、2 表示 部分成功

errorCode

32

否

当操作结果为失败时，记录操作失败对应的错误码。

detailKey

128

否

操作详情（ 支持 多语言时填写），多语言 key 格式：op.detail.<操作内容标识>，支持占位符，采用 %1, %2, %n 形式，n表示第n个参数；不支持多语言时留空。

detailItems

-

否

操作详情占位参数（ 支持 多语言时填写），用于填充 detailKey 的占位符。

detail

4096

否

操作详情（ 不支持 多语言时填写）详细的描述用户的操作内容，也可填写被操作对象的 JSON 字符串。

被操作对象相关信息

objectType

128

否

操作对象的类型标识。

objectId

128

否

操作对象的标识，若存在多个值时， 以 , 分隔，如 [1,2,3,4,5]。

objectName

255

否

操作对象的名称，若存在多个值时，以 , 分隔，如 [角色1、角色2]。

其他信息

businessId

128

否

存放与本次操作所关联其他业务操作的业务号。用于多个请求完共同完成一个业务功能时。如：上传csv进行数据的批量导入场景：上传导入文件、校验导入数据、点击确认导入、导入成功业务相关可以填同一个标识符

appId

128

是

服务唯一标识。

traceId

128

否

调用链标识。

自定义扩展字段

-

否

扩展字段，用于个别服务需要，一般留空。

与例子中的 sonatype 网站类比，一个业务是由多个子业务构成的，他们有共同的 businessId，每个业务/动作/操作都有唯一标识 operation / typeId，记录了操作的内容（被操作对象），操作结果如何，错误信息是什么，操作详情等。 可以看到自己最近什么时间在哪种终端做了什么。

Table 4. 操作日志参数格式
字段名称 长度 必填 说明

name

128

是

参数名称

value

64

是

参数值

supportI18n

1

是

value 字段是否支持多语言

使用场景

  • 业务操作，使数据库数据发生变化时（增删改）

  • 重要数据的读取时

  • 定时任务、补偿任务时

编码建议

  • 方法抛出异常，日志框架默认会将执行结果置为失败，并尝试记录操作日志

  • 有的系统自己探索日志可视化方案，为了使得操作日志支持多种语言同时查看，推荐将以下标识性字段进行一定的多语言处理。 其中部分字段为翻译型，可以自定义 多语言key前缀 以便于解析翻译，也可以直接尝试翻译，翻译失败则展示原值。

Table 5. 多语言字段对照表
字段名称 说明 建议方案

operation

操作动作标识

支持多语言时添加特定前缀，如 op.op.<操作动作标识>

objectType

被操作对象类型

支持多语言时添加特定前缀，如 op.objType.<操作对象类型标识>

detail

操作详情

使用 detailKey 作为多语言key，格式：op.detail.<操作内容标识>，detailItem 填充占位符

terminalType

终端类型

采用枚举/数据字典，展示层翻译

result

操作结果

采用枚举/数据字典，展示层翻译

appId

应用标识

结合基本规范，采用数据字典，展示层翻译

errorCode

错误码

结合错误码规范，给出错误原因和排查建议

operationTime

操作时间

结合国际化规范，时间格式可改变

日志审计

审计目的：提前发现风险，保证重要数据不被丢失，分析风险行为。如恶意攻击、非法爬虫、越权访问、潜在漏洞、命令审计、账户行为（改密）审计、登录（登录地点）审计、重要资源访问审计等。

异常日志告警一般放在错误码监控上，不在审计中，另外，审计一般不是实时的。

审计流程 [1]

  1. 定义特征

    • 定义行为特征，如SQL注入测试、端口扫描等

  2. 读取

    • 从日志存储中进行日志读取，由于数量大，故进行流式读取。

  3. 匹配与分发

    • 通过多个过滤器进行匹配，如果匹配则将结果分发至对应处理器继续处理

  4. 结果处理

    • 根据符合的结果进行一定的处理，如筛选出频率最高的 IP 进行封禁，当频次超过某个阈值或发送某个不应该发送的动作则进行 报警 ，产生处理情况报表。

💻 编码与使用

🔥直接使用 Shoulder 框架👈

其他注意事项：

  • debug环境下，nginx 日志中加入上游服务器的地址更容易调试，nginx.conf 中加入 add_header X-UpStream $upstream_addr;

  • 合理利用日志框架的 MDC 机制，利用该能力将一些通用的数据记录其中，简化代码

  • 以下情况必须打印日志

    • 数据变更时（增、删、改），debug

    • 条件分支时， debug

    • 数据量异常时（过大、过小） info / warn