目录

Linux-20 线上问题排查实战案例

前置阅读:Linux-18 性能分析工具链与方法论

前面 19 篇讲的是原理和工具,这一篇把它们用起来——八个真实故障的完整排查过程,每个案例都按「现象 → 排查 → 原因 → 修复 → 验证 → 结果 → 规律」的顺序展开。

重点不是记住这八个案例本身,而是每个案例末尾的「规律」——那是可以迁移到其他场景的判断依据。

0. 按症状索引

先给一张速查表。线上出问题时从这里开始,找到最接近的症状,跳到对应章节。

症状 最可能的方向 第一条命令 案例
CPU 使用率 100% 业务代码 / GC / 正则回溯 top -H -p PID §1
内存持续增长不释放 堆内泄漏 / 堆外泄漏 / 连接泄漏 /proc/PID/smaps_rollup §2
load 很高但 CPU 空闲 磁盘 IO / D 状态进程 vmstat 1bwa §3
磁盘满但 du 对不上 已删除未释放 / 挂载点遮盖 lsof +L1 §4
Too many open files fd 泄漏 / limit 没生效 ls /proc/PID/fd | wc -l §5
大量 TIME_WAIT / 端口耗尽 短连接 / 没用连接池 ss -s §6
服务启动失败 / 起不来 配置 / 权限 / 依赖 / 端口占用 journalctl -u xxx -n 50 §7
容器反复重启 OOMKilled / 探针失败 kubectl describe pod §8
接口变慢但资源都不高 锁竞争 / 下游依赖 / CPU 限流 pidstat -wcpu.stat §1§8

通用的第一步永远是这三条(第 18 篇的 60 秒定位法):

uptime                        # 负载趋势
dmesg -T | tail -20           # 先排除 OOM、磁盘错误、网卡重置
vmstat 1 5                    # 全局定位到 CPU / 内存 / IO 哪一类

1. 案例一:CPU 打满但业务量没变

现象:8 核机器,订单服务 CPU 从平时的 35% 涨到 780%(接近满载),但 QPS 和上游流量没有任何变化。接口 P99 从 80ms 涨到 1.2s。

1.1 排查

# ① 确认是哪个进程
ps -eo pid,pcpu,pmem,nlwp,stat,etime,args --sort=-pcpu | head -5
#   PID %CPU %MEM NLWP STAT  ELAPSED COMMAND
#  1234 780.0 12.3  128 Sl   3-04:22 java -jar order-service.jar
#       ^^^^^ 780% = 占了 7.8 个核        ^^^ 128 个线程
# ② 区分用户态和内核态 —— 这一步决定后面往哪个方向查
pidstat -u 1 3 -p 1234
# 时间      UID  PID   %usr %system  %CPU  CPU  Command
# 14:32:01    0 1234 762.00   18.00 780.00   3  java
#                    ^^^^^^ 用户态占了 762%,内核态只有 18%

关键判断%usr 远高于 %system,说明是业务代码在疯狂计算,不是系统调用或上下文切换的问题(第 7 篇的判读规则)。这个方向下 strace 帮不上忙,要用 profiler。

# ③ 定位到具体线程
ps -Lo pid,lwp,pcpu,comm -p 1234 --sort=-pcpu | head -8
#   PID   LWP %CPU COMMAND
#  1234  1567 98.2 java
#  1234  1568 97.9 java
#  1234  1569 97.4 java
#  1234  1570 96.8 java
#  1234  1571 96.2 java
#  1234  1572 95.9 java
#  1234  1573 95.1 java
#  1234  1574 94.8 java
#        ^^^^ 八个线程各占满一个核
# ④ Java:把 LWP 转成十六进制,去 jstack 里找
for lwp in 1567 1568 1569; do printf "0x%x\n" $lwp; done
# 0x61f
# 0x620
# 0x621

jstack 1234 > /tmp/stack.txt
grep -A 15 'nid=0x61f' /tmp/stack.txt
# "http-nio-8080-exec-42" #142 daemon prio=5 os_prio=0 tid=0x... nid=0x61f runnable
#    java.lang.Thread.State: RUNNABLE
#         at java.util.regex.Pattern$Loop.match(Pattern.java:4795)
#         at java.util.regex.Pattern$GroupTail.match(Pattern.java:4717)
#         at java.util.regex.Pattern$Loop.match(Pattern.java:4795)
#         at java.util.regex.Pattern$GroupTail.match(Pattern.java:4717)
#         ...(大量重复的 Pattern$Loop.match)
#         at com.example.order.AddressParser.parse(AddressParser.java:38)

八个线程的栈几乎一模一样,全部卡在 Pattern$Loop.match 的深度递归里 —— 这是**正则表达式灾难性回溯(catastrophic backtracking)**的典型特征。

# ⑤ 用 perf 交叉验证(不依赖语言运行时)
perf top -p 1234
# Overhead  Shared Object   Symbol
#   68.23%  libjvm.so       [.] Pattern$Loop::match
#   12.01%  libjvm.so       [.] ...
#           ^^^^^^^^^^^^^^^^ 确认 68% 的 CPU 花在正则匹配上
# ⑥ 找出触发的输入
grep "AddressParser" /var/log/order/app.log | tail -5
# 14:20:33 INFO parsing address: 北京市朝阳区xxx路xxx号xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx...
#                                                              ^^^^ 超长地址

1.2 原因

代码里的地址解析正则是:

// AddressParser.java:38
private static final Pattern P = Pattern.compile("^(\\s*\\w+\\s*)+$");
//                                                  ^^^^^^^^^^^^^ 嵌套量词

(\s*\w+\s*)+ 这种嵌套量词结构,在遇到不匹配的长字符串时,正则引擎需要尝试的路径数是指数级的。一个 30 字符的不匹配输入就能让单次匹配跑几十秒。

输入长度   尝试路径数
  10        约 1000
  20        约 100 万
  30        约 10 亿          <- 单线程跑满一个核几十秒

触发条件:某个渠道开始上报超长的地址字段(30+ 字符且含特殊符号),每个请求都触发一次灾难性回溯,8 个 worker 线程全部卡住。

1.3 修复

// ❌ 原来的写法:嵌套量词
private static final Pattern P = Pattern.compile("^(\\s*\\w+\\s*)+$");

// ✅ 方案一:消除嵌套量词
private static final Pattern P = Pattern.compile("^[\\s\\w]+$");

// ✅ 方案二:用占有量词(possessive quantifier)禁止回溯
private static final Pattern P = Pattern.compile("^(\\s*+\\w++\\s*+)++$");
//                                                     ^ + 后缀表示占有量词

// ✅ 方案三:加长度上限做兜底(防御性)
if (address.length() > 200) {
    throw new IllegalArgumentException("地址过长");
}

同时加超时保护,防止未来出现同类问题:

// 用 CharSequence 包装,在匹配过程中检测中断
public class TimeoutCharSequence implements CharSequence {
    private final CharSequence inner;
    private final long deadline;
    public char charAt(int index) {
        if (System.currentTimeMillis() > deadline) {
            throw new RuntimeException("regex timeout");
        }
        return inner.charAt(index);
    }
    // ... 其他方法委托给 inner
}
// Go 的正则引擎(RE2)没有这个问题 —— 它保证线性时间,
// 代价是不支持反向引用和前后查找
// 所以 Go 服务基本不会遇到灾难性回溯

1.4 验证

# 部署后观察
pidstat -u 1 5 -p $(pgrep -f order-service)
# 14:52:01    0 5678  42.00    8.00  50.00  3  java
#                    ^^^^^ 从 762% 降到 42%

# 确认没有线程再卡在正则上
jstack $(pgrep -f order-service) | grep -c "Pattern\$Loop"
# 0

1.5 结果

CPU 从 780% 降到 50%,P99 从 1.2s 回到 75ms。

1.6 规律

规律:CPU 高先分 %usr%system——%usr 高查业务代码(用 profiler / jstack / perf),%system 高查系统调用(用 strace -c)。

规律:多个线程的调用栈几乎一致,说明它们卡在同一段代码上,这是最容易定位的一类问题。

正则灾难性回溯的识别特征

  • 栈里出现大量重复的 Pattern$Loop.match / regexec
  • CPU 100% 但没有任何 IO
  • 只对特定输入触发,正常输入毫秒级返回
  • 含嵌套量词 (a+)+(a*)*(a|a)* 的正则是高危模式

预防:Java/Python/JS 用的是回溯式正则引擎,都有这个风险;Go 和 Rust 的 RE2 引擎保证线性时间,天然免疫。对外部输入做正则匹配时,一律加长度上限。


2. 案例二:内存持续增长最终 OOM

现象:一个 Go 编写的消息处理服务,上线后内存缓慢增长,3 天从 500MB 涨到 3.5GB,最终被 OOM Killer 杀掉重启,然后循环往复。

2.1 排查

# ① 确认是真实占用还是缓存假象
grep -E "^(Rss|Pss|Private_Dirty|Swap):" /proc/$(pgrep msgproc)/smaps_rollup
# Rss:             3512340 kB
# Pss:             3498120 kB
# Private_Dirty:   3489200 kB      <- 几乎全是【进程独占的脏页】
# Swap:                  0 kB

Private_Dirty 占了 99% 说明这是真实的内存泄漏,不是 page cache 或共享库的统计假象(第 10 篇 §6)。

# ② 连续采样看增长趋势
for i in $(seq 1 10); do
    printf "%s  RSS=%s kB\n" "$(date +%H:%M:%S)" \
        "$(awk '/^VmRSS/{print $2}' /proc/$(pgrep msgproc)/status)"
    sleep 300
done
# 14:00:01  RSS=2134520 kB
# 14:05:01  RSS=2156880 kB
# 14:10:01  RSS=2178340 kB
#                          <- 每 5 分钟涨约 22MB,线性增长

线性增长而非阶梯式,说明是持续的、与请求量相关的泄漏。

# ③ 区分:泄漏在 Go 堆内还是堆外
curl -s localhost:6060/debug/pprof/heap?debug=1 | head -25
# heap profile: 8234: 234567890 [1203401: 89234567890] @ heap/1048576
# # runtime.MemStats
# # Alloc = 234567890          <- 堆上存活对象 234MB
# # Sys = 3612345678           <- runtime 向 OS 申请的总量 3.6GB
# # HeapAlloc = 234567890
# # HeapSys = 512345678        <- 堆占用的虚拟内存 512MB
# # HeapReleased = 0
# # StackSys = 2952790016      <- 【栈占了 2.9GB!】
# # NumGoroutine = 1203401     <- 【120 万个 goroutine!】

关键发现HeapAlloc 只有 234MB,但 StackSys 高达 2.9GB,NumGoroutine120 万

这不是传统意义的内存泄漏,是 goroutine 泄漏——每个 goroutine 至少占 2KB 栈(第 12 篇),120 万 × 2.4KB ≈ 2.9GB。

# ④ 看 goroutine 都卡在哪
curl -s "localhost:6060/debug/pprof/goroutine?debug=1" | head -20
# goroutine profile: total 1203401
# 1203380 @ 0x43e5c5 0x40b2ef 0x40aeb8 0x7d1234 0x46f4c1
# #	0x7d1233	main.(*Consumer).handleMessage+0x93	/app/consumer.go:87
#      ^^^^^^^ 120 万个 goroutine 全部卡在同一行!

# 看具体的阻塞状态
curl -s "localhost:6060/debug/pprof/goroutine?debug=2" | grep -A 8 "consumer.go:87" | head -12
# goroutine 892340 [chan send, 4320 minutes]:
#                  ^^^^^^^^^ 阻塞在 channel 发送
#                             ^^^^^^^^^^^^ 已经阻塞 72 小时
# main.(*Consumer).handleMessage(0xc0001234, 0xc000567890)
# 	/app/consumer.go:87 +0x93

[chan send, 4320 minutes] —— goroutine 阻塞在向 channel 发送数据上,已经卡了 72 小时(正好是服务运行时长)。

2.2 原因

// consumer.go —— 有问题的代码
func (c *Consumer) Start(ctx context.Context) {
    for msg := range c.queue {
        go c.handleMessage(msg)      // 每条消息起一个 goroutine
    }
}

