Go 升级 1.24 后的 GC 延迟毛刺排查

· 技术 / Golang · Golang, GC, 性能, 排查, runtime

三月初趁版本迭代把几个核心服务从 Go 1.22 升到了 1.24。编译通过、测试全绿、灰度一天没事，就全量了。然后第三天监控群里有人发截图：P99 延迟出现规律性毛刺，每次持续大概 80~200ms，间隔接近两分钟。

P50 和 P95 完全正常，复现稳定，和流量高低没关系——这个模式我见过，基本锁定是 GC 问题。

先确认是不是 GC

最直接的办法是开 GC trace：

GODEBUG=gctrace=1 ./server 2>&1 | grep "^gc "

输出片段：

gc 47 @118.234s 2%: 0.10+181+0.22 ms clock, ...
gc 48 @236.891s 2%: 0.11+174+0.19 ms clock, ...
gc 49 @355.102s 2%: 0.09+168+0.21 ms clock, ...

间隔 118 秒左右，STW 那两段（0.1ms 和 0.2ms）是正常的，但中间的并发 mark 阶段跑了 170~180ms，这就是毛刺的来源。并发 mark 期间不 STW，但会抢 CPU，导致请求处理变慢。

进一步看 gcfraction（GC 时间占 wall time 的比例）稳定在 2%，不算高。所以问题不是「GC 太频繁」，是「每次 GC 的 mark 阶段太慢」。

堆里有什么

接着看堆的状态。用运行时指标捞一下 GC 前后的堆大小：

var stats runtime.MemStats
runtime.ReadMemStats(&stats)
// HeapInuse: 2.1GB，HeapSys: 2.8GB
// HeapObjects: 约 420 万个
// LastGC 到现在: 116 秒

2.1GB 的堆，420 万个对象，mark 扫 180ms 其实不离谱——问题是，1.22 跑同样的业务，堆只有 1.3GB，mark 大概 90ms，间隔也更短（约 70 秒），因为 GOGC 默认是 100，堆涨一倍就触发一次 GC，频率更高但每次更快。

现在堆变大、间隔变长、每次 mark 更慢，触发的时间点恰好撞上业务请求。

堆为什么从 1.3G 涨到 2.1G

这才是真正的问题。升 Go 版本不会让你的代码突然多分配内存，一定是行为改变了。

翻 1.23 和 1.24 的 release notes，找到一条不起眼的：

runtime: GOGC now interacts with GC goal calculation differently...

大意是 1.23 调整了 GC 触发策略，在某些条件下会让堆长得更高再触发，目的是减少 GC 频率、提升吞吐。这对批处理友好，对低延迟服务是个隐患。

但这只解释了堆为什么长大，没解释为什么 mark 比线性预期慢得多。2.1GB 大概是 1.3GB 的 1.6 倍，mark 时间应该也是 1.6 倍左右（90ms × 1.6 ≈ 144ms），实际却跑了 180ms。

中间差的这 36ms，我怀疑是对象图的问题，而不是纯粹的堆大小。

heap profile 找大对象

拉 heap profile，看 inuse_objects（存活对象数）和 inuse_space 分布：

go tool pprof -http=:8080 http://localhost:6060/debug/pprof/heap

有一个分配点跳出来了：cache.(*ShardedMap).loadAll 分配了一个 []Entry 切片，单次 150MB，存活在堆里。这个切片是用来做全量缓存预热的，每次预热结束后这个大切片就变成了「占着堆空间但等 GC 来收」的状态。

在 1.22 下，因为 GC 频率更高，这个切片通常在下次 GC 时就被收掉了；在 1.24 下，两次 GC 间隔拉长，缓存预热一天会跑几十次，积累的 150MB 大切片好几个同时存在于堆里，对象图的指针密度上去了，mark 变慢。

这是两个问题叠加的结果，单独任何一个都不会触发。

修法

搞清楚之后，修起来其实不复杂。

第一步，把那个大切片的生命周期管住，用完立刻置 nil 并显式调一次 runtime.GC()：

func (c *ShardedMap) loadAll(ctx context.Context) error {
    entries, err := c.store.FetchAll(ctx)  // 返回 []Entry，~150MB
    if err != nil {
        return err
    }
    c.populate(entries)
    entries = nil           // 帮助 GC 尽快识别
    runtime.GC()            // 主动回收，避免堆积
    return nil
}

主动调 runtime.GC() 这事有点争议，通常不推荐，但这里场景明确——大批量加载完成是一个清晰的「内存密集操作结束」时间点，主动触发一次比被动等合理。

第二步，针对这几个低延迟服务，调小 GOGC：

GOGC=70

70 的意思是「堆比上次 GC 后的存活对象多出 70% 就触发」，比默认的 100 更激进，GC 更频繁但每次更快，P99 毛刺变短。当然吞吐会有轻微损失，压测了一下在我们的场景里损失不到 3%，可以接受。

也可以用 1.19 引入的 GOMEMLIMIT 代替或配合 GOGC：

GOMEMLIMIT=1800MiB

设一个软上限，堆接近上限时 GC 会更主动介入，避免堆无限膨胀。两者可以同时设，runtime 会取更严格的那个触发。

上线后的数据

改完灰度一天，GC trace 里 mark 阶段从 170ms 降到 60ms 左右，毛刺幅度从 80~200ms 降到 30ms 以内，间隔也缩短到 50 秒左右，P99 曲线基本平了。

堆稳定在 1.4GB，比 1.22 时略高，主要是 1.24 的其他运行时优化确实带来了一些额外的内部数据结构开销，这部分是正常的。

事后想的几件事

Go 每个大版本的 GC 行为调整，release notes 里通常都有，但写得很克制，读的时候容易滑过去。这次我是出了问题才回头翻的，如果升版本之前专门把 runtime 相关的 note 过一遍，应该能提前预判。后来在我们的升版本 checklist 里加了这一项。

GODEBUG=gctrace=1 在生产上开短时间是可以的，输出到 stderr，不影响服务，但日志量会大，别忘了关。我当时是开了五分钟采完数据就关了，期间没发现什么异常。

还有一点：这次问题在灰度阶段没发现，因为灰度的流量不到全量的 10%，缓存预热频率低，大切片没来得及积累。GC 类问题有时候就是要上了完整流量才暴露，这是灰度的盲区之一，想通了其实没什么好办法，只能在升版本前加长观察窗口。

这次从报警到修复大概花了两个工作日，不算长。主要时间花在「堆为什么变大」和「mark 为什么比预期慢」这两个问题之间来回横跳，确认是两个原因叠加的那一刻才算找准方向。分层排查这件事，道理人人都懂，真排查的时候还是容易乱。

相关阅读