4. 结构化日志：JSON格式日志输出、日志字段标准化

说实话，我见过太多团队在排查线上问题时，对着满屏的纯文本日志抓耳挠腮。你想想看，几百台机器，每台每秒吐几百行日志，用 grep 翻来翻去，眼睛都快瞎了。这其实不是技术问题，是日志格式的问题。

我个人习惯，从项目第一天就强制要求结构化日志。说白了，就是把日志从「给人看」变成「给机器和人都能看」。今天我们就聊聊怎么落地这件事。

4.1 为什么非要用结构化日志？

我记得有一次，线上服务突然超时。我登录机器，看到的是这样的日志：

2024-03-15 10:23:45 ERROR 订单处理失败，用户ID: 12345，错误: 数据库连接超时

嗯，看起来挺清楚对吧？但当你需要统计「过去5分钟有多少订单失败」时，你就得写一堆正则表达式去匹配。更别提跨服务追踪了，字段位置稍微一变，你的解析脚本就崩了。

换成 JSON 格式后，同样的日志长这样：

{"timestamp":"2024-03-15T10:23:45.123Z","level":"ERROR","module":"order-service","message":"订单处理失败","user_id":"12345","error":"数据库连接超时","request_id":"req-abc-123","duration_ms":3021}

看到区别了吗？每个字段都有明确的键名，解析起来零歧义。你甚至可以直接把这种日志丢进 Elasticsearch，自动建索引，秒级查询。

核心原则：结构化日志不是「把文本变成 JSON」，而是「让日志自带 Schema」。每个字段都有明确的类型和含义。

4.2 日志字段标准化：五个必选字段

我在项目中踩过最大的坑，就是不同团队写的日志字段名不统一。A 团队用 time，B 团队用 timestamp，C 团队用 @timestamp。聚合分析的时候，光字段映射就写了半天。

所以我建议，所有日志至少包含以下五个标准化字段：

字段名 类型 说明 示例
timestamp ISO 8601 字符串 事件发生时间，精确到毫秒 2024-03-15T10:23:45.123Z
level 字符串 日志级别，统一大写 INFO, WARN, ERROR
module 字符串 产生日志的模块名 order-service, auth
message 字符串 人类可读的描述 订单创建成功
request_id 字符串 请求追踪 ID（可选但强烈推荐） req-abc-123

我的经验：timestamp 一定要用 UTC 时间，别用本地时间。否则跨时区排查问题的时候，你会疯掉的。我曾经因为时区问题，把一次故障的根因定位晚了整整两个小时。

4.3 代码实战：从零实现结构化日志

光说不练假把式。我们直接看代码。下面是一个 Python 示例，演示如何输出标准化的 JSON 日志：

import json
import logging
from datetime import datetime, timezone

class JSONFormatter(logging.Formatter):
    def format(self, record):
        log_entry = {
            "timestamp": datetime.now(timezone.utc).isoformat(),
            "level": record.levelname,
            "module": record.name,
            "message": record.getMessage(),
        }
        # 如果有额外字段，也加进去
        if hasattr(record, "extra_fields"):
            log_entry.update(record.extra_fields)
        return json.dumps(log_entry, ensure_ascii=False)

# 配置日志
logger = logging.getLogger("order-service")
handler = logging.StreamHandler()
handler.setFormatter(JSONFormatter())
logger.addHandler(handler)
logger.setLevel(logging.INFO)

# 使用示例
logger.info("订单创建成功", extra={
    "extra_fields": {
        "order_id": "ORD-20240315-001",
        "amount": 99.99,
        "user_id": "u-12345"
    }
})

输出结果：

{"timestamp":"2024-03-15T10:23:45.123456","level":"INFO","module":"order-service","message":"订单创建成功","order_id":"ORD-20240315-001","amount":99.99,"user_id":"u-12345"}

你看，核心逻辑其实很简单：自定义一个 Formatter，把日志记录转成 JSON 字典，然后序列化输出。关键是要保证每个字段的类型一致——比如 amount 是数字，就别写成字符串 "99.99"。

注意：千万不要在日志里拼接用户输入！比如 f"用户 {user_input} 登录失败"。如果 user_input 包含换行符或特殊字符，你的 JSON 就炸了。始终使用 extra 字段传递动态数据。

4.4 日志级别的最佳实践

我见过很多团队把 ERROR 当 INFO 用，结果告警系统天天半夜响。日志级别不是摆设，它决定了你能否在故障时快速定位问题。

我个人习惯这样划分：

  • FATAL：服务完全不可用，必须立即人工介入。比如数据库连不上、配置加载失败。
  • ERROR：某个请求失败，但服务还能继续运行。比如第三方接口超时、参数校验不通过。
  • WARN：潜在问题，不影响当前请求但需要关注。比如磁盘使用率超过 80%、重试次数过多。
  • INFO：关键业务流程节点。比如订单创建、用户注册、支付回调。
  • DEBUG：开发调试用，生产环境默认关闭。比如 SQL 语句、变量值。

避坑指南：我曾经在一个项目里，把 INFO 级别的日志量控制得很好，但 DEBUG 日志里有人打印了完整的用户密码哈希。虽然生产环境默认不输出 DEBUG，但一旦有人动态调整日志级别，这些敏感信息就暴露了。所以，永远不要在日志里打印密码、Token、身份证号。

4.5 知识体系：结构化日志的核心逻辑

下面这张图，是我对结构化日志整个知识体系的总结。你可以把它当作一个检查清单：

结构化日志知识体系 结构化日志 字段标准化 输出格式 级别规范 timestamp level module JSON 序列化 类型一致性 敏感信息过滤 FATAL / ERROR WARN / INFO DEBUG 核心原则 1. 字段名统一，避免团队间歧义 2. 类型严格一致，数字就是数字，字符串就是字符串 3. 级别分级使用，ERROR 只用于真正的错误 4. 永远不打印敏感信息

4.6 生产环境中的几个坑

最后，分享几个我在生产环境中踩过的坑，希望能帮你省点时间：

  1. 日志打得太频繁：有一次，一个同事在循环里打了 DEBUG 日志，结果日志文件每小时涨 10GB。磁盘直接写满，服务挂了。建议对高频日志做采样，或者限制单条日志的大小。
  2. JSON 里塞了太多字段：有些人喜欢把整个请求对象都塞进日志。结果一条日志几 KB，查询起来慢得要死。只保留关键字段，其他用 extra 按需添加。
  3. 时区不统一：前面说过，timestamp 必须用 UTC。如果你用本地时间，跨时区排查时你会怀疑人生的。
  4. 日志丢失：异步日志框架（比如 log4j2 的异步 Appender）在高并发下可能丢日志。如果你对日志完整性要求高，记得用同步模式，或者加一个可靠的缓冲层。

重要提醒：日志不是越多越好。每一条日志都有成本——磁盘 IO、存储空间、查询时间。我见过最夸张的项目，一天产生 500GB 日志，结果 Elasticsearch 集群直接撑爆。合理控制日志量，该打的打，不该打的坚决不打。

好了，结构化日志的核心内容就这些。记住，好的日志格式，能让你的排查效率提升十倍。下次我们聊聊怎么用这些日志做真正的协议解析和故障定位。

← 上一章 📖 返回目录 下一章 →