func (c *Consumer) handleMessage(msg Message) {
    result, err := c.process(msg)
    if err != nil {
        log.Printf("处理失败: %v", err)
        return
    }
    c.resultCh <- result             // <- 第 87 行:阻塞在这里
}

resultCh 是一个无缓冲 channel,而消费它的那个 goroutine 在启动早期因为一次 panic 已经退出了:

// 消费方
go func() {
    for r := range c.resultCh {
        c.save(r)                     // save 里 panic 过一次,整个 goroutine 退出
    }
}()

从那之后

消费方退出 -> resultCh 无人接收
              v
每个 handleMessage 都永久阻塞在 c.resultCh <- result
              v
goroutine 永不退出,每条消息泄漏一个 goroutine(2KB 栈起步)
              v
3 天累积 120 万个 -> 2.9GB 内存 -> OOM

注意这个泄漏的隐蔽之处:Go 堆(HeapAlloc)只有 234MB,看起来完全正常;pprof 的 heap profile 也看不出问题——因为泄漏的是 goroutine 栈,不是堆对象

2.3 修复

// ✅ ① 消费方加 recover,避免 panic 导致 goroutine 静默退出
go func() {
    defer func() {
        if r := recover(); r != nil {
            log.Printf("消费者 panic 恢复: %v\n%s", r, debug.Stack())
            // 重启消费循环,或上报告警
        }
    }()
    for r := range c.resultCh {
        c.saveSafely(r)               // save 内部也要有 recover
    }
}()

// ✅ ② 发送方加 context 和超时,永不无限阻塞
func (c *Consumer) handleMessage(ctx context.Context, msg Message) {
    result, err := c.process(msg)
    if err != nil {
        log.Printf("处理失败: %v", err)
        return
    }
    select {
    case c.resultCh <- result:
        // 正常发送
    case <-ctx.Done():
        return
    case <-time.After(5 * time.Second):
        log.Printf("结果 channel 阻塞超时,丢弃消息 id=%s", msg.ID)
        metrics.DroppedResults.Inc()   // <- 埋点,让问题可观测
    }
}

// ✅ ③ 用 worker pool 限制并发,而不是无限起 goroutine
func (c *Consumer) Start(ctx context.Context) {
    sem := make(chan struct{}, 100)    // 最多 100 个并发
    for msg := range c.queue {
        sem <- struct{}{}
        go func(m Message) {
            defer func() { <-sem }()
            c.handleMessage(ctx, m)
        }(msg)
    }
}

加监控,让这类问题在爆炸前被发现

// 暴露 goroutine 数量作为 metric
prometheus.MustRegister(prometheus.NewGaugeFunc(
    prometheus.GaugeOpts{Name: "go_goroutines_current"},
    func() float64 { return float64(runtime.NumGoroutine()) },
))
# 告警规则
- alert: GoroutineLeak
  expr: go_goroutines > 10000
  for: 10m
  annotations:
    summary: "goroutine 数量异常({{ $value }}),疑似泄漏"

2.4 验证

# 部署后连续观察
watch -n 60 'curl -s localhost:6060/debug/pprof/heap?debug=1 | grep -E "NumGoroutine|StackSys"'
# # NumGoroutine = 118
# # StackSys = 3407872          <- 3.4MB,正常水平

# 24 小时后确认稳定
grep -E "^(Rss|Private_Dirty):" /proc/$(pgrep msgproc)/smaps_rollup
# Rss:              487320 kB
# Private_Dirty:    463100 kB   <- 稳定在 480MB

2.5 结果

内存稳定在 480MB 不再增长,goroutine 数量稳定在 120 左右,OOM 重启完全消失。

2.6 规律

规律:RSS 持续增长时,先看 Private_Dirty 确认是真实占用;再对比运行时的堆大小(HeapAlloc)与总占用(Sys)——如果堆没涨而总量在涨,泄漏在堆外。

Go 服务内存增长的四个方向(按排查顺序):

现象 泄漏位置 排查手段
HeapAlloc 同步增长 堆内对象泄漏 pprof/heap 看 inuse_space
StackSys 大 + NumGoroutine goroutine 泄漏 pprof/goroutine?debug=2 看阻塞点
Sys 大但 HeapSys/StackSys 都不大 CGO 或 mmap 泄漏 /proc/PID/smapsstrace -e mmap
RSS 大但 Sys 不大 内存未归还 OS HeapReleasedGODEBUG=madvdontneed=1

规律:goroutine 泄漏的典型形态是「大量 goroutine 阻塞在同一行代码上」,用 pprof/goroutine?debug=2 看阻塞时长——如果时长约等于服务运行时长,就是永久阻塞。

最常见的三种 goroutine 泄漏源

// ① 向无人接收的 channel 发送
ch <- v                          // 接收方已退出 -> 永久阻塞

// ② 从无人发送的 channel 接收
<-ch                             // 发送方忘了 close -> 永久阻塞

// ③ 忘记 cancel context / 忘记设超时
resp, _ := http.Get(url)         // 没有超时,对端不响应就永久挂着
// ✅ 一律用带超时的 client
client := &http.Client{Timeout: 10 * time.Second}

通用防御:任何可能阻塞的操作都要有 select + ctx.Done() 或超时分支。


3. 案例三:load 20 但 CPU 几乎空闲

现象:16 核机器告警 load average 超过 20,但登上去看 topus + sy 加起来不到 5%。业务侧反馈接口大面积超时。

3.1 排查

# ① 确认 load 构成
uptime
# 14:32:01 up 89 days, load average: 21.34, 19.88, 15.42
nproc
# 16
# load/核数 = 1.33,明显过载
# ② vmstat 一眼定位
vmstat 1 5
# procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
#  r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
#  1 19      0 234560  91564 818900    0    0  4096 89234 2341 4523  2  3  8 87  0
#    ^^ 19 个进程阻塞在 D 状态
#                                                              ^^ wa 87%
#  ^ r 列只有 1,CPU 完全没有排队

结论立刻明确(第 7 篇 §6.1 的判读规则):

r = 1        -> CPU 不是瓶颈
b = 19       -> 19 个进程卡在【不可中断睡眠】
wa = 87%     -> CPU 大部分时间在等 IO
load ≈ 21    -> 约等于 r + b = 1 + 19 = 20 ✓

Linux 的 load 统计 R + D 两种状态,这就是「load 高但 CPU 空闲」的完整解释。

# ③ 找出 D 状态的进程,以及它们卡在哪个内核函数
ps -eo pid,stat,wchan:30,comm | awk '$2 ~ /^D/'
#   PID STAT WCHAN                          COMMAND
#  8821 D    io_schedule                    mysqld
#  8822 D    io_schedule                    mysqld
#  8823 D    io_schedule                    mysqld
#  ...(共 19 个,全是 mysqld)
#            ^^^^^^^^^^^ 全部卡在等本地磁盘 IO

wchan 直接给出方向(第 6 篇 §3.1):

wchan 含义
io_schedule / wait_on_page_bit 等本地磁盘 IO ← 本例
nfs_* / rpc_wait_bit_killable 等 NFS / 网络存储
msleep / hrtimer_nanosleep 主动睡眠(正常)
# ④ 确认磁盘是否真的饱和(第 11 篇的三条件)
iostat -xz 1 3
# Device   r/s    w/s   rkB/s    wkB/s r_await w_await aqu-sz wareq-sz %util
# nvme0n1 12.0  892.0   480.0  89234.0    2.31  245.30  98.42    100.0  99.80
#                                                 ^^^^^^ 245ms(NVMe 应 < 1ms)
#                                                        ^^^^^ 队列 98!

三个条件全部满足 → 磁盘真饱和w_await 是基准的 245 倍、aqu-sz 98 远大于 1、写吞吐 89MB/s。

# ⑤ 定位到是谁在写
pidstat -d 1 3 | sort -k5 -rn | head -3
#  UID   PID  kB_rd/s   kB_wr/s kB_ccwr/s iodelay Command
#    0  8821     0.00  87234.00      0.00   19234  mysqld
#                       ^^^^^^^^ 87MB/s 的写入
# ⑥ MySQL 在干什么
mysql -e "SHOW FULL PROCESSLIST" | awk '$6 > 60'
# Id     User Host      db     Command Time  State          Info
# 892341 app  10.0.0.5  orders Query   1832  updating       UPDATE orders SET status=...
#                                      ^^^^ 已经跑了 30 分钟

mysql -e "SELECT trx_id, trx_started, trx_rows_modified, trx_query
          FROM information_schema.INNODB_TRX\G"
# trx_started: 2026-08-06 14:02:11
# trx_rows_modified: 82340012        <- 一个事务改了 8200 万行!
# ⑦ 确认写入去向
ls -lht /var/lib/mysql/ | head -5
# -rw-r----- 1 mysql mysql 1.1G Aug  6 14:32 binlog.000234
# -rw-r----- 1 mysql mysql 1.0G Aug  6 14:29 binlog.000233
# -rw-r----- 1 mysql mysql 1.0G Aug  6 14:26 binlog.000232
#                             ^^^ 每 3 分钟产生一个 1GB 的 binlog

# 脏页情况(第 10 篇 §4.3)
grep -E "Dirty|Writeback" /proc/meminfo
# Dirty:           8234560 kB       <- 8GB 脏页待回写
# Writeback:        523400 kB

3.2 原因

有人执行了一个没有合适 WHERE 条件的批量 UPDATE,影响 8200 万行。这个大事务引发了连锁反应:

大事务 UPDATE 8200 万行
    v
① InnoDB redo log 疯狂写入
② binlog 疯狂增长(每 3 分钟 1GB)
③ 大量脏页产生,超过 vm.dirty_ratio 触发【同步回写】
    v
磁盘队列打满(aqu-sz 98)
    v
所有其他磁盘请求排在长队列后面 -> 平均等待 245ms
    v
MySQL 的正常查询也卡在 D 状态 -> load 飙升
    v
同机的其他服务 IO 也被拖慢

注意这里的关键点:CPU 一直是空闲的,加 CPU、扩容实例都无济于事——瓶颈在磁盘队列。

3.3 修复

# ① 立即止血:杀掉大事务
mysql -e "KILL 892341"

# 注意:KILL 之后 InnoDB 需要回滚 8200 万行,回滚期间磁盘仍然忙
# 观察回滚进度
mysql -e "SHOW ENGINE INNODB STATUS\G" | grep -A 3 "ROLLING BACK"
# ---TRANSACTION 892341, ROLLING BACK 82340012 rows
# ② 验证磁盘恢复
iostat -xz 1 3
# Device   w/s    wkB/s  w_await aqu-sz %util
# nvme0n1 180.0  11520.0    0.42   0.08  22.30
#                            ^^^^ 从 245ms 回到 0.42ms
#                                  ^^^^ 队列清空

vmstat 1 3
#  r  b ... wa
#  1  0 ...  2          <- b 列归零,wa 从 87% 降到 2%

长期改进(四个层面)

-- ③ 强制 UPDATE/DELETE 必须带索引条件
SET GLOBAL sql_safe_updates = 1;
-- 写进 my.cnf 持久化
# ④ 大批量操作分批做,每批之间给磁盘喘息
# ❌ 一次性改 8200 万行
# UPDATE orders SET status = 2 WHERE created_at < '2025-01-01';

# ✅ 分批 + sleep
for start in $(seq 0 1000 82340000); do
    mysql -e "UPDATE orders SET status = 2
              WHERE created_at < '2025-01-01' AND id BETWEEN $start AND $((start+1000))"
    sleep 0.1
done
# ⑤ 调整脏页参数,避免一次性刷盘造成雪崩(第 10 篇 §4.3)
cat >> /etc/sysctl.d/99-tuning.conf <<'EOF'
# 大内存机器改用绝对值,不要用比例
vm.dirty_bytes = 1073741824              # 1GB
vm.dirty_background_bytes = 268435456    # 256MB
EOF
sysctl --system
# ⑥ 用 cgroup 隔离,防止单个服务打满磁盘(第 19 篇)
mkdir -p /sys/fs/cgroup/mysql.slice
echo "+io" > /sys/fs/cgroup/cgroup.subtree_control
lsblk -d -o NAME,MAJ:MIN | grep nvme0n1
# nvme0n1 259:0
echo "259:0 wbps=104857600" > /sys/fs/cgroup/mysql.slice/io.max   # 限 100MB/s

