日志基础：日志的作用、常见日志格式与日志级别
核心原理：日志为什么是吞吐瓶颈定位的第一现场
在分布式系统或单机高并发服务的日常运维中，日志是唯一能够完整记录“系统在某个时间点到底发生了什么”的客观数据源。指标（Metrics）只能告诉你“CPU 使用率 95%”或“P99 延迟 200ms”，但无法告诉你是哪一个请求、哪一条 SQL、哪一个上游调用导致了这次延迟飙升。而日志恰恰能回答这些“为什么”的问题。
从吞吐瓶颈定位的角度看，日志的价值体现在三个层面：
- 还原请求链路：通过 requestId 或 traceId，将分散在不同服务节点上的日志片段串联成一条完整的调用链，从而定位瓶颈发生在入口网关、业务逻辑、数据库还是外部依赖。
- 量化耗时分布：如果每条日志都记录了阶段耗时（如 DB 查询耗时、下游 HTTP 调用耗时），就可以通过聚合分析找出耗时占比最高的环节。
- 发现异常模式：超时、重试、连接池耗尽、线程池拒绝等异常日志往往以特定频率出现，这些频率变化本身就是吞吐下降的前兆信号。
常见日志格式：文本日志与 JSON 日志
日志格式决定了后续解析和检索的难易程度。目前生产环境中最常见的两类格式是非结构化文本日志和结构化 JSON 日志。下面通过一个实际请求的日志对比来说明两者的差异。
1. 非结构化文本日志（传统格式）
2025-03-21 14:23:45.678 INFO [http-nio-8080-exec-7] c.t.mall.OrderService : 订单创建成功 orderId=123456 userId=8899 cost=156ms这种格式的优点是人类可读性好，grep 时直观；缺点是字段没有明确边界，当需要按 orderId 或 cost 做聚合统计时，必须依赖正则表达式提取，解析效率低且容易出错。当日志量达到每秒数万条时，正则解析会成为采集端的性能瓶颈。
2. 结构化 JSON 日志（推荐）
{"timestamp":"2025-03-21T14:23:45.678+08:00","level":"INFO","thread":"http-nio-8080-exec-7","logger":"com.trade.mall.OrderService","message":"订单创建成功","orderId":123456,"userId":8899,"costMs":156,"skuCount":3}JSON 日志的每个字段都有明确的 key，采集端（如 Filebeat、Fluentd）可以直接将字段映射到 Elasticsearch 或 ClickHouse 的列中，后续查询时无需正则提取，性能提升一个数量级。更重要的是，JSON 格式天然支持嵌套结构，可以表达“请求参数”“响应状态”“耗时明细”等复杂对象。
| 对比维度 | 文本日志 | JSON 日志 |
|---|---|---|
| 可读性 | 高（人眼友好） | 中（需要格式化工具） |
| 解析性能 | 低（正则提取开销大） | 高（字段直接映射） |
| 字段扩展性 | 差（追加字段需修改正则） | 好（新增 key 不影响旧数据） |
| 适合场景 | 本地调试、小规模系统 | 大规模日志采集、集中式分析 |
key=value 形式追加在日志末尾，便于后续用 grok 或正则提取。
日志级别：从 DEBUG 到 FATAL 的分级管理
日志级别不仅是日志框架（Logback、Log4j2）的配置项，更是吞吐瓶颈定位时的“筛选器”。如果所有级别的日志都输出，磁盘 I/O 和采集带宽会被无意义的信息淹没，反而掩盖了真正重要的信号。
标准级别从低到高依次为：
- TRACE：最细粒度的跟踪信息，通常只在开发环境开启，用于追踪方法入口、参数值等。
- DEBUG：调试信息，记录关键变量的中间值、分支判断结果。生产环境默认关闭。
- INFO：重要的业务事件，如订单创建、支付回调、用户登录。生产环境通常开启此级别。
- WARN：潜在风险但不影响当前请求完成，如重试第一次失败、缓存穿透、慢查询超过阈值。
- ERROR：当前请求或任务失败，但系统整体仍可运行，如数据库连接超时、下游返回 500。
- FATAL：致命错误，导致服务无法继续提供能力，如 OOM、配置加载失败、端口被占用。
在吞吐瓶颈定位中，WARN 级别往往比 ERROR 级别更有价值。因为 ERROR 通常意味着请求直接失败，而 WARN 意味着请求“勉强成功但付出了额外代价”——例如第一次连接超时后重试成功，这个重试过程会额外占用线程和网络资源，大量 WARN 的出现往往是吞吐下降的前兆。
# Logback 配置示例：生产环境建议级别
<logger name="com.trade.mall" level="INFO"/>
<logger name="com.trade.mall.dao" level="WARN"/> <!-- DAO 层只记录警告以上 -->
<logger name="org.springframework.web" level="WARN"/>案例场景：一次“假死”背后的日志级别陷阱
某电商系统在促销期间出现订单接口吞吐量从 3000 QPS 骤降到 800 QPS，但 CPU 和内存指标均正常。初步排查时，运维人员将日志级别临时调整为 DEBUG 以获取更多信息，结果发现吞吐量进一步下降到 400 QPS。
通过分析日志采集端的监控，发现日志采集器（Filebeat）的 CPU 使用率从 15% 飙升到 70%。进一步检查日志内容后发现，DEBUG 级别下每条请求会输出约 20 条日志，其中包含 SQL 参数、HTTP Header 等大量冗余信息。日志采集器需要对这些文本进行正则解析和 JSON 序列化，导致采集端成为新的瓶颈。
复盘后的改进措施如下：
- 将日志级别恢复为 INFO，仅对
OrderService和PaymentClient两个类开启 DEBUG，缩小排查范围。 - 在日志中增加
costMs字段，记录各阶段耗时，通过聚合分析发现 70% 的请求耗时集中在数据库查询阶段。 - 将数据库慢查询日志（超过 200ms）单独输出到独立文件，避免与业务日志混在一起。
最终定位到瓶颈是数据库连接池最大连接数设置过小，导致大量线程在等待获取连接。这个结论正是通过分析 WARN 级别的“获取连接等待超过 100ms”日志得出的——如果当时日志级别被 DEBUG 刷屏，这些关键 WARN 日志会被淹没在大量无意义信息中。
误区与复盘：日志管理中的四个常见错误
- 误区一：日志越详细越好。实际上，日志量过大会导致采集、传输、存储全链路性能下降。每增加一条 DEBUG 日志，意味着采集端多一次 I/O 和序列化操作。建议单请求日志量控制在 10 条以内。
- 误区二：所有服务使用相同的日志级别。核心交易链路和边缘服务应该区别对待。核心链路建议 INFO 起步，边缘服务可以放宽到 DEBUG，但必须设置采样率。
- 误区三：日志格式随意变更。如果从文本格式切换到 JSON 格式，需要确保采集端解析规则同步更新，否则会出现日志“写入成功但无法检索”的尴尬局面。建议先在测试环境验证解析链路。
- 误区四：忽略 WARN 级别的价值。很多团队只关注 ERROR，但 WARN 中往往隐藏着“连接池等待”“重试成功”“缓存穿透”等吞吐瓶颈的前兆信号。建议为 WARN 日志单独建立监控告警。