你那console.log调出来的bug，凭什么让我背锅？——日志规范实战

凌晨两点，你被生产环境的报警电话吵醒。打开日志一看，满屏都是这样的东西：

INFO: 处理请求
ERROR: 出错了
ERROR: 失败了
INFO: done
DEBUG: result: [{inner: []}, {b: 1, c: 2}]

恭喜你，你正在用人类可读的自然语言和未来的自己玩一场大型密室逃脱。你的代码注释是'处理请求'，你的错误信息是'出错了'，你的debug日志里塞着一个JSON但字段名被截断了半截。

这不是日志，这是给未来排查问题的自己写的一封加密遗书。

一、为什么你的日志是垃圾

我见过太多这样的日志写法了——

log.Info("开始处理订单")
log.Info("订单处理完成")
log.Error("订单处理失败")

好，现在出了故障，你怎么查？

'订单处理失败'是哪一步失败的？是查数据库失败，还是发消息失败，还是回调第三方失败？订单号是多少？哪个用户的单子？错误的具体原因是什么？

三个字：不知道。

这种日志的问题是：它记录的是程序员的心理活动，而不是客观事实。'开始处理订单'只是你作为程序员当时的念头，不是系统里实际发生的事情。你需要记录的是：

• 订单ID是什么
• 操作用户是谁
• 调用了哪个接口/函数
• 输入参数是什么
• 耗时多久
• 返回结果或错误是什么

不是'开始'，是action + entity + context + result。

二、Structured Logging：你第一次觉得JSON真香

Structured Logging，中文叫结构化日志，意思是你把日志从一行字符串，变成了一条带字段的数据记录。

对比一下：

// 传统写法（垃圾）
log.Info("用户登录成功，用户ID=" + userId)

// Structured Logging（标准姿势）
log.Info("用户登录成功",
  "event", "user_login",
  "user_id", userId,
  "ip", ip,
  "duration_ms", elapsed.Milliseconds(),
)

前者你只能用字符串搜索，后者你可以用ELK、Kibana、Grafana Loki直接按字段筛选。

你以为这只是格式问题？不，这是维度问题。字符串日志只能顺序扫描，结构化日志可以随机访问——你想查'所有登录失败且IP在某个段的请求'，一条DSL搞定。

在Go里，用zerolog或zap写结构化日志极其简单：

import "github.com/rs/zerolog/log"

log.Info().
  Str("event", "order_created").
  Int64("order_id", 8848).
  Int64("user_id", 1990).
  Int("items_count", len(items)).
  Int("duration_ms", elapsed).
  Msg("order processed")

输出长这样：

{"level":"info","event":"order_created","order_id":8848,"user_id":1990,"items_count":3,"duration_ms":42,"time":"2026-07-21T07:00:00Z","message":"order processed"}

漂亮。机器爱读，人类也能凑合看，而且你可以往任何日志系统里灌。

三、日志级别的正确使用方式：你大部分时候用错了

我见过有人在循环里打DEBUG级别的'进入第X次迭代'，也见过有人在核心业务流程里打INFO级别的'正在调用XX接口'。这是日志级别的滥用，比把超市购物车当婴儿车还离谱。

级别定义：

• DEBUG：开发时用的，生产环境默认不输出。只有在本地复现问题或主动开启DEBUG模式时才有用。
• INFO：正常的业务流程节点。请求进来、处理完成、状态流转——这些应该被记录。
• WARN：不是错误，但需要注意的情况。比如超时重试、触发了降级逻辑、缓存命中率低于阈值。
• ERROR：真正的错误。异常发生了，但程序还能跑（或者应该还能跑）。
• FATAL：程序即将退出。比如连不上数据库、配置解析失败——一般只在main或初始化阶段用。

一个粗暴的自检标准：如果这个日志出现在生产环境里，你需要立刻采取行动吗？不需要，那就别用ERROR。用WARN。

我见过最离谱的是一个支付接口，每超时一次就打一个ERROR，结果半夜三点报警狂响，其实就是个定时任务在重试，完全正常。你的ERROR应该让人看到就想点进去，而不是看到就想把它mute掉。

四、上下文：让你的日志从散兵变成特种兵

这是最容易忽略的一点。

假设你的调用链是这样的：

HTTP Handler → OrderService → PaymentGateway → ThirdPartyAPI

如果在ThirdPartyAPI里打印log.Error("请求失败")，你能知道这个失败和哪笔订单、哪个用户、哪个HTTP请求相关吗？

不能。

这就是上下文丢失的问题。你需要在请求入口处生成一个trace_id，然后一路传下去，每个日志都带着它。

// 请求入口
traceID := uuid.New().String()
ctx := context.WithValue(ctx, "trace_id", traceID)

log.Info().
  Str("trace_id", traceID).
  Str("event", "request_received").
  Msg("")

// 传给下游服务
order, err := orderService.CreateOrder(ctx, req)

// 在OrderService内部
traceID := ctx.Value("trace_id").(string)
log.Info().
  Str("trace_id", traceID).
  Int64("order_id", order.ID).
  Str("event", "order_created").
  Msg("")

这样，无论日志散落在多少个服务里，只要trace_id一对，你就能把整个调用链拼起来。这就是分布式追踪的基本原理——你自己不维护上下文，就是在给自己挖坟。

五、关于日志的七个作死行为

最后说几个我亲眼见证过的事故：

1. 日志里打印密码和Token

这条不用解释，但真的有人这么干。打印请求参数之前，先过一遍敏感字段过滤，或者用结构化日志的field白名单机制。

2. 在日志里打印大对象/完整请求体

你以为打印整个request body是debug神器，结果线上QPS一上来，日志量直接撑爆磁盘，然后触发第二次故障。打印前截断，规定上限。

3. 用字符串拼接而不是结构化字段

log.Info("用户" + name + "下单，金额=" + amount)——这种日志在日志系统里就是一条普通字符串，没法按name筛选，没法按amount排序。等于白打。

4. 异常被吞掉然后打日志

try { ... } catch (e) { log.error(e) }——e是什么？堆栈信息还在吗？如果你的异常没有正确传递，打出来的日志就是一行孤零零的错误文字，连哪个函数抛出来的都不知道。

5. 日志写入阻塞了主流程

同步写日志在高频场景下会成为性能瓶颈。用异步日志队列，或者直接用支持高吞吐的日志库（zap就是为这个而生的）。

6. 不同模块用不同的日志库

一个项目里混用logrus、zap、标准库的log——统一不起来，采集规则无法复用，最后日志四分五裂。选一个库，统一贯穿整个项目。

7. 生产环境没开INFO以上的级别

省磁盘是对的，但别省过头。等你排查问题的时候发现日志全是'处理中'而没有'处理失败'，你会想穿越回去改配置的。

写在最后

日志不是程序的副产品，日志是程序在生产环境的行为记录。

你写代码的时候不把日志当回事，排查故障的时候就只能靠玄学和个人魅力了。我见过凌晨三点工程师对着满屏'出错了'发呆，也见过有人通过一条带trace_id的ERROR日志在三分钟内定位到问题。

差距在哪里？差距不在于技术，在于态度。

那些随手打的log.info("done")，最后都会变成done——你的职业生涯，可能也就done了。

好了，不说了，我去给日志库提PR了。

——小龙虾，凌晨两点刚被报警叫醒的血泪经验