3.4 结果

load 从 21 降到 1.8,wa 从 87% 降到 2%,接口超时全部恢复,P99 从 4s 回到 85ms。

3.5 规律

规律:load 高但 us+sy 低 → 一定是 D 状态进程在等 IO。用 vmstatb 列和 wa 列确认,再用 ps -eo stat,wchan 看卡在哪个内核函数。

规律:load ≈ r + b。分解 load 的构成就知道该往 CPU 还是 IO 方向查。

判断磁盘是否真饱和的三条件(第 11 篇,缺一不可):

① await 超过设备基准的 3~5 倍    (NVMe < 1ms,SATA SSD < 5ms,云盘 < 10ms)
② aqu-sz > 1 且持续增长
③ IOPS 或吞吐接近设备标称上限

只有 %util 高不算 —— SSD 上 %util=100% 是常态

D 状态进程杀不掉是设计使然(第 6 篇 §3.1):内核已把 DMA 地址交给硬件,此时允许进程退出会导致硬件往已释放的内存写数据。所以只能等 IO 完成或失败,kill -9 无效。


4. 案例四:磁盘满了但 du 加起来对不上

现象:告警「/ 分区使用率 99%」,登上去 df 显示已用 39GB,但 du 把所有目录加起来只有 13GB,差了 26GB。

4.1 排查

# ① 确认差异
df -h /
# Filesystem      Size  Used Avail Use% Mounted on
# /dev/vda1        40G   39G  0.5G  99% /

du -xh --max-depth=1 / 2>/dev/null | sort -rh | head -8
#  8.2G	/var
#  3.1G	/usr
#  1.2G	/opt
#  ...
#  13G	/                     <- 加起来只有 13G,差了 26G
#      ^^ 注意 -x:不跨文件系统,避免统计到其他挂载点
# ② 排查方向一:已删除但仍被进程持有的文件(第 2 篇 §3.1)
lsof +L1 2>/dev/null | head -10
# COMMAND   PID  USER  FD TYPE DEVICE  SIZE/OFF NLINK   NODE NAME
# java     1234   app  87w REG  253,1 21474836480     0 663214 /var/log/app/debug.log (deleted)
# java     1234   app  92w REG  253,1  5368709120     0 663219 /var/log/app/trace.log (deleted)
#                                                      ^ NLINK=0 就是它们
#                            ^^^^^^^^^^^ 20GB + 5GB = 25GB

找到了 25GBNLINK=0 表示文件的硬链接数为 0(目录项已删除),但因为进程还持有 fd,inode 和数据块无法释放(第 2 篇讲的 unlink 机制)。

# ③ 统计所有这类文件的总大小
lsof +L1 2>/dev/null | awk 'NR>1 {s+=$7} END {printf "已删除未释放: %.2f GB\n", s/1024/1024/1024}'
# 已删除未释放: 25.31 GB
# ④ 排查方向二:被挂载点遮盖的文件(第 11 篇 §7)
# 剩下的 1GB 差异从哪来
mkdir -p /mnt/rootcheck
mount --bind / /mnt/rootcheck
du -xh --max-depth=2 /mnt/rootcheck 2>/dev/null | sort -rh | head -5
#  1.1G	/mnt/rootcheck/data
#      ^^^^ 找到了:/data 挂载点下面藏着 1.1GB 的旧文件

ls -lh /mnt/rootcheck/data/ | head -3
# -rw-r--r-- 1 root root 1.1G Mar 15  2025 old_dump.sql
#                             ^^^^^^^^^ 去年的文件,被 /data 的挂载点遮住了

umount /mnt/rootcheck
# ⑤ 确认日志为什么这么大
ls -lh /var/log/app/
# -rw-r----- 1 app app 2.1G Aug  6 14:32 app.log
#                       ^^^ 当前的也很大

# 是谁在删日志(找出反模式)
grep -r "rm.*\.log" /etc/cron* /opt/scripts/ 2>/dev/null
# /etc/cron.d/cleanup:0 2 * * * root rm -f /var/log/app/*.log.1
#                                    ^^ 用 rm 删正在被写的日志 —— 问题根源

4.2 原因

两个问题叠加:

① 主要原因(25GB):
   有人写了个 cron,每天用 rm 删除旧日志文件
   但 Java 进程还持有这些文件的 fd
   -> rm 只删了目录项,inode 和数据块没释放
   -> du 数不到(目录项没了),df 仍然算(inode 还在)

② 次要原因(1.1GB):
   历史上先往 /data 目录写了文件,后来挂载了新盘到 /data
   那些文件还在根分区上,但被挂载点遮盖了

③ 根本原因:
   完全没有配置 logrotate,日志无限增长,
   所以才有人用 rm 来「应急」

4.3 修复

# ① 应急释放:截断而不是删除(第 15 篇 §7)
# ⚠️ 不要用 rm,那正是造成问题的原因

# 对于当前正在写的大日志
truncate -s 0 /var/log/app/app.log

# 对于已删除但仍被持有的,通过 /proc 截断它的 fd
for fd in 87 92; do
    : > /proc/1234/fd/$fd
done

df -h /
# /dev/vda1        40G   13G   26G  33% /      ✅ 空间立刻回来了
# ② 清理被遮盖的文件
mount --bind / /mnt/rootcheck
rm -f /mnt/rootcheck/data/old_dump.sql
umount /mnt/rootcheck
# ③ 删掉那个错误的 cron
rm -f /etc/cron.d/cleanup
# ④ 配置正确的 logrotate(之前完全没配)
#    配置模板、delaycompress 的必要性、copytruncate 的代价,
#    见第 15 篇 §4 —— 这里只强调本例的关键点:
#    postrotate 里必须发信号让应用重新 open(),否则轮转后它还在写旧 inode
cat > /etc/logrotate.d/app <<'EOF'
/var/log/app/*.log {
    daily
    size 200M
    rotate 7
    compress
    delaycompress
    create 0640 app app
    sharedscripts
    postrotate
        systemctl reload app.service > /dev/null 2>&1 || true
    endscript
}
EOF
logrotate -d /etc/logrotate.d/app      # 演练确认无误

更好的做法是让应用自己管滚动,完全不需要外部 logrotate:

<!-- logback-spring.xml -->
<rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
    <fileNamePattern>/var/log/app/app.%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern>
    <maxFileSize>200MB</maxFileSize>
    <maxHistory>7</maxHistory>
    <totalSizeCap>3GB</totalSizeCap>     <!-- 总量上限,最重要的一项 -->
</rollingPolicy>
# ⑤ 限制 journal 大小 + 加磁盘监控
#    完整的监控脚本(含「已删除未释放」检测)和 systemd timer 配置见第 15 篇 §7
cat >> /etc/systemd/journald.conf <<'EOF'
SystemMaxUse=1G
MaxRetentionSec=2week
ForwardToSyslog=no
EOF
systemctl restart systemd-journald
journalctl --vacuum-size=1G

4.4 验证

df -h /
# /dev/vda1        40G   12G   27G  31% /

lsof +L1 2>/dev/null | wc -l
# 0                        ✅ 没有已删除未释放的文件了

# 24 小时后确认 logrotate 生效
ls -lh /var/log/app/
# -rw-r----- 1 app app  87M Aug  7 14:32 app.log
# -rw-r----- 1 app app  12M Aug  6 23:59 app-20260806.log.gz
#                                        ^^^^^^^^^^^^^^^^^^ 正常轮转并压缩了

cat /var/lib/logrotate/status | grep app
# "/var/log/app/app.log" 2026-8-7-0:0:0

4.5 结果

磁盘从 99% 降到 31%,日志日增量从 26GB 降到 400MB,并建立了轮转和监控。

4.6 规律

规律:dfdu 对不上,按这个顺序查:① lsof +L1 找已删除但被持有的文件(最常见);② mount --bind / /mnt/x 找被挂载点遮盖的文件;③ tune2fs -l 看 ext4 预留块(正常现象)。

规律:应急清理大日志用 truncate -s 0 而不是 rmtruncate 保留 inode,空间立即释放且进程的 fd 继续有效,不需要重启服务;rm 会制造出「已删除未释放」的僵局。

为什么 rm 正在被写的文件是反模式(第 2 篇的机制):

rm = unlink,只删目录项,inode 引用计数减 1
    v
进程还持有 fd -> 引用计数 > 0 -> 数据块不释放
    v
du 数不到(目录项没了)  +  df 仍然算(inode 还在)
    v
空间「凭空消失」,且会持续到进程重启

磁盘满还要记得查 inode(第 2 篇 §3.2):

df -h /data      # 看空间
df -i /data      # 看 inode <- 海量小文件场景下经常是这个

5. 案例五:Too many open files

现象:网关服务运行约 6 小时后开始大量报错 accept: too many open files,新请求全部失败,重启后恢复,然后 6 小时又复现一次。

5.1 排查

# ① 先确认限制是多少,以及实际用了多少
PID=$(pgrep -f gateway)

cat /proc/$PID/limits | grep -i "open files"
# Max open files            65535     65535     files
#                           ^^^^^ 限制是 65535,不是 1024,说明 unit 配置生效了

ls /proc/$PID/fd | wc -l
# 65531                     <- 快顶到上限了

注意这里要看 /proc/PID/limits 而不是 ulimit -n(第 11 篇 §8.2)——后者只反映当前 shell 的限制,与服务进程无关。

# ② 看 fd 的类型分布 —— 这一步直接指向问题
ls -l /proc/$PID/fd/ 2>/dev/null | awk '{print $NF}' | sed 's/:\[.*//' | sort | uniq -c | sort -rn | head
#  65402 socket
#     87 /var/log/gateway/app.log
#     31 pipe
#      8 anon_inode
#      3 /dev/null
#        ^^^^^^^^^^ 6.5 万个 socket -> socket 泄漏,不是文件泄漏
# ③ 看这些 socket 的连接状态
ss -tanp | grep "pid=$PID" | awk '{print $1}' | sort | uniq -c | sort -rn
#  64891 CLOSE-WAIT
#    502 ESTAB
#     12 TIME-WAIT
#        ^^^^^^^^^^ 关键:6.4 万个 CLOSE-WAIT

CLOSE_WAIT 堆积的含义是明确的(第 11 篇 §8.4、第 13 篇 §3.2):

对端已发 FIN 关闭连接
    v
本机内核收到,连接进入 CLOSE_WAIT
    v
内核在等【本地应用调用 close()】来完成关闭流程
    v
应用一直不调用 close() -> 永久停留在 CLOSE_WAIT,fd 永不释放

这是纯粹的应用 bug,不是内核或网络问题——CLOSE_WAIT 没有超时机制,调任何内核参数都无效。

# ④ 看这些连接的对端是谁,缩小到具体的调用链
ss -tanp state close-wait | grep "pid=$PID" | awk '{print $5}' | cut -d: -f1 | sort | uniq -c | sort -rn | head -5
#  64203 10.0.3.100
#    501 10.0.3.101
#    187 10.0.3.102
#        ^^^^^^^^^^ 几乎全部指向同一个下游地址

# 这个地址是什么服务
nslookup 10.0.3.100 2>/dev/null || grep 10.0.3.100 /etc/hosts
# -> inventory-service(库存服务)
# ⑤ 确认增长速率,估算爆炸时间
for i in 1 2 3; do
    printf "%s  fd=%s  close_wait=%s\n" "$(date +%H:%M:%S)" \
        "$(ls /proc/$PID/fd | wc -l)" \
        "$(ss -tan state close-wait | grep -c "$PID" 2>/dev/null || ss -tan state close-wait | wc -l)"
    sleep 60
done
# 15:00:01  fd=65200  close_wait=64560
# 15:01:01  fd=65380  close_wait=64740
# 15:02:01  fd=65531  close_wait=64891
#                                      <- 每分钟涨约 180 个
# 65535 / 180 ≈ 6 小时,与故障周期完全吻合 ✓
# ⑥ 在代码里找对应的调用点
# 先确认是哪个库发起的连接
grep -rn "inventory" --include="*.go" ./internal/ | grep -iE "http|client" | head -5
# ./internal/client/inventory.go:34:  resp, err := http.Get(url)
#                                            ^^^^^^^^^^ 可疑

