目录

Linux-39 线上排查实战案例集:从症状到证据链

目录

前 38 篇已经分别拆开 CPU、内存、调度、锁、文件系统、网络、容器、systemd 和 eBPF。这一篇不再按机制讲,而是把它们重新放回事故现场:用户只告诉你“接口慢了”,你如何避免看到一个异常指标就宣布根因?

线上排查最危险的不是不会命令,而是过早形成故事:CPU 高就扩容、TIME_WAIT 多就改内核参数、容器 OOM 就加内存、DNS 慢就换 resolver。一个现象可能由多个层次产生;一个异常也可能只是结果。可靠方法是不断区分:观察到的事实、尚待验证的假设、能推翻假设的反证,以及修复后的因果验证。

本文所有案例使用统一结构:

现象 -> 影响范围 -> 时间线 -> 假设
     -> 证据与反证 -> 根因
     -> 止血 -> 长期修复 -> 验证 -> 防复发

案例中的地址、数值和服务名均为教学示例。生产执行抓包、ptrace、eBPF、配置修改、重启或流量切换前,应遵循授权、变更、隐私和回滚流程。

先看五个问题:

  1. 第一分钟应该收集什么,才能在止血后仍保留故障证据?
  2. “相关”怎样升级成“因果”?修复后为什么还需要对照和反证?
  3. CPU 平均值、Go heap、磁盘利用率、丢包率这些指标为何经常指向错误层?
  4. 什么情况下先止血,什么情况下继续观察?怎样避免排障动作扩大事故?
  5. 复盘应留下哪些可执行改进,而不是“加强监控、提高稳定性”?

1. 一套不会因工具变化而失效的方法

1.1 先定义用户影响

不要从机器指标开始。先问:

谁受影响:全部用户、某区域、某租户、某版本?
什么失败:超时、错误、数据错、吞吐下降、连接失败?
何时开始:绝对时间、持续还是周期?
多严重:请求量、错误预算、收入/数据风险?
是否仍在扩大:流量、队列、资源和重试趋势?

同样是 CPU 100%,若请求正常可能只是高效满载;CPU 20%但所有请求卡住,可能是锁、quota、IO或下游。事故等级由用户影响和恢复风险决定,不由某资源颜色决定。

1.2 建立共同时间轴

记录:

T-30m 最近部署/配置/流量/证书/DNS/节点变化
T0    告警首次触发
T+3m  症状扩大到哪些维度
T+8m  执行了什么动作
T+10m 指标如何变化

机器 wall clock要确认同步;内核 monotonic事件需带 boot ID转换。dashboard聚合窗口会让峰值看起来比实际晚,日志 ingestion也有延迟。事件时间与接收时间不要混为一谈。

1.3 区分事实、假设与结论

示例:

事实:12:01-12:06 P99 每约100ms出现台阶,cpu.stat throttled_usec增长。
假设:cgroup CPU quota导致请求等待下一period。
待验证:Go G是否runnable、OS thread是否因quota未运行。
反证:若提高quota后P99不变,或throttle只发生在非关键sidecar,假设不成立。

“CPU quota导致延迟”在验证前不是事实。事故频道中显式标注 [FACT][HYPOTHESIS][ACTION] 能减少故事被转述成结论。

1.4 先收集易失证据

重启会清空:

  • 进程 stack、goroutine、heap与fd状态
  • cgroup目录及其累计 events
  • socket队列、conntrack和临时端口分布
  • /proc/PID 数据
  • 内核/应用内存中的短时 trace buffer

在不延误必要止血的前提下,先抓短快照:状态、关键 counters、profile、最近日志和配置版本。若正在数据损坏或安全事件,隔离优先,不应为“证据完整”继续放任影响。

1.5 每次只改变可解释的变量

同时重启、扩容、调 timeout、改 DNS、关防火墙,即使恢复也不知道哪个动作有效,还可能掩盖根因。紧急时不得不做组合动作,也要逐项记录并在事后受控复现。

1.6 修复必须有验证指标

修复前:P99=800ms, throttled=40%, throughput=10k/s
动作:quota 2CPU -> 4CPU
预期:throttle显著下降,P99台阶消失,throughput不降
副作用:节点CPU与成本上升
观察窗:30m peak + next daily peak
回滚条件:error/CPU/noise neighbor恶化

“重启后好了”只是恢复事实,不是根因证明。


2. 第一分钟:安全快照与分层判断

2.1 应用与流量

request rate / success / timeout / reject
latency histogram而非只看平均
按region/version/route/tenant的有限维度
in-flight / queue / pool wait
最近部署、feature flag、配置变更

先找受影响维度能大幅缩小系统范围:只有新版本、单节点、单upstream或大请求,假设不同。

2.2 主机和 cgroup

date -Ins
uptime
vmstat 1 5
mpstat -P ALL 1 5
pidstat -u -w -d -p "$PID" 1 5
cat /proc/pressure/{cpu,memory,io}

CG=/sys/fs/cgroup/path/to/workload
cat "$CG/cpu.max" "$CG/cpu.stat" "$CG/cpu.pressure"
cat "$CG/memory.current" "$CG/memory.max" "$CG/memory.events"
cat "$CG/io.stat" "$CG/io.pressure"
cat "$CG/pids.current" "$CG/pids.max"

命令路径需按实际 cgroup层级。采集结果要附 host/container/cgroup ID和时间。

2.3 进程与 socket

ls /proc/"$PID"/fd | wc -l
cat /proc/"$PID"/limits
ss -s
ss -ltnp
ss -tinp

高 fd、TIME_WAIT、Recv-Q/Send-Q都只是线索。需要看增长速度、状态分布、对应remote和业务连接池。

2.4 Go 快照

curl -m 35 -o cpu.pprof \
  'http://127.0.0.1:6060/debug/pprof/profile?seconds=30'
curl -m 10 -o heap.pprof \
  'http://127.0.0.1:6060/debug/pprof/heap'
curl -m 10 -o goroutines.txt \
  'http://127.0.0.1:6060/debug/pprof/goroutine?debug=2'

