大多数项目的日志是这样演化的:初期只有几行 print,调试时随手加几条,上线后怕出问题又加几条,最后日志量膨胀到每天几个 GB,真正需要排查问题时却在海量日志里找不到关键信息。日志的膨胀和质量的下降是同步发生的——写得多不代表写得好,很可能恰恰相反。
非结构化日志的三个致命问题
问题一:可搜索性差。 非结构化日志是给人读的文本,不是给程序处理的数据。当你需要查找"过去一周内所有支付失败的请求"时,面对的是一行行格式不统一的文本:有的是 Payment failed for user 123,有的是 Error processing payment: timeout,有的是 支付失败 userId=123 reason=timeout。写 grep 正则需要覆盖所有变体,而且无法保证没有遗漏。
更糟糕的是,同一个事件在不同位置可能被记录为不同格式。A 模块写 order_id=456,B 模块写 orderId=456,C 模块写 order:456。这不是故意制造混乱,而是不同开发者在不同时间独立添加的日志,没有统一规范。当模块数量超过十个时,格式统一性就不可能靠人的自觉来维持了。
问题二:上下文丢失。 一条日志 Operation failed 包含了什么信息?有一个操作失败了。但什么操作?哪个用户的?什么时候?什么参数?什么错误?这些上下文全都没有。不是开发者不想加,而是在写日志的当下觉得"这一看就知道是什么操作",三个月后看日志的人却完全不知道。
上下文丢失的另一个表现是:关联信息分散在不同日志行中。请求 A 的入口日志在第一行,错误日志在第一百行,中间夹着其他请求的日志。要还原请求 A 的完整链路,需要手动从海量日志中挑出相关行。这不是"不方便",在严重故障时这是"不可能"——当每秒产生几千行日志时,人工关联已经不可行。
问题三:无法自动分析。 非结构化日志只能做全文搜索,无法做聚合分析。"过去一小时的错误率是多少?""哪些 API 端点的响应时间超过了两秒?""哪种错误类型出现最频繁?"这些问题的答案就在日志里,但非结构化的格式让自动提取变得极其困难。需要为每种查询写定制的正则,而正则的脆弱性意味着任何格式变化都可能导致分析结果不准确。
结构化日志的核心要素
结构化日志的核心理念是:每条日志都是一个有明确字段定义的数据记录,而不是一段自由文本。这意味着日志可以被程序可靠地解析、索引、查询和分析。
一条结构化日志至少应该包含以下字段:
时间戳(timestamp):精确到毫秒。这不是可选的——没有时间戳的日志几乎没用。时间戳应该是 UTC 或者明确标注时区,避免跨时区部署时的混乱。
日志级别(level):DEBUG / INFO / WARN / ERROR / FATAL。级别的定义要明确:DEBUG 只在开发时用,INFO 记录正常业务事件,WARN 记录可恢复的异常,ERROR 记录需要关注的失败,FATAL 记录导致服务不可用的严重错误。模糊的级别定义比没有级别更糟糕,因为会导致信息被错误过滤。
事件类型(event):这条日志描述的是什么事件?不是"发生了一个错误",而是具体的 payment_failed、request_timeout、cache_miss。事件类型应该是枚举值,而不是自由文本。每个事件类型对应一种已知的系统行为,未知的事件类型意味着有未预期的行为需要关注。
请求标识(request_id / trace_id):用于关联同一请求的所有日志。在分布式系统中,一个用户请求可能经过多个服务,trace_id 是跨服务追踪的线索。没有 trace_id,分布式系统的日志几乎不可能关联。
上下文字段(context):与事件相关的关键数据。支付失败需要记录 user_id、order_id、error_code、amount。请求超时需要记录 endpoint、timeout_ms、retry_count。上下文字段的选取原则是:排查问题时一定会问的信息。如果排查"支付失败"时第一个问题是"哪个用户",那 user_id 就是必填字段。
从非结构化到结构化的迁移
不需要一步到位。以下是一个渐进式迁移策略:
第一阶段:JSON 格式化。 把现有的文本日志改为 JSON 输出。这一步不改日志内容,只改格式。原来写 logger.info(f"Payment failed for user {user_id}"),改为 logger.info("payment_failed", user_id=user_id),框架自动输出为 JSON。这一步的收益是日志可以被 jq、Elasticsearch 等工具直接处理。
第二阶段:统一事件类型。 为每个模块定义事件类型枚举。不再用自由文本描述事件,而是从预定义列表中选择。这一步的收益是日志可以被精确搜索和过滤——查所有 payment_failed 事件只需要一个查询条件。
第三阶段:补充上下文字段。 审查每个事件类型,确保记录了排查问题所需的全部字段。这一步需要站在运维的角度思考:"如果这个事件在生产环境发生,我需要什么信息才能定位问题?"缺什么补什么。这一步的收益是问题排查不再需要"登录服务器看代码"来理解日志含义。
第四阶段:引入 trace_id。 在请求入口生成唯一标识,传递到整个调用链。这需要各服务配合,但在分布式系统中是必须的。这一步的收益是可以追踪一个请求的完整路径。
第五阶段:建立日志质量门。 在 CI 中检查日志语句是否符合规范:是否使用了结构化格式、是否包含必要字段、事件类型是否在枚举中。不合规的日志在代码审查阶段就被拦截。这一步的收益是防止日志质量退化。
日志级别的正确使用
日志级别是最常被误用的设计。常见错误:
用 ERROR 记录预期内的异常。 比如用户输入不合法、第三方 API 限流返回 429、缓存未命中需要回源。这些是已知的、可恢复的情况,不应该用 ERROR。滥用 ERROR 会导致真正的错误被淹没在噪声中,监控告警也频繁误报。
正确的做法:预期内的异常用 WARN,只有需要人工介入的意外情况才用 ERROR。判断标准是"这条日志是否需要有人立即查看"。如果不需要,它不应该是 ERROR。
用 DEBUG 记录所有细节。 DEBUG 日志的初衷是帮助开发调试,但如果 DEBUG 日志包含大量数据(如完整的请求/响应体、大数组内容),在生产环境打开 DEBUG 时会产生海量输出,影响性能和存储。
正确的做法:DEBUG 只记录调试逻辑所需的最小信息。大数据量的内容使用 TRACE 级别(如果框架支持),或者根本不记录——需要时可以通过专门的调试接口获取。
INFO 日志要么太多要么太少。 太多:每个函数入口出口都记一条 INFO,日志量爆炸。太少:只有服务启动和停止的日志,出问题时完全没有线索。
正确的做法:INFO 记录业务关键事件——请求处理完成、状态变更、定时任务执行、外部调用结果。判断标准是"如果这条日志缺失,是否影响对系统运行状态的理解"。
日志的量与质的权衡
日志量和日志质量是反相关的。日志量越大,单条日志的平均价值越低,因为有用的信息被噪声稀释了。
一个实用的策略是分层日志:
- 业务层日志:记录业务事件和关键指标,量小但价值高。这是运维和产品团队日常关注的日志。
- 技术层日志:记录技术细节(接口调用、缓存命中、队列消费),量中等,排查技术问题时使用。
- 调试层日志:记录详细执行过程,量大,只在开发调试时开启。
三层日志的输出可以由级别控制:业务层对应 INFO,技术层对应 DEBUG,调试层对应 TRACE。生产环境通常只输出业务层日志;需要排查技术问题时临时开启技术层;调试层只在开发环境使用。
日志不是唯一的可观测性手段
日志、指标(metrics)、追踪(traces)是可观测性的三大支柱。把所有可观测性需求都压到日志上,会导致日志承担过多职责:
- 用日志统计 QPS → 应该用指标
- 用日志追踪请求链路 → 应该用分布式追踪
- 用日志监控系统健康 → 应该用健康检查和告警
日志的优势是记录事件详情——具体发生了什么、上下文是什么。指标的优势是聚合和趋势——过去一小时的 QPS 变化、P99 延迟走势。追踪的优势是关联和定位——一个慢请求卡在哪一步。
各司其职,不要让日志越俎代庖。当你发现自己写日志是为了"之后用 awk 统计"时,说明这个信息应该是一个指标而不是一条日志。
总结
日志不是垃圾桶——不该什么都往里扔;日志是档案——每条记录都应该有明确的用途和结构。从非结构化到结构化不是格式升级,而是管理理念的转变:日志不再是"出了问题再看的文本",而是"系统行为的结构化数据"。
关键原则:每条日志都有明确的事件类型、必要的上下文字段、准确的级别、和可关联的请求标识。做到这四点,日志就从"需要大海捞针的文本堆"变成了"可精确查询的数据源"。排查问题的时间从小时级降到分钟级,不是因为人变聪明了,是因为日志终于变得可搜索了。