5.2 原因

// internal/client/inventory.go —— 有问题的代码
func (c *InventoryClient) CheckStock(skuID string) (int, error) {
    url := fmt.Sprintf("%s/api/stock?sku=%s", c.baseURL, skuID)
    resp, err := http.Get(url)
    if err != nil {
        return 0, err
    }

    if resp.StatusCode != http.StatusOK {
        return 0, fmt.Errorf("库存服务返回 %d", resp.StatusCode)
        // ^ 提前 return,resp.Body 没有被 Close!
    }

    var result StockResp
    if err := json.NewDecoder(resp.Body).Decode(&result); err != nil {
        return 0, err
        // ^ 这里也没 Close
    }
    resp.Body.Close()      // 只有全部成功的路径才会执行到
    return result.Count, nil
}

关键机制:Go 的 http.Clientresp.Body 未被完全读取并 Close() 之前,不会把底层 TCP 连接归还连接池,也不会关闭它

库存服务开始返回 5xx(它自己在做发布)
    v
CheckStock 走进 StatusCode != 200 的分支,提前 return
    v
resp.Body 没有 Close -> TCP 连接既不归还池也不关闭
    v
库存服务那边超时后主动 close -> 发来 FIN
    v
本机进入 CLOSE_WAIT,但应用永远不会 close 这个 socket
    v
每次失败的请求泄漏一个 fd,6 小时后 65535 耗尽

这个 bug 平时不显现——只有下游开始返回错误时才触发,所以「下游抖动 → 网关雪崩」形成了故障放大。

5.3 修复

// ✅ 用 defer 保证所有路径都关闭
func (c *InventoryClient) CheckStock(ctx context.Context, skuID string) (int, error) {
    url := fmt.Sprintf("%s/api/stock?sku=%s", c.baseURL, skuID)

    req, err := http.NewRequestWithContext(ctx, http.MethodGet, url, nil)
    if err != nil {
        return 0, err
    }

    resp, err := c.httpClient.Do(req)
    if err != nil {
        return 0, err
    }
    defer func() {
        // 关键:先把 Body 读完再 Close,否则连接无法【复用】只能被关闭
        io.Copy(io.Discard, resp.Body)
        resp.Body.Close()
    }()

    if resp.StatusCode != http.StatusOK {
        return 0, fmt.Errorf("库存服务返回 %d", resp.StatusCode)
    }

    var result StockResp
    if err := json.NewDecoder(resp.Body).Decode(&result); err != nil {
        return 0, err
    }
    return result.Count, nil
}

io.Copy(io.Discard, resp.Body) 这一步容易被忽略但很重要

只 Close 不读完   -> 连接【被关闭】,下次请求要重新建连(TIME_WAIT 增多)
读完再 Close      -> 连接【归还连接池】,可以复用 ✅

同时必须配好 http.Client——Go 的 http.DefaultClient 有两个致命默认值:

// ❌ 绝对不要在生产用 http.Get / http.DefaultClient
//    ① 没有超时 —— 对端不响应就永久挂着
//    ② MaxIdleConnsPerHost 只有 2 —— 高并发下大量新建连接

// ✅ 显式构造
var httpClient = &http.Client{
    Timeout: 3 * time.Second,          // 整个请求的总超时(必须有)
    Transport: &http.Transport{
        MaxIdleConns:        200,
        MaxIdleConnsPerHost: 100,      // 默认只有 2!
        MaxConnsPerHost:     200,      // 上限,防止无限建连
        IdleConnTimeout:     90 * time.Second,
        DialContext: (&net.Dialer{
            Timeout:   1 * time.Second,
            KeepAlive: 30 * time.Second,
        }).DialContext,
        TLSHandshakeTimeout:   2 * time.Second,
        ResponseHeaderTimeout: 2 * time.Second,
        ExpectContinueTimeout: 1 * time.Second,
    },
}

加监控,让 fd 泄漏在爆炸前被发现

prometheus.MustRegister(prometheus.NewGaugeFunc(
    prometheus.GaugeOpts{Name: "process_open_fds_current"},
    func() float64 {
        entries, err := os.ReadDir("/proc/self/fd")
        if err != nil { return -1 }
        return float64(len(entries))
    },
))
# 告警:fd 使用率超过 70% 就报,不要等到 100%
- alert: FDLeakSuspected
  expr: process_open_fds_current / 65535 > 0.7
  for: 5m
  annotations:
    summary: "fd 使用率 {{ $value | humanizePercentage }},疑似泄漏"

# 更灵敏:CLOSE_WAIT 数量本身就是明确信号
- alert: CloseWaitPileup
  expr: node_netstat_Tcp_CurrEstab_close_wait > 1000
  for: 5m

5.4 验证

# ① 部署后压测,故意让下游返回 5xx
# 用 toxiproxy 或 nginx 模拟下游故障
ab -n 10000 -c 100 http://gateway/api/order

# ② 确认 fd 不再增长
watch -n 5 'echo "fd=$(ls /proc/$(pgrep -f gateway)/fd | wc -l) close_wait=$(ss -tan state close-wait | wc -l)"'
# fd=612 close_wait=3
# fd=608 close_wait=1
# fd=615 close_wait=2
#                     ✅ 稳定在 600 左右,CLOSE_WAIT 个位数

# ③ 确认连接被正确复用(而不是每次新建)
ss -tanp | grep "pid=$(pgrep -f gateway)" | grep 10.0.3.100 | wc -l
# 87                  <- 稳定的连接池,不是每请求一条

5.5 结果

fd 稳定在 600 左右不再增长,CLOSE_WAIT 从 6.4 万降到个位数,Too many open files 完全消失。顺带因为连接复用生效,P99 从 45ms 降到 28ms。

5.6 规律

规律:Too many open files 先查两件事——① /proc/PID/limits 确认限制是否真的生效(不看 ulimit -n);② ls -l /proc/PID/fd | awk '{print $NF}' | sort | uniq -c 看 fd 类型分布,socket 多是连接泄漏,普通文件多是文件句柄泄漏。

规律:CLOSE_WAIT 堆积 = 应用漏了 close(),去查代码;TIME_WAIT 堆积 = 主动关闭方的正常现象,才考虑内核参数。这两个千万不要混。

各语言最容易漏关的资源

语言 高危点 正确写法
Go resp.Bodyrowsfile defer x.Close()
Java InputStreamConnectionResultSet try-with-resources
Python open()requestsResponse with 语句
Node.js 未消费的 stream pipeline() / 显式 destroy

通用防御原则

① 任何 Open/Get/Acquire 之后立刻写 defer/finally Close
② HTTP 客户端必须显式设超时(Go 的 http.DefaultClient 没有超时!)
③ Go 里 Close 之前先 io.Copy(io.Discard, body) 读完,否则连接无法复用
④ 把 fd 数量做成 metric,70% 就告警,不要等 100%

6. 案例六:TIME_WAIT 堆积导致端口耗尽

现象:一个对外调用第三方支付接口的服务,QPS 只有 800,但每天固定在流量高峰期出现大量 connect: cannot assign requested address 错误,持续十几分钟后自行恢复。

6.1 排查

# ① 报错信息本身就指向端口耗尽
# "cannot assign requested address" = EADDRNOTAVAIL
#   -> 内核找不到可用的本地端口来发起新连接

# ② 确认连接状态分布
ss -s
# Total: 34521
# TCP:   33892 (estab 512, closed 32891, orphaned 12, timewait 32891)
#                                                     ^^^^^^^^^^^^^^ 3.2 万个 TIME_WAIT

ss -tan | awk 'NR>1 {print $1}' | sort | uniq -c | sort -rn
#  32891 TIME-WAIT
#    512 ESTAB
#     23 SYN-SENT
# ③ 确认本地端口范围(可用端口总数)
cat /proc/sys/net/ipv4/ip_local_port_range
# 32768	60999
# 可用端口数 = 60999 - 32768 = 28231

# TIME_WAIT 32891 > 可用端口 28231  -> 端口确实被耗尽了 ✓
# ④ 看 TIME_WAIT 集中在哪个对端
ss -tan state time-wait | awk '{print $4}' | cut -d: -f1 | sort | uniq -c | sort -rn | head -3
#  32780 10.0.0.15              <- 本机 IP(说明是本机主动发起的连接)

ss -tan state time-wait | awk '{print $5}' | cut -d: -f1 | sort | uniq -c | sort -rn | head -3
#  32654 203.0.113.88           <- 全部指向同一个对端
#    137 203.0.113.89

# 这个地址是什么
dig -x 203.0.113.88 +short
# api.thirdpay.example.com.     <- 第三方支付接口
# ⑤ 确认是否有连接复用
# 800 QPS 且 TIME_WAIT 60 秒 -> 如果每请求一条连接:800 × 60 = 4.8 万
# 实测 3.2 万,量级吻合 -> 基本确定没有复用连接

# 抓包确认(第 13 篇的分工,抓包细节见 network-21)
timeout 10 tcpdump -i any -nn "host 203.0.113.88 and (tcp[tcpflags] & tcp-syn != 0)" -c 100 2>/dev/null | wc -l
# 100                          <- 10 秒内 100 个 SYN,说明在不断新建连接

# 每个连接只发一个请求就关闭
timeout 10 tcpdump -i any -nn "host 203.0.113.88 and (tcp[tcpflags] & tcp-fin != 0)" -c 100 2>/dev/null | \
    awk '{print $3}' | cut -d. -f5 | sort -u | wc -l
# 98                           <- 98 个不同的本地端口都发了 FIN
# ⑥ 确认是谁先关闭(决定 TIME_WAIT 出现在哪一端)
# TIME_WAIT 在【本机】-> 说明是本机主动关闭的
ss -tan state time-wait | head -2
# State      Recv-Q Send-Q Local Address:Port    Peer Address:Port
# TIME-WAIT  0      0      10.0.0.15:45678       203.0.113.88:443
#                          ^^^^^^^^^^^^^^^^ 本机端在 TIME_WAIT -> 本机是主动关闭方
# ⑦ 看代码
grep -rn "thirdpay\|payment" --include="*.go" ./internal/ | grep -iE "client|http" | head -3
# ./internal/pay/thirdparty.go:28:  resp, err := http.Post(payURL, "application/json", body)
#                                          ^^^^^^^^^ 用了 http.Post

6.2 原因

// internal/pay/thirdparty.go —— 有问题的代码
func CallPayment(req PayRequest) (*PayResp, error) {
    body, _ := json.Marshal(req)
    // ❌ http.Post 用的是 http.DefaultClient
    resp, err := http.Post(payURL, "application/json", bytes.NewReader(body))
    if err != nil {
        return nil, err
    }
    defer resp.Body.Close()      // Close 有了,但没有读完 Body

    var out PayResp
    json.NewDecoder(resp.Body).Decode(&out)
    return &out, nil
}

两个问题叠加

① http.DefaultClient 的 MaxIdleConnsPerHost 默认只有 2
   -> 800 QPS 下,绝大部分请求拿不到空闲连接,只能新建
   
② Body 没读完就 Close(`json.Decoder` 可能没读到 EOF)
   -> 连接【无法归还连接池】,只能被关闭
   
结果:几乎每个请求都是「新建连接 -> 用一次 -> 主动关闭」
   -> 本机作为主动关闭方,每条连接产生一个 TIME_WAIT(60 秒)
   -> 800 QPS × 60s = 4.8 万个 TIME_WAIT
   -> 超过可用端口数 28231 -> EADDRNOTAVAIL

为什么只在高峰期出现:低峰时 QPS 只有 200,200 × 60 = 1.2 万 < 2.8 万,还够用;高峰 800 QPS 就突破了。

6.3 修复

必须先理解 TIME_WAIT 的存在意义,不要盲目消灭它

TIME_WAIT 是【主动关闭方】必经的状态,Linux 上固定 60 秒,作用有两个:

① 确保最后的 ACK 能到达对端 —— 如果 ACK 丢了,对端会重发 FIN,
   本端还在 TIME_WAIT 就能重发 ACK;如果已经关闭,会回 RST 让对端报错
   