只在已授权管理接口执行,并限制并发/持续时间。CPU已极端饱和时,30秒 profile可能加剧影响;可先5–10秒或在一个canary实例采集。

2.5 内核和服务日志

journalctl -u api.service --since '-15 min' --no-pager
journalctl -k --since '-15 min' --no-pager
systemctl status api.service --no-pager -l

查 OOM、I/O error、NETDEV watchdog、conntrack full、segfault、restart、start-limit。日志没有结果也要检查 journald/exporter drop。


3. 案例一:平均 CPU 只有两核,P99 却每 100ms 跳一次

3.1 现象

Go API运行在64核节点,容器限制2 CPU。午间流量增加后:

平均CPU:约2 cores,未超过limit
P50:20ms
P99:周期性落在100/200ms附近
数据库和缓存span正常
错误率不高,但客户端开始hedge/retry

值班最初认为“CPU没满,可能网络抖动”。

3.2 假设

候选:

  1. cgroup CFS bandwidth quota提前耗尽
  2. Go GC stop-the-world恰好约100ms
  3. 下游每100ms批量flush
  4. 客户端/代理的100ms timer
  5. 节点CPU steal或softirq

3.3 证据

cat "$CG/cpu.max"
# 200000 100000

watch -n 1 cat "$CG/cpu.stat"

故障窗口:

nr_periods      +300
nr_throttled    +287
throttled_usec  快速增长

Go启动日志:

NumCPU=64 GOMAXPROCS=64

Go trace显示大量 goroutine runnable;CPU profile没有100ms函数。调度采样显示多个M并行运行约数十毫秒后,整个cgroup长时间不上CPU。

机制:

quota=200ms CPU / period=100ms
8个线程并行运行25ms
-> 已消费200ms CPU time
-> 剩余约75ms wall time被throttle

3.4 反证

  • 数据库span在慢请求中仍短
  • GC pause只有亚毫秒到数毫秒,不匹配100ms台阶
  • 同节点无quota的canary没有该周期
  • 网络重传和RTT无同步变化

3.5 止血

将受影响实例 CPU limit临时从2提高到4,并限制入口并发,避免重试继续放大。修改前确认节点容量和邻居影响。

3.6 长期修复

  • 使用能感知容器额度的Go版本/自动设置GOMAXPROCS,或显式按quota配置
  • 减少无界并行worker和突发分配
  • 为CPU-bound服务使用合理request/limit;评估weight替代过紧硬quota
  • 客户端retry budget和jitter
  • 告警关联P99、nr_throttled比例而非只看平均CPU

3.7 验证

负载回放下比较:

P99台阶消失
throttled_usec接近0
throughput保持
GC CPU未显著恶化
node CPU仍有安全余量

结论不是“所有quota都不好”,而是并行度与period额度不匹配。


4. 案例二:Go heap 只有 600MB,1GiB 容器却 OOMKilled

4.1 现象

文件代理服务每隔数小时被重启:

container status: OOMKilled
memory.max: 1GiB
pprof heap inuse: 600MiB
Go GC正常,live heap无持续增长

团队怀疑“内核误杀”或Go内存泄漏。

4.2 假设

  1. cgo/native分配未被heap profile记录
  2. page cache/socket/kernel memory占用
  3. 同Pod sidecar共享父上限
  4. Go RSS归还延迟
  5. 父cgroup先达到memory.max
  6. 临时大buffer峰值恰好没被pprof捕获

4.3 证据

在旧容器销毁前持续采集:

cat "$CG/memory.current"
cat "$CG/memory.events"
cat "$CG/memory.stat"
cat "$CG/memory.swap.current" "$CG/memory.swap.max"

事故前:

memory.current ≈ 1024MiB
memory.events: max/oom/oom_kill增长
anon          ≈ 650MiB
file          ≈ 80MiB
sock          ≈ 180MiB
kernel/slab   其余

ss -m 与应用指标显示数千慢客户端,每条连接有较大发送队列;服务不断读取上游文件并向慢下游写,用户态pending buffer和socket send memory同时增长。

4.4 反证

  • heap profile按连接对象聚合后基本稳定,不是经典永久泄漏
  • sidecar内存小,父cgroup未先触限
  • 没有显著cgo分配
  • 删除page cache不能解释高sock与pending bytes

4.5 根因

缺少慢客户端背压:handler持续从上游读取并把数据排入用户态/内核发送队列。Go heap快照只看到部分用户buffer,memcg还记账socket与其他内存;瞬时总和触发OOM。

4.6 止血

  • 降低每实例并发下载数
  • 暂时缩小单连接用户态buffer/队列上限
  • 对最慢客户端设置写deadline并关闭
  • 在容量允许下暂增memory limit,避免重启风暴

增内存只是恢复手段,不是根治。

4.7 长期修复

per-connection pending bytes high watermark
-> 暂停上游读取
-> 等下游flush到low watermark
-> 超过deadline/总量则中止

同时按连接跟踪 user pending、socket queue、吞吐和关闭原因;GOMEMLIMIT为非Go内存留余量。

4.8 验证

慢速客户端压测下:memory.current形成平台而非线性增长;超过限额的连接被有界关闭;正常用户P99不受慢用户拖累;memory.events不再增长。


5. 案例三:数据库 commit P99 抖动,但磁盘 %util 只有 40%

5.1 现象

订单服务每5秒出现一次commit延迟峰:

transaction P99: 10ms -> 300ms
CPU正常
磁盘吞吐和%util不高
应用log显示fsync偶发慢

“磁盘没满”让调查一度转向数据库锁。

5.2 假设

  1. WAL fsync等待设备flush/journal
  2. cgroup IO throttle
  3. writeback/dirty page周期压力
  4. 数据库group commit锁竞争
  5. 云盘burst credit或宿主噪声
  6. 文件系统错误/设备重试

5.3 证据

iostat -xz 1
pidstat -d -p "$PID" 1
cat "$CG/io.stat" "$CG/io.pressure"
grep -E '^(Dirty|Writeback):' /proc/meminfo

短时过滤 syscall:

sudo timeout 20s strace -ff -ttT -p "$PID" \
  -e trace=fsync,fdatasync,pwrite64

