日志打爆磁盘:一次 error.log 涨到 388G 的周末宕机复盘

2024 年某个周末凌晨,我们的核心服务集体宕机。值班同学爬起来一看,所有实例报的都是同一个错:"No space left on device" —— 磁盘被写满了。再一查,罪魁祸首是日志:一个 ERROR 日志在异常风暴里疯狂打印,几个小时就把几百 G 的磁盘灌满,服务连日志都写不进去,直接崩了。投了几天做日志治理,本文复盘这次"日志打爆磁盘"的完整实战。

问题背景

业务:核心交易服务,Logback + 本地磁盘日志,12 实例
事故现象:
- 凌晨 02:40 起,服务陆续不可用
- 报错:java.io.IOException: No space left on device
- 监控显示磁盘从 60% 在 3 小时内冲到 100%

现场排查:
# 1. 登上去看磁盘
$ df -h
Filesystem      Size  Used Avail Use%  Mounted on
/dev/vda1       500G  500G    0  100%  /

# 2. 找谁占的
$ du -sh /www/wwwroot/app/logs/*
388G  /www/wwwroot/app/logs/error.log     <- 单个文件 388G!
12G   /www/wwwroot/app/logs/app.log

# 3. 看 error.log 在打什么
$ tail -100 error.log
  [ERROR] call inventory-service failed
  java.net.SocketTimeoutException: ...
     ... 完整堆栈 30 行 ...
# 同一个异常,每秒打了上千次,每次还带完整堆栈

根因:
1. 凌晨库存服务抖动,大量 RPC 超时,每次失败打一条 ERROR
2. 异常风暴下,ERROR 日志每秒上千条,每条带 30 行堆栈
3. error.log 没有任何大小上限,没有滚动删除,无限增长
4. 日志是同步写,磁盘 IO 被打满,反过来又拖慢业务
5. 没有任何磁盘使用率告警,等发现时已经 100%

修复 1:日志滚动与总量上限

<!-- === 出事的旧配置:只按天滚动,没有总量上限 === -->
<!-- 
       error.%d{yyyy-MM-dd}.log
     
     问题:按天滚动,但一天之内可以无限大;
           没配 maxHistory / totalSizeCap,旧文件永不删除 -->

<!-- === 正确:按时间 + 大小双滚动,且设总量上限 === -->
<appender name="ERROR_FILE"
          class="ch.qos.logback.core.rolling.RollingFileAppender">
    <file>logs/error.log</file>
    <rollingPolicy
        class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
        <fileNamePattern>logs/error.%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern>
        <!-- 单个文件超 200MB 就滚动一个新的 -->
        <maxFileSize>200MB</maxFileSize>
        <!-- 最多保留 15 天 -->
        <maxHistory>15</maxHistory>
        <!-- 关键:所有归档文件总大小上限 10GB,超了自动删最老的 -->
        <totalSizeCap>10GB</totalSizeCap>
    </rollingPolicy>
    <encoder>
        <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger - %msg%n</pattern>
    </encoder>
</appender>
<!-- 三道保险:单文件 maxFileSize、保留天数 maxHistory、
     总量 totalSizeCap。totalSizeCap 是最后一道,
     无论日志怎么暴涨,磁盘占用都有硬上限。
     文件名带 .gz,归档自动压缩,体积再降一个量级。-->

修复 2:异步日志,别让日志拖垮业务

<!-- === 同步日志的问题:写日志 = 业务线程直接做磁盘 IO === -->
<!-- 磁盘 IO 被打满时,业务线程卡在写日志上,接口跟着变慢 -->

<!-- === 用 AsyncAppender 把写日志丢给独立线程 === -->
<appender name="ASYNC_ERROR" class="ch.qos.logback.classic.AsyncAppender">
    <!-- 队列容量:业务线程把日志塞进队列就返回,不等磁盘 -->
    <queueSize>2048</queueSize>

    <!-- 关键:队列满了的策略 -->
    <!-- discardingThreshold=0 表示队列满时一条都不丢(默认会丢 INFO/DEBUG) -->
    <!-- 这里设 0:宁可阻塞也不丢 ERROR;若可容忍丢日志可设大些 -->
    <discardingThreshold>0</discardingThreshold>

    <!-- neverBlock=true:队列满时直接丢弃,绝不阻塞业务线程 -->
    <!-- 核心交易链路建议 true:日志可以丢,业务不能卡 -->
    <neverBlock>true</neverBlock>

    <appender-ref ref="ERROR_FILE"/>
</appender>
<!-- 取舍:
     neverBlock=true  -> 极端情况丢日志,但业务绝不被日志拖慢(推荐)
     neverBlock=false -> 不丢日志,但磁盘慢时业务线程会被阻塞
     核心服务选前者:日志是为了排障,不该成为压垮服务的最后一根稻草。-->

修复 3:控制异常风暴的日志量

// === 根因之一:同一个异常每秒打上千次,每次带完整堆栈 ===
// 异常风暴时,真正有用的信息就那么几条,后面全是重复噪音。

// === 方案 1:日志限流 —— 同类日志每秒最多打几条 ===
public class RpcClient {
    // 一个简单的滑动窗口限流器
    private final RateLimiter logLimiter = RateLimiter.create(5.0); // 每秒 5 条

    public Result call(Request req) {
        try {
            return doCall(req);
        } catch (Exception e) {
            // 限流:拿到令牌才打详细日志,否则只计数
            if (logLimiter.tryAcquire()) {
                log.error("call inventory-service failed, req={}", req, e);
            } else {
                errorCounter.increment();   // 没打日志,但计数不丢
            }
            throw e;
        }
    }
}
// 异常风暴下,日志从"每秒上千条"降到"每秒 5 条",
// 既保留了样本,又不会把磁盘冲垮;真实失败量靠 metrics 计数体现。

// === 方案 2:堆栈别重复打,异常摘要化 ===
catch (SocketTimeoutException e) {
    // 错误:e 整个堆栈打出来,30 行
    // log.error("rpc failed", e);
    // 改进:同一类异常,堆栈打一次就够,后续只打摘要
    log.error("rpc failed: {} - {}", e.getClass().getSimpleName(),
              e.getMessage());      // 一行,不带堆栈
}

// === 方案 3:Logback 自带的重复日志过滤器 ===
// 
//   5   
//   200
// 
// 完全相同的日志消息,超过 5 次后自动丢弃,天然防刷屏。

修复 4:日志级别与内容规范

// === 级别用错是日志暴涨的常见原因 ===

// 反例 1:把业务正常分支当 ERROR 打
if (user.getCoupon() == null) {
    log.error("用户没有优惠券");   // 错!没券是正常情况,不该 ERROR
}
// 没券是正常业务分支,要么 debug,要么干脆不打。
// ERROR 应该只留给"真正需要人介入排查"的问题。

// 反例 2:循环里逐条打日志
for (Order order : orders) {        // orders 可能上万条
    log.info("处理订单 {}", order.getId());   // 一次请求打上万条 INFO
}
// 改成:循环外打汇总
log.info("开始处理 {} 笔订单", orders.size());
// ... 循环 ...
log.info("处理完成,成功 {} 失败 {}", successCount, failCount);

// === 日志级别的正确划分 ===
// ERROR : 系统错误,需要人介入(DB 连不上、关键流程异常)
// WARN  : 可恢复的异常、降级、重试(单次 RPC 失败但有重试)
// INFO  : 关键业务节点(订单创建成功、支付完成)—— 适度
// DEBUG : 排查问题用的详细信息,生产默认关闭

// === 生产环境的级别配置 ===
// 生产默认 INFO,第三方库("org.apache""com.netflix")压到 WARN,
// 它们的 INFO 日志往往是纯噪音,占了日志量的大头。
// logging.level.root=INFO
// logging.level.org.apache=WARN

修复 5:应急处理 —— 磁盘已满怎么办

# === 磁盘 100% 时的应急步骤(线上救火)===

# 1. 先找出大文件,确认是不是日志
$ du -sh /www/wwwroot/app/logs/* | sort -rh | head

# 2. 【不要】直接 rm 正在被写入的日志文件!
#    rm 后进程仍持有文件句柄,空间不会真正释放,
#    要等进程关闭句柄。正确做法是"清空"而非"删除":
$ : > /www/wwwroot/app/logs/error.log     # 清空文件,句柄还在,空间立即释放
# 或者
$ truncate -s 0 /www/wwwroot/app/logs/error.log

# 3. 如果必须删历史归档(已滚动、没人写的),可以直接删
$ find /www/wwwroot/app/logs/ -name "error.*.log.gz" -mtime +3 -delete

# 4. 确认空间释放
$ df -h

# 5. 空间腾出后,服务能恢复写日志,多数会自愈;
#    若进程已假死,再重启

# === 兜底:把日志单独挂一块盘,别和系统盘 / 数据盘混 ===
# 日志写爆了,最多日志盘满,不会拖垮系统盘和数据库
# /dev/vdb1  ->  /www/wwwroot/app/logs   (独立日志盘)

# === 定时清理兜底脚本(防御性,配合 logback 总量上限双保险)===
# crontab: 每小时检查,日志目录超 20G 就删最老的归档
$ cat /opt/scripts/clean_log.sh
#!/bin/bash
LOG_DIR=/www/wwwroot/app/logs
SIZE=$(du -s $LOG_DIR | awk '{print $1}')
if [ $SIZE -gt 20971520 ]; then     # 20GB(KB)
    find $LOG_DIR -name "*.log.gz" -mtime +1 -delete
fi

修复 6:监控告警

# 这次事故最痛的点:磁盘 3 小时冲到 100% 竟然没有任何告警
groups:
- name: disk-and-log
  rules:
  # 1. 磁盘使用率(分级告警,留出处理时间)
  - alert: DiskUsageWarning
    expr: |
      (1 - node_filesystem_avail_bytes / node_filesystem_size_bytes) > 0.80
    for: 5m
    annotations:
      summary: "{{ $labels.instance }} 磁盘 {{ $labels.mountpoint }} > 80%"

  - alert: DiskUsageCritical
    expr: |
      (1 - node_filesystem_avail_bytes / node_filesystem_size_bytes) > 0.90
    for: 2m
    annotations:
      summary: "{{ $labels.instance }} 磁盘 > 90%,紧急处理"

  # 2. 磁盘增长速率(比绝对值更早预警 —— 突然猛涨)
  - alert: DiskFillingFast
    expr: predict_linear(node_filesystem_avail_bytes[1h], 4*3600) < 0
    for: 10m
    annotations:
      summary: "{{ $labels.instance }} 磁盘按当前速率 4 小时内将写满"

  # 3. ERROR 日志速率突增(异常风暴的早期信号)
  - alert: ErrorLogSurge
    expr: increase(logback_events_total{level="error"}[5m]) > 1000
    for: 3m
    annotations:
      summary: "{{ $labels.app }} 5 分钟 ERROR 日志超 1000 条,排查异常风暴"

优化效果

指标                      治理前              治理后
=============================================================
磁盘被写满事故            周末凌晨集体宕机     0
日志总量上限              无(无限增长)       totalSizeCap 10GB 硬上限
单个日志文件最大          388GB               200MB(滚动)
归档保留                  永不删除             15 天 + 总量封顶
归档压缩                  无                   .gz 压缩
日志写入方式              同步(拖垮业务)     异步 + neverBlock
异常风暴日志量            每秒上千条           限流后每秒 5 条
磁盘告警                  完全没有             80%/90%/增速三级告警
日志独立磁盘              与系统盘混用         独立日志盘

事故复盘后改造:
- 应急清空日志 + 服务恢复:0.5 小时
- Logback 滚动 + 总量上限 + 异步化:1 天
- 异常日志限流 + 重复过滤:1 天
- 日志级别全面梳理(去掉噪音 INFO/ERROR):1 天
- 磁盘 + ERROR 速率监控接入:0.5 天

避坑清单

1. 日志文件必须配总量上限 totalSizeCap,这是磁盘占用的最后一道硬保险
2. 滚动策略用按大小+时间双触发,单文件 maxFileSize、保留 maxHistory 都要配
3. 归档文件名带 .gz 自动压缩,体积能再降一个量级
4. 核心服务用异步日志 AsyncAppender,neverBlock=true,宁可丢日志不卡业务
5. 异常风暴下同类日志要限流,每秒几条留样本即可,真实量靠 metrics 计数
6. 同一个异常的完整堆栈打一次就够,后续只打一行摘要
7. 日志级别别用错:没券、查无数据这类正常分支绝不该打 ERROR
8. 不要在循环里逐条打日志,改成循环外打汇总
9. 磁盘满时用 truncate/: > 清空文件,不要 rm 正在写入的文件(空间不释放)
10. 磁盘使用率、磁盘增长速率、ERROR 日志速率都要上告警,留足处理时间

总结

这次"日志打爆磁盘"的事故,起因小得有点荒谬 —— 不过是凌晨依赖的库存服务抖了一下,但它最终演变成核心服务集体宕机,根子上暴露的是我们对日志这件事的全面失控。复盘下来,最深的一个体会是:日志是用来排查问题的辅助手段,但如果它本身没有任何约束,就会从"帮手"变成"杀手"。我们的 error.log 单个文件涨到了 388G,原因简单到不该发生 —— 滚动策略只按天切分,而一天之内文件可以无限大,又没有配任何总量上限,旧文件永远不删,等于给了日志一张可以无限消耗磁盘的空白支票。所以治理的第一条铁律就是:日志必须有总量上限,Logback 的 totalSizeCap 是最后一道硬保险,无论日志怎么暴涨,磁盘占用都被钉死在一个上限内。第二个深刻的认知是关于日志和业务的关系 —— 我们原来用的是同步日志,意味着业务线程要亲自去做磁盘 IO,当磁盘被日志打满、IO 变慢时,业务线程就卡在写日志上,日志反过来拖垮了业务,这是一种很荒诞的因果。正确的做法是异步日志,而且对核心交易链路要果断设置 neverBlock,宁可在极端情况下丢掉一些日志,也绝不能让写日志这件事阻塞业务 —— 要时刻记得日志是配角,业务才是主角。第三点是要正视"异常风暴"这个场景:当依赖服务大面积故障时,失败是成片成片发生的,如果每一次失败都老老实实打一条带三十行完整堆栈的 ERROR,日志量瞬间就是平时的成百上千倍,所以同类日志必须限流,留几条样本足矣,真实的失败规模交给监控指标去计数。还有大量日志暴涨其实源于级别用错和习惯不好——把"用户没有优惠券"这种正常业务分支打成 ERROR、在动辄上万条的循环里逐条打 INFO,这些都要靠规范和评审去掐掉。但所有这些技术改造里,最让我后怕的其实是那个"3 小时磁盘从 60% 冲到 100%、全程没有一条告警"的事实 —— 如果当时有一条磁盘使用率告警、哪怕只是一条 ERROR 日志速率突增的告警,值班同学就能在凌晨两点多就介入,而不是等服务全部宕机才被惊醒。可观测性不是锦上添花,它是把"凌晨的灾难"变成"白天的一个小工单"的关键。

—— 别看了 · 2026