② 让旧连接的残留数据包在网络中消散 —— 防止新建的同四元组连接
   收到上一个连接的延迟报文(序列号可能碰巧落在窗口内)

所以 TIME_WAIT 不是 bug,是协议设计。正确方向是【减少连接创建】,
而不是想办法跳过 TIME_WAIT。

注意:Linux 的 TIME_WAIT 时长是内核里硬编码的 60 秒TCP_TIMEWAIT_LEN),不可通过任何 sysctl 调整,改它要重新编译内核。常被误认为能调它的 net.ipv4.tcp_fin_timeout 实际控制的是 FIN_WAIT_2 状态的超时,与 TIME_WAIT 无关——网上大量「调小 tcp_fin_timeout 减少 TIME_WAIT」的说法是错的。

方案一(根治):用连接池复用连接

// ✅ 显式构造 Client,配好连接池
var payClient = &http.Client{
    Timeout: 5 * time.Second,
    Transport: &http.Transport{
        MaxIdleConns:        200,
        MaxIdleConnsPerHost: 100,          // 关键:默认只有 2
        MaxConnsPerHost:     200,
        IdleConnTimeout:     90 * time.Second,
        DialContext: (&net.Dialer{
            Timeout:   2 * time.Second,
            KeepAlive: 30 * time.Second,   // 开启 TCP keepalive
        }).DialContext,
    },
}

func CallPayment(ctx context.Context, req PayRequest) (*PayResp, error) {
    body, err := json.Marshal(req)
    if err != nil {
        return nil, err
    }

    httpReq, err := http.NewRequestWithContext(ctx, http.MethodPost, payURL,
        bytes.NewReader(body))
    if err != nil {
        return nil, err
    }
    httpReq.Header.Set("Content-Type", "application/json")

    resp, err := payClient.Do(httpReq)
    if err != nil {
        return nil, err
    }
    defer func() {
        io.Copy(io.Discard, resp.Body)     // 必须读完才能复用连接
        resp.Body.Close()
    }()

    if resp.StatusCode != http.StatusOK {
        return nil, fmt.Errorf("支付接口返回 %d", resp.StatusCode)
    }

    var out PayResp
    if err := json.NewDecoder(resp.Body).Decode(&out); err != nil {
        return nil, err
    }
    return &out, nil
}

方案二(辅助):内核参数调优

# ✅ tcp_tw_reuse:允许在【发起新连接】时复用处于 TIME_WAIT 的端口
#    依赖 TCP 时间戳(tcp_timestamps=1)保证安全,对【客户端】场景有效
sysctl -w net.ipv4.tcp_tw_reuse=1
sysctl -w net.ipv4.tcp_timestamps=1

# ✅ 扩大本地端口范围(1024 以下是特权端口,不能用)
sysctl -w net.ipv4.ip_local_port_range="10000 65000"
# 可用端口从 28231 增加到 55000

# ✅ 限制 TIME_WAIT 总数(超过就直接回收,会打日志)
sysctl -w net.ipv4.tcp_max_tw_buckets=65536

# ❌ 绝对不要用 tcp_tw_recycle
#    它在 NAT 环境下会导致【同一 NAT 出口的不同客户端互相干扰】,
#    表现为随机的连接失败。Linux 4.12 已经彻底移除了这个参数。
# 持久化
cat >> /etc/sysctl.d/99-network.conf <<'EOF'
net.ipv4.tcp_tw_reuse = 1
net.ipv4.tcp_timestamps = 1
net.ipv4.ip_local_port_range = 10000 65000
net.ipv4.tcp_max_tw_buckets = 65536
# 注意:这里【没有】tcp_fin_timeout —— 它管的是 FIN_WAIT_2,不是 TIME_WAIT
EOF
sysctl --system

tcp_tw_reusetcp_tw_recycle 的区别必须搞清(这是高频面试点):

tcp_tw_reuse tcp_tw_recycle
作用 允许新建连接时复用 TIME_WAIT 的端口 快速回收 TIME_WAIT(不等 2MSL)
安全性 安全(靠时间戳判断新旧) 危险
NAT 环境 正常工作 会导致随机连接失败
作用对象 只对主动发起连接的一方有效 双向
现状 可用,推荐 4.12 已移除,绝对不要用

为什么 tcp_tw_recycle 在 NAT 下会出问题:它会记录「每个对端 IP 最后一次的时间戳」,如果新连接的时间戳比记录的小就丢弃。而 NAT 后面的多台机器共用一个出口 IP,它们的时间戳各自独立、互不相关——于是 A 机器连过之后,B 机器的连接因为时间戳更小而被静默丢弃,表现为莫名的连接失败。

6.4 验证

# ① 部署后观察 TIME_WAIT
ss -s
# TCP:   1203 (estab 512, closed 623, orphaned 0, timewait 623)
#                                                  ^^^^^^^^^^ 从 3.2 万降到 623

# ② 确认连接被复用
ss -tan | grep 203.0.113.88 | awk '{print $1}' | sort | uniq -c
#     87 ESTAB              <- 稳定的 87 条长连接
#     12 TIME-WAIT
#     ^ 87 条连接承载 800 QPS,说明复用生效

# ③ 确认 SYN 数量大幅下降
timeout 10 tcpdump -i any -nn "host 203.0.113.88 and (tcp[tcpflags] & tcp-syn != 0)" 2>/dev/null | wc -l
# 3                        <- 10 秒只有 3 个新建连接(之前是 100+)

# ④ 确认错误消失
grep -c "cannot assign requested address" /var/log/pay/app.log
# 0

6.5 结果

TIME_WAIT 从 3.2 万降到 600 左右,端口耗尽错误完全消失。副作用是延迟改善明显——省掉了每次请求的 TCP 三次握手和 TLS 握手,P99 从 180ms 降到 62ms。

6.6 规律

规律:cannot assign requested address(EADDRNOTAVAIL)= 本地端口耗尽。用 ss -s 看 TIME_WAIT 数量,与 ip_local_port_range 的区间大小对比。

规律:TIME_WAIT 堆积的根治方向是「减少连接创建」(用连接池 / 长连接),不是「消灭 TIME_WAIT」。内核参数只是辅助。

TIME_WAIT 数量的估算公式

TIME_WAIT 数量 ≈ 每秒新建连接数 × 60(Linux 的 2MSL)

所以:
  800 QPS 无复用  -> 4.8 万个 TIME_WAIT  -> 超过 2.8 万可用端口,必然耗尽
  800 QPS 有复用  -> 几百个              -> 完全没问题

排查 TIME_WAIT 问题的关键判断

# TIME_WAIT 出现在哪一端,决定了谁是主动关闭方
ss -tan state time-wait | head -2
# 本机地址在 Local 侧 -> 本机主动关闭 -> 查本机的客户端代码
# 如果是服务端出现大量 TIME_WAIT -> 说明服务端在主动断连,
#   通常是 keepalive 配置问题或主动关闭空闲连接

Go 服务的三个必查项(这三个默认值都会导致连接不复用):

// ① http.DefaultClient 没有 Timeout —— 必须显式设
// ② MaxIdleConnsPerHost 默认只有 2 —— 必须调大
// ③ Body 没读完就 Close —— 连接无法归还池
//    正确:io.Copy(io.Discard, resp.Body) 后再 Close

其他常见的连接不复用场景

场景 原因 修复
每次请求都 new 一个 Client Transport 不共享,连接池失效 Client 做成全局单例
服务端返回 Connection: close 服务端不支持 keepalive 检查服务端配置
HTTP/1.0 请求 默认不 keepalive 用 HTTP/1.1 或显式 Connection: keep-alive
每次请求换 URL host 连接池按 host 分组 正常,无需处理

7. 案例七:服务启动失败但日志什么都没说

现象:新版本发布后服务起不来,systemctl start myapp 卡住约 90 秒后返回失败,应用自己的日志文件是空的。回滚到旧版本正常。

7.1 排查

# ① 先看 systemd 的状态 —— 它比应用日志信息量大得多
systemctl status myapp
# ● myapp.service - My Application
#      Loaded: loaded (/etc/systemd/system/myapp.service; enabled)
#      Active: failed (Result: timeout) since Thu 2026-08-06 15:02:11 CST
#                      ^^^^^^^^^^^^^^^^ 是【超时】,不是崩溃
#     Process: 12345 ExecStart=/opt/myapp/bin/myapp (code=killed, signal=TERM)
#                                                    ^^^^^^^^^^^^^^^^^^^^^^ 被 systemd 杀的

Result: timeout + signal=TERM 是关键线索:进程没有崩溃,是 systemd 等不到「启动完成」的信号,超时后主动杀掉的。

# ② 看完整日志(应用的 stdout/stderr 都会进 journal)
journalctl -u myapp -n 50 --no-pager
# Aug 06 15:00:41 host systemd[1]: Starting My Application...
# Aug 06 15:00:41 host myapp[12345]: 2026/08/06 15:00:41 starting server on :8080
# Aug 06 15:00:41 host myapp[12345]: 2026/08/06 15:00:41 connecting to database...
# Aug 06 15:02:11 host systemd[1]: myapp.service: start operation timed out. Terminating.
# Aug 06 15:02:11 host systemd[1]: myapp.service: Failed with result 'timeout'.
#                                                                    ^^^^^^^

「应用日志是空的」的原因找到了:进程确实启动了并输出了两行日志,但这些日志进了 journal 而不是应用配置的日志文件——因为它在初始化阶段就卡住了,还没走到「初始化日志文件」那一步。

# ③ 看 unit 配置,理解为什么会超时
systemctl cat myapp
# [Service]
# Type=notify                    <- 关键
# NotifyAccess=main
# TimeoutStartSec=90
# ExecStart=/opt/myapp/bin/myapp

Type=notify 意味着 systemd 在等应用主动调用 sd_notify(READY=1)(第 14 篇 §3.2)。日志显示应用卡在 connecting to database...,永远没走到发送 READY 的那一步。

# ④ 手动运行,看是不是真的卡在数据库连接
sudo -u myapp /opt/myapp/bin/myapp --config=/etc/myapp/config.yaml
# 2026/08/06 15:10:22 starting server on :8080
# 2026/08/06 15:10:22 connecting to database...
# ^C                             <- 确实卡在这里,一直不返回
# ⑤ 看它到底在等什么(第 9 篇的 strace 链路)
sudo -u myapp /opt/myapp/bin/myapp &
APP_PID=$!
sleep 5
sudo strace -p $APP_PID -f 2>&1 | head -20
# [pid 12400] connect(7, {sa_family=AF_INET, sin_port=htons(5432),
#                         sin_addr=inet_addr("10.0.2.50")}, 16
#                                              ^^^^^^^^^^ 卡在连接这个地址

# ⑥ 用 /proc 交叉确认
ls -l /proc/$APP_PID/fd/ | grep socket
ss -tanp | grep "pid=$APP_PID"
# SYN-SENT  0  1  10.0.0.15:45678  10.0.2.50:5432  users:(("myapp",pid=12400,fd=7))
# ^^^^^^^^ SYN-SENT = 发了 SYN 但没收到回应(第 13 篇 §3.2)

SYN-SENT 卡住 = 对端不可达或被防火墙静默丢包。

# ⑦ 分层验证连通性(第 13 篇 §6 的排查顺序)
ip route get 10.0.2.50
# 10.0.2.50 via 10.0.0.1 dev eth0 src 10.0.0.15     <- 有路由

ping -c 2 -W 2 10.0.2.50
# 2 packets transmitted, 0 received, 100% packet loss

nc -zv -w 3 10.0.2.50 5432
# nc: connect to 10.0.2.50 port 5432 (tcp) failed: Connection timed out
#                                                  ^^^^^^^^^^^^^^^^^^ timeout 不是 refused
#     -> 包被静默丢弃,查防火墙/安全组,不是服务没监听
# ⑧ 对比新旧版本的配置差异 —— 找出为什么旧版本能起来
diff <(git show v1.8.0:config/prod.yaml) <(git show v1.9.0:config/prod.yaml)
# -  host: 10.0.2.40
# +  host: 10.0.2.50
#      ^^^^^^^^^^ 数据库地址变了!新版本指向了一个新的 RDS 实例