结果:峰值时多个事务都卡同一个 fdatasync;block issue/complete trace显示设备请求本身大多<10ms,但每5秒文件系统journal commit/flush出现长等待。云盘指标显示flush latency与burst credit下降同步。

5.4 反证

  • mutex profile中WAL lock等待是结果:leader在fsync,followers等group commit
  • 提高DB worker数不改善
  • page cache命中与普通write吞吐正常,不代表flush正常
  • %util 聚合无法表达flush尾延迟和设备内部credit

5.5 止血

  • 临时切换到有余量的存储/提高云盘性能等级
  • 在业务容许的durability边界内增加group commit批量
  • 限制非关键后台写和checkpoint并发

不能直接删除fsync;那会改变订单提交的抗崩溃承诺。

5.6 长期修复

  • 为WAL选具有稳定flush latency的存储
  • 监控fsync histogram、cloud credit、journal/IO pressure
  • 调整checkpoint避免与峰值重叠
  • 容量测试包含sync write而非只测顺序吞吐
  • 明确数据库事务durability,不用mount参数“偷性能”

5.7 验证

故障负载和断电/进程kill恢复测试同时通过:commit P99稳定,吞吐满足,WAL恢复无已确认事务丢失。


6. 案例四:网络 P99 高,服务端 CPU 与 handler 都正常

6.1 现象

只有一个可用区客户端访问API变慢:

server handler duration正常
client observed latency高
server error少
TCP retransmission上升
同区域小请求影响轻,大响应影响重

6.2 假设

  1. 路径丢包/拥塞
  2. MTU/PMTUD black hole
  3. 服务端Send-Q和慢客户端
  4. NIC RX/TX drop
  5. 跨区路由变化
  6. TLS record/代理buffer

6.3 证据

服务端:

ss -tinp '( sport = :443 )'
nstat -az TcpRetransSegs
ip -s link show dev eth0
ethtool -S eth0

双端窄抓包发现:SYN、TLS小record正常;服务端发送接近MTU的大segment后重复重传,路径没有返回预期ACK,也看不到ICMP Packet Too Big。受影响区新部署overlay封装增加50字节,但Pod MTU仍1500。

inner 1500 + overlay 50 > underlay 1500
DF set
ICMP too-big 被中间策略丢弃

6.4 反证

  • NIC drop计数不增
  • 服务端Send-Q增长是重传/无ACK结果,不是handler写过快根因
  • 关闭TLS后大payload仍失败
  • 小payload成功排除DNS/connect/listener

6.5 止血

将受影响节点/Pod MTU改为与overlay匹配的1450(按实际header计算),或临时调整路由/策略允许必要ICMP。变更网络时先canary并准备回滚。

6.6 长期修复

  • CNI按underlay与encapsulation统一计算MTU
  • 保留ICMP too-big控制报文
  • 部署前做跨区大包/IPv4/IPv6 PMTU测试
  • 监控retrans、MSS、ICMP和按区域SLO

6.7 验证

不同payload、TLS certificate、大response和长连接均通过;抓包不再重传;客户端与服务端duration差值恢复。


7. 案例五:只有域名请求慢,直接访问 IP 正常

7.1 现象

Go服务向依赖发请求:

curl https://10.0.8.12 偶尔正常
通过 service.example.local 经常2s超时
应用错误:lookup ... i/o timeout
CPU/网络接口正常

7.2 假设

  1. DNS resolver过载
  2. search/ndots产生多次查询
  3. UDP/53可达但TCP/53被阻断
  4. 容器 /etc/resolv.conf 指向错误loopback
  5. conntrack/UDP表压力
  6. Go纯resolver与cgo/NSS行为差异

7.3 证据

在与应用相同network + mount namespace:

cat /etc/resolv.conf
getent ahosts service.example.local

抓包按resolver过滤,看到每次短名先尝试多个search suffix,部分大DNS响应带TC flag,客户端随后发TCP/53但network policy只允许UDP/53。Go日志把这些阶段统一包装成lookup timeout。

7.4 反证

  • 目标IP connect/TLS正常
  • UDP小响应域名稳定,只有较大/特定记录失败
  • CoreDNS CPU并未饱和
  • 增大应用HTTP timeout不改变lookup阶段

7.5 止血

放行到受信resolver的TCP/53;使用完整FQDN减少不必要search;必要时降低异常记录集或切换健康resolver。

7.6 长期修复

  • DNS policy同时考虑UDP/TCP
  • 合理ndots/search,避免请求放大
  • 按resolver/result记录DNS latency与错误
  • CoreDNS/上游cache容量与负载测试包含TCP fallback
  • Go版本/解析模式变化纳入发布验证

7.7 验证

强制查询可产生截断的大记录,确认TCP fallback成功;DNS P99和查询放大下降,HTTP timeout恢复。


8. 案例六:连接池“已满”,数据库却很空闲

8.1 现象

API超时增多:

DB CPU 20%
DB active sessions不高
Go sql.DB WaitCount/WaitDuration快速增长
MaxOpenConns=100
请求goroutine数暴涨

第一反应是把池从100调到500。

8.2 假设

  1. 连接泄漏:Rows/Tx未关闭
  2. 少数慢query长期占连接
  3. 下游连接半断开,健康检查等待
  4. transaction内调用外部RPC
  5. pool设置过小
  6. 请求并发缺少上限

8.3 证据

Goroutine dump大量栈停在 database/sql.(*DB).conn 等待;少数goroutine持有transaction并调用外部HTTP。trace显示外部服务P99 5s,事务从查询前开始,到HTTP返回后才commit。

数据库看到真正执行SQL的时间很短,所以active低;连接却被应用transaction owner持有。

8.4 反证

  • Rows/Tx最终都defer Close/Rollback,没有永久引用泄漏
  • SQL server query latency正常
  • 临时把池调500仅短时缓解,随后更多连接同时被占,外部服务压力更大
  • 连接建立没有明显延迟

8.5 根因

事务边界过宽,把不需要数据库原子性的外部RPC放在事务中;慢依赖消耗稀缺连接,等待goroutine又提高内存和超时重试。

