一次线上 GC 抖动的排查记录

背景

凌晨三点,告警群炸了。某个核心服务的 p99 从平时的 40ms 飙到了 800ms,接口大面积超时。业务方反馈"整个系统像卡住了一样"。

奇怪的是:QPS 没有明显上涨,依赖的 MySQL / Redis 都正常,机器 CPU、内存、网络也都在合理范围。典型的"看起来一切正常,但就是慢"。

排查链路

第一步:排除外部依赖

先确认是不是下游变慢了。把 P99 飙升的时间段和 MySQL slow log、Redis latency 对比——完全对不上,下游都在 1ms 以内。

排除外部因素,问题出在服务自身。

第二步:看 Go runtime 指标

服务是 Go 写的,p99 阶梯式跳变 + 没有明显 CPU 飙升,第一反应是 GC。拉了 runtime 指标:

go_gc_duration_seconds{quantile="0.5"}  3.2e-04
go_gc_duration_seconds{quantile="0.9"}  1.8e-03
go_gc_duration_seconds{quantile="1"}    2.1e-01   ← 单次 GC 210ms
go_memstats_gc_cpu_fraction            0.42       ← GC 占了 42% CPU

单次 GC 最长花了 210ms,而且 GC CPU 占比 42%——这就是 p99 的来源。STW 期间所有 goroutine 都得停。

第三步:为什么 GC 这么重

GC 重通常意味着堆太大。再看堆指标:

go_memstats_heap_inuse_bytes   8.2e+09   ← 8.2 GB 活跃堆
go_memstats_heap_alloc_bytes  9.1e+09
go_memstats_next_gc_bytes     1.0e+10   ← 下次 GC 目标 10 GB

8.2 GB 的活跃堆,对一个标称"内存占用 500MB"的服务来说,明显异常。说明有大量对象该回收却没回收——内存泄漏。

第四步:定位泄漏点

用 pprof 抓堆:

go tool pprof http://service:6060/debug/pprof/heap
(pprof) top

输出里一个全局 map[string]*Entry 缓存占了 7.8 GB,排在第一。这个缓存是业务里用来缓存用户配置的,key 是用户 ID,只增不删,跑了两个月积累了 2000 多万条目。

根因与修复

一个无界增长的全局 map 缓存导致堆膨胀,触发频繁且漫长的 GC,STW 期间 p99 飙升。

修复方案分两步:

1. 止血:给缓存加上限,超过阈值时按 LRU 淘汰。重启后堆立刻降到 600MB,GC 恢复到 3ms 级别。
2. 根治:换成带 TTL 的缓存库(groupcache 或 bigcache),过期自动清理,从根本上避免无界增长。

反思

这次故障给我三个教训:

• 全局可变状态必须有边界。任何"只增不删"的数据结构都是定时炸弹,代码 review 时要特别警惕。
• Go 服务的 GC 指标要常态化监控。go_gc_duration_seconds 的 max 和 go_memstats_gc_cpu_fraction 应该有独立告警,而不是等 p99 炸了才发现。
• pprof 是 Go 后端的命根子。把 /debug/pprof 端点一直开着(内网可达即可),出事时能省下大量定位时间。

下次再遇到"一切正常但就是慢",第一反应就是:看 runtime 指标,上 pprof。