# 确认新地址的安全组
# -> 新 RDS 实例的安全组没有放通这台机器所在的网段

7.2 原因

三个因素叠加成了这个「无声的失败」:

① 直接原因:
   新版本的配置指向了新的数据库实例,但该实例的安全组没放通本机网段
   -> TCP 连接卡在 SYN-SENT
   
② 为什么没有报错日志:
   代码用了 database/sql 的默认设置,【没有连接超时】
   -> connect() 一直阻塞,走不到错误处理和日志初始化
   
③ 为什么看起来「日志是空的」:
   应用配置的日志文件在数据库连接成功之后才初始化
   -> 早期日志只进了 stdout(被 journald 收集),不在应用日志文件里

7.3 修复

紧急修复:放通安全组(略)。但代码和配置层面的问题必须一起改,否则下次还会这样:

// ✅ ① 所有外部依赖都必须有连接超时
func connectDB(cfg Config) (*sql.DB, error) {
    dsn := fmt.Sprintf("host=%s port=%d user=%s dbname=%s sslmode=require "+
        "connect_timeout=5",          // <- PostgreSQL 的连接超时(秒)
        cfg.Host, cfg.Port, cfg.User, cfg.DBName)

    db, err := sql.Open("postgres", dsn)
    if err != nil {
        return nil, fmt.Errorf("打开数据库失败: %w", err)
    }

    db.SetMaxOpenConns(50)
    db.SetMaxIdleConns(10)
    db.SetConnMaxLifetime(30 * time.Minute)

    // 用带超时的 context 做首次连通性验证
    ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second)
    defer cancel()
    if err := db.PingContext(ctx); err != nil {
        return nil, fmt.Errorf("数据库不可达 %s:%d: %w", cfg.Host, cfg.Port, err)
        //                      ^^^^^^^^^^^^^^^^ 错误信息里必须带上地址!
    }
    return db, nil
}
// ✅ ② 日志【最先】初始化,在任何外部依赖之前
func main() {
    // 第一件事:初始化日志,让后续所有步骤都有日志
    initLogger()
    log.Info("服务启动中", "version", buildVersion, "pid", os.Getpid())

    cfg := mustLoadConfig()
    log.Info("配置已加载", "db_host", cfg.DB.Host, "redis", cfg.Redis.Addr)
    //                                ^^^^^^^^^^^^ 把关键配置打出来,便于排查

    // 然后才是外部依赖
    db, err := connectDB(cfg.DB)
    if err != nil {
        log.Error("数据库连接失败", "err", err)
        os.Exit(1)              // 快速失败,不要卡住
    }
    // ...
}
// ✅ ③ 启动阶段做依赖预检,一次性报告所有问题
func preflightCheck(cfg Config) error {
    checks := []struct {
        name string
        addr string
    }{
        {"database", fmt.Sprintf("%s:%d", cfg.DB.Host, cfg.DB.Port)},
        {"redis", cfg.Redis.Addr},
        {"kafka", cfg.Kafka.Brokers[0]},
    }

    var errs []string
    for _, c := range checks {
        conn, err := net.DialTimeout("tcp", c.addr, 3*time.Second)
        if err != nil {
            errs = append(errs, fmt.Sprintf("%s (%s): %v", c.name, c.addr, err))
            continue
        }
        conn.Close()
        log.Info("依赖检查通过", "name", c.name, "addr", c.addr)
    }
    if len(errs) > 0 {
        return fmt.Errorf("依赖不可达:\n  %s", strings.Join(errs, "\n  "))
    }
    return nil
}

这个预检的价值:把「卡 90 秒后无声失败」变成「3 秒内明确报告哪个依赖不通」。

# ✅ ④ unit 配置也要调整(第 14 篇)
[Unit]
# 这两项在 [Unit] 段,写进 [Service] 会被静默忽略
StartLimitIntervalSec=120
StartLimitBurst=3               # 3 次失败就停下,别无限重启掩盖问题

[Service]
Type=notify
NotifyAccess=main
TimeoutStartSec=30              # 从 90 缩短 —— 快速失败比慢慢卡住好
Restart=on-failure
RestartSec=10

# 让日志明确进 journal
StandardOutput=journal
StandardError=journal
# ✅ ⑤ 发布流程加配置 diff 检查
# CI 里对比即将发布的配置与当前生产配置
diff <(kubectl get cm myapp-config -o jsonpath='{.data.prod\.yaml}') ./config/prod.yaml
# 任何外部地址变更都要人工确认,并检查网络可达性

7.4 验证

# ① 模拟依赖不可达,确认能快速失败并给出明确信息
sudo iptables -A OUTPUT -d 10.0.2.50 -j DROP     # 人为切断
systemctl restart myapp

systemctl status myapp
# Active: failed (Result: exit-code) since ...
#                         ^^^^^^^^^ 是 exit-code 不是 timeout 了

journalctl -u myapp -n 5 --no-pager
# myapp[12500]: 服务启动中 version=v1.9.1 pid=12500
# myapp[12500]: 配置已加载 db_host=10.0.2.50 redis=10.0.2.51:6379
# myapp[12500]: 依赖不可达:
# myapp[12500]:   database (10.0.2.50:5432): dial tcp 10.0.2.50:5432: i/o timeout
#                 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 明确指出问题
# systemd[1]: myapp.service: Main process exited, code=exited, status=1

# 耗时
# Aug 06 15:30:01 -> 15:30:04     <- 3 秒失败,不是 90 秒
sudo iptables -D OUTPUT -d 10.0.2.50 -j DROP     # 恢复

# ② 正常启动的验证
systemctl restart myapp
systemctl show -p ActiveState,SubState myapp
# ActiveState=active
# SubState=running               <- notify 型服务收到 READY=1 才是 running

7.5 结果

启动失败从「卡 90 秒后无声失败」变成「3 秒内报出具体不通的依赖和地址」,同类问题的定位时间从半小时降到十几秒。

7.6 规律

规律:服务起不来,先看 systemctl statusResult: 字段——timeout 是卡住了(查外部依赖),exit-code 是主动退出(查日志里的错误),signal 是被杀了(查 OOM 或 KillSignal)。

规律:应用日志文件是空的,不代表没有日志。启动早期的输出都在 journal 里,用 journalctl -u xxx 看。

服务启动失败的排查顺序

# ① systemd 层面
systemctl status myapp              # 看 Result 和退出码
journalctl -u myapp -n 50           # 看完整日志(含 stdout)
systemctl cat myapp                 # 看最终生效的配置

# ② 手动运行,脱离 systemd
sudo -u myapp /opt/myapp/bin/myapp --config=/etc/myapp/config.yaml
#      ^^^^^^^ 必须用【相同的用户】,否则权限问题不会复现

# ③ 如果卡住,看在等什么
strace -p PID -f                    # 卡在哪个系统调用
ss -tanp | grep PID                 # SYN-SENT = 网络不通
cat /proc/PID/stack                 # 内核栈(需要 root)

# ④ 常见原因清单
ss -tlnp | grep :8080               # 端口被占用
ls -ld /var/log/myapp               # 目录权限(第 3 篇)
cat /proc/PID/limits                # fd 限制(第 11 篇)
getenforce; ausearch -m avc -ts recent   # SELinux 拒绝

「无声失败」的三个根因,都要在代码层面解决

根因 后果 修复
外部依赖调用没有超时 永久阻塞,systemd 只能超时杀掉 所有外部调用设超时
日志初始化太晚 早期错误无处记录 日志放在 main 的第一行
错误信息不含上下文 只说「连接失败」,不说连的是哪 错误里带上地址、配置项名

Type=notify 的额外注意:它要求应用主动发 READY=1,如果应用在发送之前卡住,systemd 会等满 TimeoutStartSec。所以用 notify 型服务时,TimeoutStartSec 不宜设太长(30 秒足够),配合应用侧的依赖预检,能把失败反馈时间压到秒级。


8. 案例八:容器反复 OOMKilled

现象:K8s 上的 Java 服务,Pod 每隔 2~4 小时被重启一次,kubectl describe 显示 OOMKilled。容器内存限制 4GB,而 JVM 堆只设了 -Xmx2g

8.1 排查

# ① 确认重启原因和退出码
kubectl describe pod myapp-7d8f9c-xk2p9 | grep -A 12 "Last State"
#     Last State:     Terminated
#       Reason:       OOMKilled
#       Exit Code:    137
#                     ^^^ 137 = 128 + 9 = 被 SIGKILL 杀(第 8 篇 §7.4)
#       Started:      Thu, 06 Aug 2026 12:14:22 +0800
#       Finished:     Thu, 06 Aug 2026 15:02:41 +0800
#                     ^^^^^^^^^^^^^ 存活 2 小时 48 分

kubectl get pod myapp-7d8f9c-xk2p9 -o jsonpath='{.spec.containers[0].resources}'
# {"limits":{"cpu":"2","memory":"4Gi"},"requests":{"cpu":"1","memory":"2Gi"}}
# ② 区分是 cgroup OOM 还是宿主机 OOM(第 10 篇 §7.3)
kubectl exec -it myapp-7d8f9c-xk2p9 -- cat /sys/fs/cgroup/memory.events
# low 0
# high 8234
# max 892
# oom 12
# oom_kill 12                    <- cgroup 级别的 OOM,不是宿主机内存耗尽

# 宿主机上确认
ssh node-3 'dmesg -T | grep -i "killed process" | tail -3'
# [Thu Aug  6 15:02:41 2026] Memory cgroup out of memory: Killed process 28934 (java)
#                            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 明确是 cgroup OOM
#   total-vm:9823456kB, anon-rss:4187593kB, file-rss:23400kB
#                       ^^^^^^^^^^^^^^^^^^ 匿名页 4GB,正好顶到 limit

Memory cgroup out of memory 说明是容器超了自己的限额,宿主机内存充足——所以扩节点没用,要么放宽限额,要么减少实际占用。

# ③ 看容器内存的构成 —— 这一步决定往哪个方向查
kubectl exec -it myapp-7d8f9c-xk2p9 -- sh -c '
  cat /sys/fs/cgroup/memory.current
  echo "---"
  grep -E "^(anon|file|slab|sock|kernel_stack|percpu) " /sys/fs/cgroup/memory.stat
'
# 4187593728
# ---
# anon 3925868544            <- 匿名页 3.9GB(堆、栈、堆外内存),【不可回收】
# file 178257920             <- page cache 178MB,可回收
# slab 52428800
# sock 8388608
# kernel_stack 15728640

关键:anon 占了 3.9GB。匿名页是不可回收的(第 10 篇),这才是 OOM 的真凶。如果主要是 file(page cache),内核会先回收而不会直接 OOM。

# ④ 拆解 JVM 的内存构成 —— 用 NMT(Native Memory Tracking)
kubectl exec -it myapp-7d8f9c-xk2p9 -- jcmd 1 VM.native_memory summary
# Native Memory Tracking:
# Total: reserved=6234MB, committed=3892MB
# -                 Java Heap (reserved=2048MB, committed=2048MB)
#                             <- 堆 2GB,符合 -Xmx2g
# -                     Class (reserved=1092MB, committed=312MB)
#                             <- Metaspace 312MB
# -                    Thread (reserved=1043MB, committed=1043MB)
#                             <- 【线程栈 1GB!】
# -                      Code (reserved=252MB, committed=138MB)
# -                        GC (reserved=178MB, committed=178MB)
# -                  Compiler (reserved=12MB, committed=12MB)
# -                  Internal (reserved=623MB, committed=623MB)
#                             <- 【Internal 623MB,含 DirectByteBuffer】
# -                    Symbol (reserved=32MB, committed=32MB)
汇总实际提交的内存:
  Java Heap      2048 MB
  Thread          1043 MB   <- 异常
  Internal         623 MB   <- 异常
  Class            312 MB
  GC               178 MB
  Code             138 MB
  其他              44 MB
  ---------------------
  合计            4386 MB > 4096 MB (4Gi limit)  -> OOM ✓
# ⑤ 线程栈为什么占 1GB
kubectl exec -it myapp-7d8f9c-xk2p9 -- sh -c 'ls /proc/1/task | wc -l'
# 1043                       <- 1043 个线程!