8.6 止血

  • 限制该route并发
  • 对外部RPC设置更短deadline/熔断
  • 在语义允许时提前结束事务
  • 小幅增加池仅作为有上限缓冲

8.7 长期修复

read/validate outside transaction
-> begin tx
-> minimal DB operations
-> commit
-> external side effect via outbox/idempotent workflow

按operation暴露pool wait、in-use、idle、transaction duration,给慢事务采样stack/trace。

8.8 验证

外部服务故障注入时,DB transaction duration仍短,pool wait有界,入口快速降级而不产生goroutine海啸。


9. 案例七:CPU profile 正常,吞吐下降一半

9.1 现象

部署新版本后:

CPU利用率约60%,无明显热点变化
吞吐下降45%
P99升高
Go mutex profile显示某锁等待增加
context switch增加

9.2 假设

  1. 全局锁竞争/lock convoy
  2. false sharing/cache line bouncing
  3. GC assist
  4. logging同步锁
  5. cgroup quota
  6. scheduler migration/NUMA

9.3 证据

新版本把每请求统计写入一个全局map并在同一mutex下更新多个label。CPU profile只采on-CPU;大量goroutine off-CPU等mutex。mutex profile的阻塞栈指向metrics helper,lock holder在格式化动态label并可能扩容map。

perf显示cache misses/context switches增长;禁用该实验metric的canary吞吐恢复。

9.4 反证

  • cpu.stat无throttle
  • GC频率与assist没有足够变化
  • 下游latency正常
  • 日志量未增加
  • 单线程benchmark差异小,多核并发才恶化,符合共享锁

9.5 止血

关闭feature flag/回滚metric;不能为保留观测而牺牲服务可用性。

9.6 长期修复

  • metric label白名单和预注册
  • 使用库的并发安全counter,不在热路径构建动态series
  • per-shard/per-CPU聚合并周期合并
  • contention benchmark覆盖目标核数
  • mutex/block profile按需动态开启

9.7 验证

多核负载下吞吐、P99、mutex wait、context switch和series cardinality均回到预算;确认指标仍语义正确。


10. 案例八:服务报 too many open files,但连接数并不高

10.1 现象

运行三天后:

accept: too many open files
HTTP连接只有约5k
LimitNOFILE=65536
/proc/PID/fd数量接近65536并持续增长
重启立即恢复

10.2 假设

  1. socket连接泄漏
  2. 打开文件未close
  3. inotify/eventfd/epollfd泄漏
  4. TLS/HTTP response body未close导致连接不复用
  5. debug/profile文件泄漏
  6. fork子进程继承fd

10.3 证据

ls -l /proc/"$PID"/fd | head
lsof -nP -p "$PID" | awk '{print $5}' | sort | uniq -c

大多数fd指向 regular files under /tmp/export-*。代码路径为每次导出创建临时文件,在成功路径defer Close,错误路径在设置defer前return。磁盘上部分文件已unlink但fd仍打开:

lsof +L1 -p "$PID"

Go goroutine数量和TCP socket数稳定。

10.4 反证

  • 提高NOFILE只延长故障时间
  • HTTP transport idle连接未接近上限
  • fd类型分布明确指向临时文件而非socket
  • epoll/eventfd数量稳定

10.5 止血

滚动重启释放fd;限流/关闭导出功能;保留一个实例现场用于证据,不在全部实例同时重启前丢失线索。

10.6 修复

获取资源后立即建立close责任:

f, err := os.CreateTemp(dir, "export-*")
if err != nil {
    return err
}
defer func() {
    _ = f.Close()
    _ = os.Remove(f.Name())
}()

if err := prepare(f); err != nil {
    return err
}

若循环中大量文件,不能把defer累积到外层函数结束,应抽小函数或显式close并检查错误。

10.7 验证

错误注入覆盖每个return路径;fd数量在长期soak中围绕并发平台波动,deleted-open不增长;fd使用率提前告警并按类型采样。


11. 案例九:内存不断涨,但不是 Go 对象泄漏

11.1 现象

图像服务:

Go heap after GC稳定在400MiB
RSS从500MiB涨到4GiB
容器memory.current同步增长
heap profile无大对象增长

11.2 假设

  1. cgo C库malloc未释放
  2. mmap映射未unmap
  3. Go idle span未归还
  4. page cache
  5. thread stack增长
  6. allocator fragmentation

11.3 证据

cat /proc/"$PID"/smaps_rollup
cat "$CG/memory.stat"
pmap -x "$PID" | tail

anon RSS高,file cache不大;每次处理图像调用C库创建context,成功路径destroy,解码错误路径漏掉。用受控故障输入复现,native allocation随错误请求增长;Go heap不变。

11.4 反证

  • debug.FreeOSMemory不能释放该内存
  • 降低Go GC目标只增加CPU,不改变RSS斜率
  • 无大量线程
  • smaps显示匿名映射归属于native allocator区域

11.5 止血与修复

限制错误图像并发/大小,滚动重启;在C资源创建后立即defer封装destroy,使用RAII式Go wrapper和finalizer仅作告警而非主要回收;升级修复后的native库。

11.6 验证

native fault test和长时间fuzz/soak下RSS平台稳定;监控Go managed、process RSS、memcg anon分别展示,防止再次只看heap。


12. 案例十:日志系统故障拖垮业务

12.1 现象

集中日志后端不可用后:

API P99上升
磁盘写和空间快速增长
应用CPU用于JSON logging
错误日志每请求重复数十条
最终节点磁盘满,数据库也受影响

12.2 假设

  1. 同步日志 exporter阻塞请求
  2. 本地队列无界
  3. error retry无退避
  4. 日志采集agent反复读取/写临时文件
  5. 高基数索引导致后端拒绝
  6. journald rate limit/drop

12.3 证据

block/mutex profile显示请求goroutine等待logger queue mutex;queue length无上限。后端429后每条日志立即重试并追加本地spool,同一错误含request body和stack。磁盘/var与数据库共享。

12.4 反证

  • 业务依赖本身正常
  • 关闭debug/error重复日志的canary立即恢复
  • 磁盘IO由log spool进程/文件占主导
  • 网络带宽未满,问题是后端拒绝与本地策略