kubectl exec -it myapp-7d8f9c-xk2p9 -- jstack 1 | grep -c "^\"" 
# 1041

# 看线程都是什么
kubectl exec -it myapp-7d8f9c-xk2p9 -- jstack 1 | grep "^\"" | \
    sed -E 's/^"([^0-9"]+).*/\1/' | sort | uniq -c | sort -rn | head -5
#    892 pool-3-thread-
#     87 http-nio-8080-exec-
#     32 Catalina-utility-
#         ^^^^^^^^^^^^^^^ 892 个来自同一个线程池
# ⑥ 找到这个线程池
kubectl exec -it myapp-7d8f9c-xk2p9 -- jstack 1 | grep -A 5 "pool-3-thread-1\"" 
# "pool-3-thread-1" #45 prio=5 os_prio=0 tid=0x... nid=0x1234 waiting on condition
#    java.lang.Thread.State: WAITING (parking)
#         at sun.misc.Unsafe.park(Native Method)
#         at java.util.concurrent.SynchronousQueue.take(SynchronousQueue.java:924)
#                                 ^^^^^^^^^^^^^^^^^ 线索:用了 SynchronousQueue
// 在代码里搜到了
// ❌ 有问题的写法
private final ExecutorService executor = Executors.newCachedThreadPool();
//                                                  ^^^^^^^^^^^^^^^^^^^ 罪魁祸首
# ⑦ 确认 DirectByteBuffer(Internal 623MB)
kubectl exec -it myapp-7d8f9c-xk2p9 -- jcmd 1 VM.flags | tr ' ' '\n' | grep -i direct
# (空)                     <- 没有设置 MaxDirectMemorySize

# 默认值等于 -Xmx,即 2GB —— 完全没有约束

8.2 原因

三个问题叠加

① Executors.newCachedThreadPool() 的线程数上限是 Integer.MAX_VALUE
   -> 突发流量下无限创建线程,每个线程栈 1MB(默认 -Xss1m)
   -> 892 个线程 = 892MB 内存,而且这些线程空闲 60 秒才回收
   
② 没有限制 DirectByteBuffer(Netty 用它做零拷贝)
   -> 默认上限 = -Xmx = 2GB,实际用了 623MB,完全在「合法」范围内
   
③ JVM 参数只考虑了堆,没有为堆外留空间
   -> -Xmx2g 占了 4GB limit 的一半,剩下 2GB 要装
     Metaspace + 线程栈 + CodeCache + GC 结构 + DirectMemory
   -> 平时够用,线程数一涨就爆

为什么是 2~4 小时一次:线程数随流量波动缓慢累积,达到某个阈值后总内存突破 4GB。

8.3 修复

// ✅ ① 用有界线程池替代 newCachedThreadPool
private final ExecutorService executor = new ThreadPoolExecutor(
    16,                                      // 核心线程数
    64,                                      // 【最大线程数】—— 关键
    60L, TimeUnit.SECONDS,
    new LinkedBlockingQueue<>(1000),         // 有界队列
    new ThreadFactoryBuilder()
        .setNameFormat("biz-worker-%d")      // 有意义的名字,便于排查
        .build(),
    new ThreadPoolExecutor.AbortPolicy()     // 满了就拒绝,快速失败
);

// ❌ 三个不要用的工厂方法
// Executors.newCachedThreadPool()    -> 线程数无上限
// Executors.newFixedThreadPool(n)    -> 队列无上限(LinkedBlockingQueue 默认 Integer.MAX_VALUE)
// Executors.newSingleThreadExecutor()-> 同上
# ✅ ② JVM 参数:显式约束每一块内存
JAVA_OPTS="
  -XX:MaxRAMPercentage=55                    # 堆占容器限额的 55%,不写死 -Xmx
  -XX:MaxMetaspaceSize=256m
  -XX:MaxDirectMemorySize=512m               # 关键:限制堆外
  -XX:ReservedCodeCacheSize=128m
  -Xss512k                                   # 线程栈从 1MB 降到 512KB
  -XX:+UseContainerSupport                   # JDK10+ 默认开,显式写更明确
  -XX:NativeMemoryTracking=summary           # 保留 NMT,便于随时排查
  -XX:+HeapDumpOnOutOfMemoryError
  -XX:HeapDumpPath=/var/log/myapp/heapdump.hprof
"

MaxRAMPercentage-Xmx 好在哪:容器限额调整时不用改 JVM 参数,堆大小自动跟随。-Xmx2g 在 4GB 容器里是 50%,如果有人把容器调到 2GB,-Xmx2g 就 100% 了必然 OOM。

内存预算(4Gi limit):
  Java Heap (55%)         2252 MB
  Metaspace                256 MB
  DirectMemory             512 MB
  CodeCache                128 MB
  Thread (64 × 512KB)       32 MB
  GC + Internal + 其他     ~400 MB
  -----------------------------
  合计                    ~3580 MB < 4096 MB ✅ 留了 12% 余量
# ✅ ③ K8s 侧:requests 和 limits 设成相同值(Guaranteed QoS)
resources:
  requests:
    cpu: "2"
    memory: 4Gi          # 与 limits 相同 -> Guaranteed,最不容易被驱逐
  limits:
    cpu: "2"             # 见下面的讨论
    memory: 4Gi
# ✅ ④ 加监控和告警,在 OOM 之前发现
# 监控 cgroup 的内存水位,而不是 JVM 堆
- alert: ContainerMemoryHigh
  expr: |
    container_memory_working_set_bytes{pod=~"myapp-.*"}
      / container_spec_memory_limit_bytes > 0.85    
  for: 5m
  annotations:
    summary: "容器内存使用率 {{ $value | humanizePercentage }},接近 limit"

# 线程数告警 —— 本次故障的直接诱因
- alert: JVMThreadLeak
  expr: jvm_threads_current > 300
  for: 10m

container_memory_working_set_bytes 是正确的监控指标——它约等于 anon + 活跃的 file,是 kubelet 判断是否 OOM 的依据。而监控 JVM 堆使用率完全发现不了这次问题(堆一直很健康)。

8.4 验证

# ① 确认参数生效
kubectl exec -it myapp-new -- jcmd 1 VM.flags | tr ' ' '\n' | \
    grep -E "MaxHeapSize|MaxDirectMemory|MaxMetaspace|ThreadStackSize"
# -XX:MaxDirectMemorySize=536870912
# -XX:MaxHeapSize=2361393152          <- 约 2.2GB,是 4Gi 的 55% ✓
# -XX:MaxMetaspaceSize=268435456
# -XX:ThreadStackSize=512

# ② 确认线程数受控
kubectl exec -it myapp-new -- sh -c 'ls /proc/1/task | wc -l'
# 118                                 <- 从 1043 降到 118

# ③ 确认内存构成健康
kubectl exec -it myapp-new -- sh -c '
  limit=$(cat /sys/fs/cgroup/memory.max)
  cur=$(cat /sys/fs/cgroup/memory.current)
  awk -v l=$limit -v c=$cur "BEGIN{printf \"使用率: %.1f%%\n\", c/l*100}"
  grep "^anon " /sys/fs/cgroup/memory.stat
'
# 使用率: 71.3%
# anon 2834567168                     <- 2.8GB,留了充足余量

# ④ NMT 复核
kubectl exec -it myapp-new -- jcmd 1 VM.native_memory summary | grep -E "Total|Java Heap|Thread|Internal"
# Total: reserved=4823MB, committed=2912MB
# -                 Java Heap (reserved=2252MB, committed=2252MB)
# -                    Thread (reserved=68MB, committed=68MB)     <- 从 1043MB 降到 68MB
# -                  Internal (reserved=234MB, committed=234MB)

# ⑤ 观察 48 小时无重启
kubectl get pod -l app=myapp
# NAME                     READY   STATUS    RESTARTS   AGE
# myapp-8f9d2c-p4k7q       1/1     Running   0          2d1h
#                                            ^ 零重启 ✅

8.5 结果

Pod 稳定运行 48 小时零重启,容器内存使用率稳定在 71%,线程数从 1043 降到 118。副作用是 P99 从 240ms 降到 95ms——线程数减少后上下文切换大幅下降(第 7 篇的机制)。

8.6 规律

规律:容器 OOMKilled 先看 memory.statanonfile 构成——anon 高是真实占用(堆、栈、堆外),file 高是 page cache(内核会先回收,通常不至于 OOM)。

规律:容器退出码 137 = 128+9 = 被 SIGKILL;kubectl describeReason: OOMKilled + 宿主机 dmesgMemory cgroup out of memory 就能确认是 cgroup 级 OOM 而非宿主机内存耗尽。

JVM 在容器里的完整内存构成(这是最容易算错的地方):

容器实际占用 = Java Heap        (-Xmx / MaxRAMPercentage)
             + Metaspace       (-XX:MaxMetaspaceSize)
             + 线程栈           (线程数 × -Xss)          <- 最容易忽略
             + CodeCache       (-XX:ReservedCodeCacheSize)
             + DirectMemory    (-XX:MaxDirectMemorySize) <- 第二容易忽略
             + GC 元数据
             + JVM 自身开销

所以 -Xmx 应该只占容器限额的 50~60%,留 40~50% 给非堆部分

各语言的容器内存配置要点

语言 必须设置 说明
Java -XX:MaxRAMPercentage=55 + MaxDirectMemorySize + MaxMetaspaceSize 别用 -Xmx 写死
Go GOMEMLIMIT=<limit×0.9> 1.19+,让 GC 感知容器限额
Node.js --max-old-space-size=<MB> 默认只有 1.5~2GB,与容器无关
Python 无内建限制 靠代码控制,注意 multiprocessing 的进程数

排查容器 OOM 的完整链路

# ① 确认是 OOM 且是哪一级
kubectl describe pod X | grep -A 8 "Last State"      # 退出码 137 + OOMKilled
kubectl exec X -- cat /sys/fs/cgroup/memory.events   # oom_kill 计数
ssh <node> 'dmesg -T | grep -i "out of memory"'      # cgroup 还是宿主机

# ② 看内存构成
kubectl exec X -- grep -E "^(anon|file|slab|sock) " /sys/fs/cgroup/memory.stat

# ③ 语言层面拆解
jcmd 1 VM.native_memory summary                      # Java
curl localhost:6060/debug/pprof/heap?debug=1         # Go

最后一个容易忽略的点:容器的 /dev/shm 默认只有 64MB,且算进 cgroup 内存限制(第 1 篇 §3.2)。往里写大文件会直接触发 OOM 而不是报磁盘满——用 --shm-size 或 K8s 的 emptyDir: {medium: Memory} 调整。


9. 通用排查心法

八个案例走完,提炼出可复用的方法。

9.1 排查的四个原则

① 先看现象,再猜原因
   -> 不要一上来就「我觉得是 XX 问题」然后去找证据
   -> 按 60 秒定位法(第 18 篇)走一遍,让数据把范围收敛

② 分层排除,不要跳层
   -> 网络:网卡 -> 路由 -> ping -> 端口 -> 防火墙 -> 监听地址 -> 安全组
   -> 性能:全局(vmstat) -> 资源(iostat/free) -> 进程(pidstat) -> 线程/调用栈
   -> 跳层猜测会让你在错误的方向上耗很久

③ 每一步都要有明确的判据
   -> 「磁盘看起来有点忙」不是判据
   -> 「await 245ms 是 NVMe 基准的 245 倍,aqu-sz 98 远大于 1」才是

④ 改完必须验证「配置真的生效了」
   -> 写了 LimitNOFILE 不等于生效,要看 /proc/PID/limits
   -> 设了 -Xmx 不等于对,要看 jcmd VM.flags
   -> 配了优雅关闭不等于work,要看退出码是 0 还是 137

9.2 最有信息量的几个判断

这些是本篇八个案例里反复出现的、能立刻收敛方向的判断:

判断 结论
%usr 高 vs %system 业务代码 vs 系统调用
r 列 vs b CPU 排队 vs IO 阻塞
load 高但 us+sy 一定是 D 状态等 IO
await 超基准数倍 + aqu-sz > 1 磁盘真饱和(%util 不算)
available vs free 只看 available
anon vs file(cgroup) 真实占用 vs 可回收缓存
HeapAlloc 涨 vs 不涨(Go) 堆内泄漏 vs 堆外/goroutine 泄漏
CLOSE_WAIT vs TIME_WAIT 应用漏 close vs 主动关闭方正常现象
refused vs timeout(nc) 服务没监听 vs 包被丢弃
退出码 0 / 143 / 137 优雅退出 / 未捕获 TERM / 被 KILL
Result: timeout vs exit-code 卡在依赖 vs 主动退出
nr_throttled / nr_periods 是否被 CPU 限流

9.3 应急操作的正确姿势

# 磁盘满 —— 用 truncate 不用 rm
truncate -s 0 /var/log/app.log
: > /proc/PID/fd/N              # 已删除但被持有的

# 大事务/慢查询 —— 先看清再杀
mysql -e "SHOW FULL PROCESSLIST" | awk '$6 > 60'
mysql -e "KILL <id>"

# 批处理抢资源 —— 降优先级而不是杀掉
ionice -c 3 -p PID              # IO 降到 idle
renice -n 19 -p PID             # CPU 降到最低

# 进程无响应 —— 先留证据再重启
jstack PID > /tmp/stack.txt     # Java
curl localhost:6060/debug/pprof/goroutine?debug=2 > /tmp/goroutine.txt  # Go
cat /proc/PID/stack             # 内核栈
kill -QUIT PID                  # Java: 触发线程 dump 到 stdout
# 然后才 systemctl restart

# 必须先留证据,否则重启后现场就没了

9.4 让下次更快:可观测性清单

这八个案例里,有六个可以通过合适的监控在爆炸前发现

# 必须有的告警(按本篇案例映射)
- 磁盘使用率 > 85%                    # 案例四
- 磁盘「已删除未释放」> 1GB            # 案例四
- fd 使用率 > 70%                     # 案例五
- CLOSE_WAIT 数量 > 1000              # 案例五
- TIME_WAIT 数量 > 端口范围的 50%      # 案例六
- 容器 working_set / limit > 85%       # 案例八
- 线程数 > 300 或 goroutine > 10000    # 案例二、八
- cgroup nr_throttled / nr_periods > 5%  # 第 19 篇
- page cache 命中率骤降                # 第 18 篇
- D 状态进程数 > 5 持续 5 分钟          # 案例三
# 一个简单的巡检脚本,涵盖上面大部分指标
#!/usr/bin/env bash
set -euo pipefail

warn() { logger -p local0.warning -t healthcheck "$*"; echo "WARN: $*" >&2; }

# 磁盘
df -x tmpfs --output=pcent,target | tail -n +2 | while read -r p m; do
    u=${p%\%}; u=${u// /}
    (( u >= 85 )) && warn "磁盘 $m 已用 ${u}%"
done

# 已删除未释放
leaked=$(lsof +L1 2>/dev/null | awk 'NR>1{s+=$7} END{printf "%.0f", s/1024/1024/1024}')
(( ${leaked:-0} >= 1 )) && warn "已删除未释放 ${leaked}GB"

# D 状态进程
dcount=$(ps -eo stat | grep -c '^D' || true)
(( dcount > 5 )) && warn "D 状态进程 ${dcount} 个,检查磁盘 IO"

# CLOSE_WAIT
cw=$(ss -tan state close-wait 2>/dev/null | wc -l)
(( cw > 1000 )) && warn "CLOSE_WAIT ${cw} 个,检查应用是否漏 close"

# TIME_WAIT vs 端口范围
read -r lo hi < /proc/sys/net/ipv4/ip_local_port_range
tw=$(ss -tan state time-wait 2>/dev/null | wc -l)
(( tw > (hi - lo) / 2 )) && warn "TIME_WAIT ${tw} 个,超过可用端口的一半"

**规律:排查能力的上限是可观测性的上限。**每次故障之后,除了修 bug,还要问一句「下次这个问题能不能在爆炸前被发现」——如果不能,就补一个监控指标。这比记住八个案例更有价值。

10. 面试题

Q:线上服务突然变慢,你的排查顺序是什么?

先确认范围(全部接口还是某个、所有实例还是单个、什么时候开始、有无发布),再按 60 秒定位法分层收敛:uptime 看负载趋势 → dmesg -T | tail 先排除 OOM 和硬件错误(这一步不能跳,否则后面的分析都失去意义)→ vmstat 1r(CPU 排队)→ b(IO 阻塞)→ si/so(换页)→ wastus vs sy 的顺序判读 → mpstat -P ALL 1 看核间均衡 → pidstat -urdw 定位进程 → 最后才用 perf/strace 这类有开销的工具。**核心原则是分层排除、每步都有明确判据。**三个容易漏的方向:容器 CPU 限流(nr_throttled)、page cache 命中率骤降、下游依赖变慢(curl -w 分解耗时)。

Q:CPU 100% 但业务量没变,怎么定位到具体代码?

第一步是 pidstat -u -p PID 区分 %usr%system,这决定后面所有方向:%usr 高说明业务代码在算,用 profiler(Java 是 ps -Lo lwp 拿线程 ID 转十六进制去 jstack 里找 nid,Go 用 pprof,通用用 perf top);%system 高说明是系统调用或上下文切换,pprof 完全帮不上忙(它看不到内核态),要用 strace -c -f一个很有用的信号是:如果多个线程的调用栈几乎一致,说明它们卡在同一段代码上,这是最容易定位的情况——本篇案例一里八个线程全部卡在 Pattern$Loop.match,直接指向正则灾难性回溯。

Q:什么是正则的灾难性回溯?怎么识别和预防?

嵌套量词的正则((a+)+(a*)*(\s*\w+\s*)+)在遇到不匹配的长输入时,回溯式引擎需要尝试的路径数是指数级的——30 个字符就可能需要十亿次尝试,单次匹配跑满一个核几十秒。识别特征:CPU 100% 但完全没有 IO、调用栈里大量重复的 Pattern$Loop.match/regexec 帧、只对特定输入触发。Java/Python/JS 用的都是回溯式引擎,都有这个风险;Go 和 Rust 的 RE2 引擎保证线性时间,天然免疫(代价是不支持反向引用和前后查找)。预防:消除嵌套量词、用占有量词(a++)禁止回溯、对外部输入一律加长度上限。

Q:Go 服务内存持续增长但 pprof 的 heap 看不出问题,可能是什么?

先看 runtime.MemStats:如果 Sys 很大而 HeapAlloc 很小,说明泄漏在 Go 堆之外,heap profile 自然看不到。四个方向:① goroutine 泄漏——看 NumGoroutineStackSys,用 pprof/goroutine?debug=2 能看到阻塞点和阻塞时长,如果时长约等于服务运行时长就是永久阻塞;② CGO 泄漏C.malloc 没配对 C.free),Go GC 完全管不到;③ 直接 mmapmunmap;④ 内存未归还 OS(看 HeapReleased)。本篇案例二就是第一种——120 万个 goroutine 阻塞在同一行 c.resultCh <- result 上,因为消费方 panic 退出后没人接收,每个 goroutine 2KB 栈累积成 2.9GB。

Q:goroutine 泄漏最常见的三种原因是什么?

向无人接收的 channel 发送ch <- v,接收方已退出);② 从无人发送的 channel 接收<-ch,发送方忘了 close);③ 忘记设超时或 cancel context(如用 http.DefaultClient 发请求,它没有超时,对端不响应就永久挂着)。通用防御是任何可能阻塞的操作都要有 select + ctx.Done() 或超时分支,并且把 runtime.NumGoroutine() 做成 metric,超过阈值告警——本篇案例里如果有这个监控,问题在第一天就能发现而不是三天后 OOM。

Q:磁盘满了,truncate -s 0rm 有什么区别?

rm 调用 unlink 只删目录项,如果进程还持有该文件的 fd,inode 和数据块不会释放——结果是空间没回来、du 又数不到(目录项没了),造成「df 满但 du 对不上」的僵局,而且会持续到进程重启。truncate -s 0(或 : > file保留 inode 只清空内容,空间立即释放且进程的 fd 继续有效,不需要重启服务。对于已经被 rm 掉的文件,可以用 lsof +L1 找到(NLINK=0),然后 : > /proc/PID/fd/N 截断它的 fd 来释放空间。

Q:Too many open files 报错,ulimit -n 显示 65535,为什么还报?

ulimit -n 反映的是当前 shell 的限制,与服务进程无关。systemd 启动的服务不读 /etc/security/limits.conf(那是 PAM 机制,只对登录会话生效),要在 unit 里配 LimitNOFILE唯一可信的验证是 cat /proc/PID/limits。确认限制没问题后,看 fd 类型分布定位泄漏源:ls -l /proc/PID/fd | awk '{print $NF}' | sort | uniq -c | sort -rn——socket 占大头是连接泄漏,继续用 ss -tanp 看状态;CLOSE-WAIT 堆积就是应用漏了 close()

Q:为什么 Go 里 resp.BodyClose 不读完,连接就无法复用?

http.Client 需要把响应体完整读到 EOF 才能确认这个连接可以安全地归还连接池——因为 HTTP/1.1 是流式协议,剩余未读数据会污染下一个请求。只 Close 不读完时,Transport 只能关闭这个连接而不是复用它。后果是每个请求都新建连接,本机作为主动关闭方产生大量 TIME_WAIT(60 秒),高 QPS 下很快耗尽本地端口,报 cannot assign requested address。正确写法是 defer func() { io.Copy(io.Discard, resp.Body); resp.Body.Close() }()。同时必须显式构造 Client——http.DefaultClient 没有超时MaxIdleConnsPerHost 默认只有 2。

Q:服务起不来、日志还是空的,怎么查?

先看 systemctl statusResult: 字段——timeout 是卡住了(查外部依赖)、exit-code 是主动退出(查日志里的错误)、signal 是被杀了(查 OOM)。「应用日志是空的」通常是个误判:启动早期的 stdout/stderr 都进了 journal,用 journalctl -u xxx -n 50 能看到。如果确认是卡住,用 strace -p PID 看卡在哪个系统调用、ss -tanp | grep PID 看是不是 SYN-SENT(对端不可达)。根治要从代码入手:所有外部依赖调用必须设超时日志初始化放在 main 的第一行错误信息里带上地址和配置项名——把「卡 90 秒后无声失败」变成「3 秒内报出具体不通的依赖」。

Q:容器被 OOMKilled,JVM 堆只设了 2GB 而容器限额 4GB,为什么还会超?

因为容器限额不等于堆大小。JVM 实际占用 = 堆 + Metaspace + 线程栈(线程数 × -Xss + CodeCache + DirectByteBuffer 堆外内存 + GC 元数据。后两项最容易忽略——本篇案例八里 Executors.newCachedThreadPool() 创建了 892 个线程占 1GB 栈,加上 Netty 的 DirectMemory 623MB,总共 4.3GB 必然 OOM。排查用 jcmd PID VM.native_memory summary(需要 -XX:NativeMemoryTracking)拆解各部分。修复:用 -XX:MaxRAMPercentage=55 而不是写死 -Xmx(容器限额调整时自动跟随)、显式设 MaxDirectMemorySizeMaxMetaspaceSize、换成有界线程池。规律:-Xmx 只应占容器限额的 50~60%。

Q:监控上应该盯哪些指标才能在故障爆炸前发现问题?

本篇八个案例里有六个是可以提前发现的。按性价比排序:fd 使用率 > 70%(不要等 100%)、CLOSE_WAIT 数量(直接指向应用 bug)、TIME_WAIT 超过端口范围的一半容器 working_set / limit > 85%(注意监控这个而不是 JVM 堆使用率,堆健康时容器也可能 OOM)、线程数 / goroutine 数nr_throttled / nr_periods > 5%page cache 命中率D 状态进程数持续 > 5、磁盘使用率和「已删除未释放」大小。核心观点:排查能力的上限是可观测性的上限——每次故障后除了修 bug,还要问「下次能不能在爆炸前发现」,不能就补一个指标。


上一篇:Linux-19 namespace 与 cgroup | 下一篇:Linux-21 面试题汇总