12.5 止血

  • 降低非关键日志级别/采样
  • 暂停无界重试,保留drop计数
  • 限制spool容量并保护业务磁盘
  • 对敏感request body停止采集
  • 恢复/切换日志后端但避免积压瞬间洪峰回放

12.6 长期修复

业务线程 -> 有界非阻塞queue
queue满 -> 按优先级drop + metric
export -> batch + backoff + jitter + retry budget
local spool -> 独立quota/filesystem + max age/size

审计日志若必须可靠,使用独立有保证通道,不与普通debug telemetry混合。

12.7 验证

断开日志后端故障注入:业务SLO基本不受影响,queue/spool有界,drop告警触发,恢复后发送速率受控且无敏感泄漏。


13. 案例十一:TIME_WAIT 很多,但真正问题是重试风暴

13.1 现象

客户端节点:

TIME_WAIT 20万
connect EADDRNOTAVAIL
上游CPU不高
新连接率突然10倍

团队准备启用激进TIME_WAIT复用参数。

13.2 假设

  1. HTTP keep-alive失效
  2. 上游主动关闭
  3. 客户端transport每请求新建
  4. DNS轮转导致pool key碎片
  5. retry无预算
  6. 临时端口范围过窄

13.3 证据

部署变更把自定义http.Transport从进程级移进请求函数,每次创建并在请求后丢弃;连接无法复用。另一个feature把超时请求最多立即重试3次。连接建立率和TIME_WAIT同步增长,源端口对单一目标耗尽。

13.4 反证

  • 上游没有主动大量FIN,主动关闭主要在客户端
  • 扩大端口范围延后失败但新建率不变
  • 网络RTT稳定
  • 恢复共享transport的canary连接复用率恢复

13.5 修复

  • 复用进程级http.Client/Transport
  • 设置合理MaxIdleConns/PerHost、idle timeout
  • 有界retry + backoff/jitter/幂等
  • 监控new connection rate、reuse、pool wait和端口使用

13.6 验证

连接新建率下降数量级,TIME_WAIT自然回落,端口错误消失。未通过削弱TCP安全语义“清理状态”。


14. 案例十二:应用“随机”卡死,实际是锁顺序死锁

14.1 现象

服务仍存活:

CPU接近0
健康检查超时
连接仍accept但handler不完成
goroutine从几千涨到几十万
无panic/error

14.2 假设

  1. 全局deadlock
  2. 下游无限等待
  3. channel无消费者
  4. fd耗尽
  5. runtime scheduler问题
  6. STW/内核D状态

14.3 证据

goroutine dump显示:

路径A:持有 cache.mu -> 等 config.mu
路径B:持有 config.mu -> 等 cache.mu
其他请求排队等两把锁

Go runtime没有报“all goroutines asleep”,因为网络poller、timer和后台goroutine仍可运行。mutex profile在死锁后也不一定给出完整持有者因果,dump和代码锁顺序才是关键。

14.4 反证

  • 下游无请求增加
  • fd、CPU quota、memory正常
  • OS threads未处D状态
  • 强制关闭网络不能让已死锁路径前进

14.5 止血

从负载均衡摘除,保留dump/trace后重启实例;逐个滚动,避免全服务同时失去容量。若写操作可能部分完成,按业务协议确认一致性。

14.6 修复

  • 定义全局锁顺序:config -> cache
  • 重构避免同时持两锁,复制不可变快照后在锁外工作
  • 禁止锁内网络/磁盘调用
  • 并发测试、race detector、故障调度
  • watchdog关注请求进展而非仅进程存活

14.7 验证

定向并发测试重复旧交错数百万次;线上canary启用短时mutex/block profile,锁等待保持预算;健康检查包含关键事件循环progress。


15. 案例十三:服务频繁重启,根因不是应用崩溃

15.1 现象

systemd service每隔30秒重启:

application log最后一行正常
没有panic
systemctl status: result=timeout / signal=KILL
restart count增长

15.2 假设

  1. Type=notify未发READY导致TimeoutStartSec
  2. watchdog未喂
  3. memory OOM
  4. stop timeout被SIGKILL
  5. health manager主动重启
  6. ExecStart包装shell main PID错误

15.3 证据

systemctl show api.service \
  -p Type -p Result -p ExecMainCode -p ExecMainStatus \
  -p WatchdogUSec -p TimeoutStartUSec -p NRestarts
journalctl -u api.service -b -o short-monotonic
systemctl cat api.service

unit被改为Type=notify,应用版本尚未实现sd_notify;systemd等30秒判定启动超时,发送TERM/KILL,Restart=always再启动。应用本身一直能临时接流量,造成周期断连。

15.4 反证

  • memory.events无oom
  • core/panic不存在
  • 每次KILL精确匹配TimeoutStartSec
  • 改回Type=simple的canary稳定

15.5 修复

短期改回Type=exec/simple;长期在应用完成listener和必要初始化后正确发送READY,增加unit集成测试。StartLimit避免配置错误无限重启。

15.6 验证

ActiveState=active、启动时间符合预期;故意不发READY时测试环境能按timeout失败;正常SIGTERM graceful流程通过。


16. 案例十四:数据删除后磁盘空间没有回来

16.1 现象

日志目录已删除数百GB:

du -sh /var/log/app: 10G
df -h /var: 95% used
应用仍写日志

16.2 假设

  1. deleted-open文件
  2. filesystem snapshot
  3. hidden mount
  4. reserved blocks/metadata
  5. sparse file统计差异
  6. 容器overlay writable layer

16.3 证据

lsof +L1
ls -l /proc/"$PID"/fd | grep deleted
df -h /var
du -xsh /var/*
findmnt -T /var/log/app

应用logger在logrotate后仍持有旧inode并继续写,目录项已unlink但fd引用让blocks无法回收。

16.4 反证

  • 无snapshot增长
  • mount topology正常
  • lsof +L1大小恰好解释df-du差额
  • 重启应用后空间立即释放

16.5 止血与修复

向应用发送已支持的reopen信号/API,或滚动重启;不要用> /proc/PID/fd/N随意截断未知文件,可能破坏应用与审计。配置logrotate使用正确postrotate,或让应用写stdout交给日志系统;监控deleted-open。

16.6 验证

轮转演练后新fd指向新inode,旧fd关闭,df空间回收,日志无丢失/重复。


17. 案例十五:一次“优化”关闭了零拷贝,CPU 反而升高

17.1 现象

静态文件服务加入统一metrics wrapper后:

吞吐相同
CPU增加70%
perf出现copy/memmove和TLS外额外开销
strace不再看到sendfile

17.2 假设

  1. wrapper破坏Go io.ReaderFrom/WriterTo优化分派
  2. TLS路径本来就不走sendfile
  3. buffer变小
  4. page cache miss
  5. syscall数量增加

17.3 证据

plain HTTP路径原来是 *os.File -> *net.TCPConnio.Copy可走sendfile。新wrapper只实现Write,把具体TCPConn隐藏,io.Copy退回用户态buffer循环。HTTPS本来就走用户态TLS,变化主要在plain internal流量。

sudo timeout 10s strace -ff -p "$PID" \
  -e trace=sendfile,read,write

17.4 反证

  • page faults/cache命中相近
  • 文件大小/流量组成不变
  • 移除wrapper的canary恢复sendfile和CPU
  • 增大buffer仅部分改善,不恢复原路径

17.5 修复

让wrapper在语义正确时透传ReaderFrom/专用接口,或把metrics放在不破坏动态类型的层;测试plain/TLS/限速/压缩各路径。不要为了“强制零拷贝”绕过需要修改字节的TLS/压缩。

17.6 验证

strace/perf确认目标路径恢复,字节/错误metrics仍准确;吞吐、CPU、RSS、慢客户端内存均满足。


18. 常见误判与反证清单

18.1 CPU 高

可能:真实计算、spin、GC、softirq、logging、profile、steal补偿。反证问题:

on-CPU stack是什么?
user/system/softirq分别多少?
是否quota/affinity?
吞吐是否同步增长?

18.2 CPU 低但慢

可能:锁、IO、网络、下游、run queue、quota、线程池/连接池。看off-CPU、PSI、queue和trace,不要因CPU低就扩实例。

18.3 内存高

可能:live heap、native、page cache、socket、slab、fragmentation、同cgroup邻居。看memory.stat、smaps、语言heap和时间趋势。

18.4 磁盘util高/低

高可能是健康顺序吞吐;低也可能flush尾延迟、单队列、cgroup throttle或文件系统锁。看await、queue、operation类型、fsync、PSI与应用语义。

18.5 TIME_WAIT 多

它是主动关闭后的协议状态,不等于泄漏。看新建率、主动关闭方、连接池、端口压力和实际错误。

18.6 大量 goroutine

可能是健康长连接,也可能pool wait、channel、无deadline、死锁。按stack状态和生命周期增长率分类,不能只设固定数量阈值。

18.7 重传增加

可能真实网络丢包、MTU、接收端CPU/队列、拥塞、虚拟网络drop。双端抓包与接口/softirq指标找丢失边界。

18.8 重启恢复

可能释放泄漏、清cache/队列/锁/连接、迁移节点,也可能恰逢外部恢复。重启证明“状态相关”,不证明状态来源。


19. 止血动作的风险矩阵

动作 可能收益 风险/丢失证据
重启单实例 快速清理进程状态 丢heap/fd/stack,未知请求结果
扩容 降低单实例压力 加剧DB/DNS/下游连接风暴
提高timeout 减少表面超时 队列/内存更大,用户等更久
增加buffer 吸收突发 排队延迟和内存上升
增加连接池 降低pool wait 压垮数据库,扩大事务并发
关闭日志/采样 降低观测开销 丢诊断/审计,需分级
调大limit 恢复容量 把压力转给节点/邻居
回滚 消除变更 数据/schema/feature兼容风险
切流 隔离故障域 目标区域容量与缓存冷启动

选择原则:优先可逆、blast radius小、预期明确的动作;设观察和回滚条件;一人执行、一人复核;不要多人同时改同一系统。


20. 故障期间如何使用高开销工具

20.1 从低到高

已有metrics/counters
-> /proc/ss/iostat/pidstat短快照
-> Go pprof低频采样
-> filtered strace/perf
-> targeted BPF/tracepoint
-> packet capture/full execution trace

不是每次都走到底。上一层已经得到强证据就停止增加风险。

20.2 预先定义采集配方

#!/usr/bin/env bash
set -euo pipefail
out="incident-$(date +%Y%m%dT%H%M%S%z)"
mkdir -m 0700 "$out"

date -Ins >"$out/time.txt"
uptime >"$out/uptime.txt"
vmstat 1 5 >"$out/vmstat.txt"
ss -s >"$out/ss-summary.txt"

生产脚本还应:验证PID/host、timeout每个命令、限制文件大小、脱敏、记录失败、不执行配置更改,并由安全/运维review。本文不建议把未知环境数据自动打包上传外部。

20.3 Profile 代表窗口,不代表永恒

30秒CPU profile只描述那30秒on-CPU样本;事故若有1秒尖峰,可能被平均。用告警触发flight recorder、连续profile或多个短窗口;报告附采集时间和流量。

20.4 抓包最小化

sudo timeout 30s tcpdump -ni eth0 \
  -s 128 -c 100000 \
  'host 203.0.113.20 and tcp port 443' \
  -w incident.pcap

snaplen=128可能足够看header且减少payload隐私,但协议/VLAN/IPv6扩展头可能需要更多;根据目的选择。pcap本身是敏感资产,限制权限和保留。

20.5 eBPF 要有 drop 和 kill switch

任何临时BPF工具应限定PID/cgroup、map size、采样率、持续时间,监控lost/drop;使用timeout/link生命周期确保detach。不要在生产运行无界printf或按用户值创建map key。


21. 从事故到容量模型

21.1 找到饱和前拐点

压测逐步提高arrival rate,记录:

throughput
P50/P95/P99 + timeout/reject
in-flight/queue
CPU quota/throttle/PSI
memory/GC
pool/DB/network/IO

当吞吐不再线性增长而queue与latency陡升,就是饱和拐点。容量应留故障、发布、节点迁移和流量偏斜余量,而非运行在实验最大值。

21.2 有界队列与过载保护

无界队列把过载转换成高延迟和OOM;有界队列能尽早reject并保护已接请求:

arrival > service rate
-> queue reaches bound
-> reject/load shed
-> client receives explicit retryable result

客户端也要retry budget,否则reject转成重试风暴。

21.3 容量按最稀缺资源

CPU服务看cycles/request;内存服务看bytes/in-flight;数据库看connection/transaction/WAL;网络代理看pps、bandwidth、socket memory。不能统一用QPS表示所有容量。

21.4 灰度必须包含资源回归

功能正确的canary也可能:alloc/request +30%、syscall翻倍、连接复用消失、metric series暴增。发布门槛应包括SLO、CPU/request、memory/in-flight、connection rate、IO与telemetry成本。


22. 复盘:从“人犯错”转成系统改进

22.1 一份有用的时间线

记录客观事件、信息当时可见性和决策依据:

12:00 deploy 10%
12:07 first latency alert
12:10 operator sees CPU average normal
12:14 throttle hypothesis
12:18 captures cpu.stat/Go trace
12:22 raises quota on one canary
12:24 canary recovers
12:30 rollout fix

不要用事后知识评价12:10为何没立即知道根因。

22.2 根因不是最后一个报错

可以分层:

trigger:新版本并行worker从8增到64
mechanism:2CPU quota在period早期耗尽
amplifier:客户端立即重试、无并发限制
missing guardrail:canary未检查throttling与P99周期
organizational:CPU limit由模板固定且owner不明确

“CPU quota”只是机制;完整改进要处理触发和放大器。

22.3 Action item 必须可验收

差:

加强监控
提高代码质量
谨慎发布

好:

在2026-09-01前,由Platform团队:
- 为所有Go服务导出cpu.stat throttle ratio
- 当P99 burn与throttle同时触发时链接runbook
- canary门禁验证GOMAXPROCS <= effective CPU policy
- 用故障注入证明2CPU quota下100ms台阶告警可发现

要有owner、期限、验收测试和优先级。

22.4 删除无效告警

事故中没人使用、不可行动或重复的告警应修/删。增加十个dashboard不是默认改进;真正缺的是某个分层证据、基数维度、保留窗口或owner。

22.5 演练恢复而非只写文档

runbook会过期。定期演练:单实例OOM、DNS TCP fallback、日志后端断开、CPU throttle、磁盘满、优雅shutdown、连接池耗尽。演练在隔离/授权环境进行,限定blast radius和停止条件,不能拿生产用户做未授权破坏测试。


23. 通用 Runbook 模板

23.1 入口

告警名称/SLO:
服务与owner:
用户影响:
最近变更链接:
仪表盘/日志/trace/profile入口:

23.2 前五分钟

[ ] 确认告警不是采集缺失
[ ] 确认影响维度和错误预算
[ ] 建立事件时间线与指挥/沟通角色
[ ] 保存易失状态快照
[ ] 检查近期部署/配置/流量/基础设施变化
[ ] 判断是否需要立即止血

23.3 假设表

假设 支持证据 反证 下一测试 风险 状态
CPU quota throttle增长 待查 canary提高quota 节点容量 open
DB慢 trace DB span DB P99正常 查pool wait rejected

保持多个候选,按可区分信息增益排序测试。

23.4 动作记录

时间:
执行人/复核人:
动作与命令/变更ID:
预期指标:
风险/回滚:
实际结果:

23.5 结束条件

用户SLO恢复并持续观察窗口
队列/资源回到安全范围
重试/积压已消化且无二次洪峰
临时变更已记录/回收
证据安全保存
安排复盘与owner

24. 常用命令知识点扩展

命令 关注点 不能单独证明
uptime load average、运行时间 CPU必然饱和
vmstat 1 run queue、swap、CPU、block概览 具体调用栈
mpstat -P ALL 1 每CPU与softirq分布 cgroup内部公平
pidstat -u -w -d 进程CPU、切换、IO 用户请求因果
iostat -xz 1 设备IOPS、await、queue page cache/应用锁
ss -tinp TCP队列、RTT、重传线索 L7处理成功
lsof +L1 deleted-open文件 全部df/du差异
perf record on-CPU采样栈 off-CPU原因
strace -T syscall wall duration 内核CPU执行时间
journalctl -k 内核日志事件 无日志即无故障

组合配方:

# CPU quota
cat "$CG/cpu.max" "$CG/cpu.stat" "$CG/cpu.pressure"

# memcg OOM
cat "$CG/memory.current" "$CG/memory.max"
cat "$CG/memory.events" "$CG/memory.stat"

# fd泄漏
ls /proc/"$PID"/fd | wc -l
lsof -nP -p "$PID"
lsof +L1 -p "$PID"

# 网络路径
ss -tinp
nstat -az | grep -E 'Retrans|Listen|Syncookie'
ip -s link

# Go现场
go tool pprof -top cpu.pprof
go tool pprof -top heap.pprof

25. 面试题

Q:线上故障排查的第一步是什么?

先定义用户影响、范围、开始时间和是否扩大,再建立共同时间轴;不是先SSH看CPU。资源指标只有放进受影响请求、版本、区域和变更上下文才有意义。随后在止血前尽量保存易失证据。

Q:如何区分事实与假设?

事实是可复现观测及其时间/范围,例如cpu.stat throttled_usec在故障窗增长;“quota导致P99”是解释,需由调度等待、period周期、canary变更等验证。为假设写可推翻的反证,避免只找支持材料。

Q:相关性怎样升级为因果证据?

要求时间顺序、符合机制、排除主要替代解释,并通过受控干预得到预期变化;最好还可在测试环境复现、恢复变量后重现。一次重启同时改变太多状态,只提供弱因果证据。

Q:为什么CPU平均值低仍可能被CPU限制?

cgroup quota按period计CPU time,多线程可在period前段耗尽额度,后段整体throttle;平均仍等于limit。cpuset、单核热点和run queue也会在总CPU空闲时造成等待。需看每CPU、cpu.stat、PSI和调度延迟。

Q:为什么Go heap小于容器内存仍会OOM?

memcg还记账native/mmap、线程栈、page cache、socket和部分kernel memory、同cgroup其他进程;瞬时峰值也可能不在heap快照中。看memory.stat/events、smaps、socket队列和父cgroup,而非只看pprof。

Q:磁盘%util不高为什么fsync仍可能慢?

%util是聚合忙碌线索,无法表达flush尾延迟、journal等待、云盘credit、cgroup throttle或单请求barrier。fsync语义要求稳定介质确认,普通buffered吞吐低也可能偶发数百毫秒;需追syscall、filesystem、block和设备层。

Q:连接池满而数据库空闲可能是什么原因?

连接可能被应用transaction持有却在等待外部RPC、锁或业务计算,数据库只看到短SQL所以CPU/active低。也可能Rows/Tx未关闭或健康检查卡住。看pool wait、transaction lifetime、goroutine和trace,不要先放大池。

Q:大量TIME_WAIT是否应修改内核参数?

先找主动关闭方、连接新建率、复用率和是否真有端口错误。TIME_WAIT提供最后ACK重传和旧报文隔离;常见根因是每请求新transport或重试风暴。优先连接池/keepalive/幂等退避,而非削弱协议状态。

Q:CPU profile为何可能看不到锁竞争?

普通CPU profile只采正在CPU上执行的栈;等mutex的goroutine/线程处于off-CPU。使用mutex/block profile、goroutine dump和off-CPU调度观测,再检查lock holder。CPU低加吞吐低尤其应查等待。

Q:fd泄漏为何不能只看TCP连接数?

fd还可指向regular file、pipe、eventfd、epoll、inotify、Unix socket等。按/proc/PID/fd和lsof类型分类、看增长路径;deleted-open文件还会同时占fd和磁盘空间。提高NOFILE只延后失败。

Q:重启恢复说明了什么?

说明故障与该实例可清除状态或节点迁移相关,例如泄漏、锁、连接、cache、cgroup或外部时机;不说明具体根因。重启会销毁关键证据,应在可行时先抓profile/fd/events,并通过复现或单变量实验继续验证。

Q:为什么增加timeout常会恶化事故?

服务率不足时,更长timeout让请求在队列/内存/连接池占位更久,降低取消速度;客户端还可能并发重试。它减少表面timeout却增加Little’s Law中的在途量。应优先有界队列、load shedding和修复服务能力。

Q:为什么扩容可能压垮下游?

更多实例带来更多连接池、并行请求、cache miss、DNS和重试;若瓶颈在数据库/依赖,入口能力提高会把更大流量推给它。扩容前识别瓶颈,限制全局并发并监控下游。

Q:排障时怎样控制strace、perf和eBPF风险?

按PID/cgroup和事件过滤,低频/短时间,使用timeout,限制buffer/map和输出,记录lost/drop与开销;先canary或staging验证。抓包和syscall参数还涉及隐私。必须有权限、审计和自动detach。

Q:什么是好的止血动作?

可逆、blast radius小、预期指标明确、有回滚条件并不会破坏数据语义。例如摘除单个坏实例或canary提高quota;直接删fsync、关闭安全策略或全局调内核参数风险高。紧急动作也要记录执行人与结果。

Q:如何验证修复不是巧合?

修复前定义机制预期和副作用;只改变目标变量,看领先/结果指标按预期变化;使用canary/对照,经过足够业务周期,并在测试环境复现旧故障、应用修复后消失。必要时恢复旧配置验证可重现,但不能在生产制造破坏。

Q:复盘的根因应如何分层?

区分trigger、failure mechanism、amplifier、missing guardrail和组织/流程条件。例如并行度变更触发、quota机制形成100ms等待、重试放大、canary没看throttle、limit模板无owner。只写“CPU不足”无法防复发。

Q:可执行action item应包含什么?

具体改动、owner、截止日期、优先级和可验证验收标准;最好有测试/演练。比如“为Go服务导出throttle ratio并在SLO burn时关联告警”,而不是“加强监控”。

Q:为什么要监控排障工具和telemetry自身?

采集可能drop、延迟、限流或改变系统。没有profile lost、BPF ring drop、log queue、scrape失败等指标,“没有观测到”无法区分没有事件和采集失效。观测平台故障也不应同步阻塞业务。


小结

  • 排查从用户影响、范围和时间线开始;机器指标是证据,不是事故等级
  • 显式区分事实、假设、反证和结论;相关性需要机制、时间顺序、替代解释与受控干预才能升级为因果
  • 止血前尽量保存进程、cgroup、socket和短时trace等易失证据,但数据损坏/安全风险时应优先隔离
  • CPU平均低仍可能因quota period、cpuset或run queue变慢;Go heap小仍可能因native/socket/cache/父cgroup触发OOM
  • 磁盘吞吐和util无法代替fsync尾延迟;网络重传要从双端与多接口找丢失边界,MTU故障常呈现小包好、大包坏
  • DNS、连接池、锁和fd问题都可能表现为“请求超时”,需按阶段、资源owner和off-CPU栈区分
  • TIME_WAIT、Recv-Q、goroutine数量和重启恢复都只是线索;不结合速率、生命周期与业务语义不能下结论
  • 日志和观测系统也会锁竞争、填满磁盘、制造重试风暴;telemetry必须有界、可降级并暴露drop
  • 止血动作要可逆、范围小、有预期/回滚;扩容、加timeout、加buffer和调limit都可能把压力移到下游
  • 高开销工具按低到高逐级使用,限定scope、时间、数据和权限,记录observer effect与丢失
  • 修复验证应包括对照、足够窗口、故障复现和副作用;“重启后好了”不是根因
  • 复盘要拆trigger、mechanism、amplifier和guardrail,action item必须有owner、期限与可验收测试

下一篇是系列收官:Linux 面试题与系统设计题汇总 —— 不再按命令背答案,而是从进程、内存、调度、文件系统、网络、容器、systemd和观测中抽出跨层问题,并用约束、机制、权衡、故障与验证组织完整回答。