一次 GC 停顿排查：从 P99 毛刺到 GOGC 与 GOMEMLIMIT

2026-01-1527 分钟读完0 次浏览

P99 周期性毛刺怎么确认是不是 GC、gctrace 每列怎么读、runtime/metrics 该取哪几个指标、GOGC 与 GOMEMLIMIT 各自拿什么换什么，以及「别把 GC 当唯一嫌疑人」的区分方法。

监控图上平均延迟很平，但 P99 每隔几秒顶一次尖，尖的形状很规律，像心跳。这种"周期性毛刺"通常只有两个来源：定时任务，和 GC。这篇记录我怎么把两者分开、确认是 GC 之后试过的三档旋钮（GOGC、GOMEMLIMIT、减少分配），每档都附上验证方法。

先说清测量环境，下面的数字只在这个环境里可复现：Go 1.25.0 windows/amd64，12 代 i9-12900H（20 逻辑核，GOMAXPROCS=8），16 GiB 内存。负载是我写的合成负载：8 个 worker，每请求分配 128 KiB 临时对象并做固定量计算，实测约 7300 req/s、分配速率约 900 MiB/s、常驻存活堆 64 MiB，单次运行 8 秒，每秒采样一行。这是示例环境，不是给你的容量结论——给你的是方法。

一、先把延迟曲线和 GC 周期放在同一根时间轴上

"P99 有毛刺"不是结论，先要能回答三件事：毛刺的周期是多少、每个周期里延迟抬高了多久、这段时间进程在干什么。所以我的第一步不是调参，而是让同一个进程每秒吐一行 CSV，把延迟分位和 GC 指标放进同一行——两边的时钟天然对齐，不需要事后对表。

// 需要 import："fmt"、"runtime/metrics"、"time"
type gcStats struct {
	stwCounts []uint64  // 暂停直方图的累计计数
	stwBounds []float64 // 桶边界（对同一指标固定不变）
	gcCycles  uint64
	heapGoal  uint64
	heapLive  uint64
}

func readGC() gcStats {
	st := []metrics.Sample{
		{Name: "/sched/pauses/total/gc:seconds"}, // 等价于旧名 /gc/pauses:seconds
		{Name: "/gc/cycles/total:gc-cycles"},
		{Name: "/gc/heap/goal:bytes"},
		{Name: "/gc/heap/live:bytes"},
	}
	metrics.Read(st)
	if st[0].Value.Kind() == metrics.KindBad {
		panic("指标名写错时 Kind 是 KindBad，而不是静默给出 0")
	}
	var s gcStats
	h := st[0].Value.Float64Histogram()
	s.stwCounts, s.stwBounds = h.Counts, h.Buckets
	s.gcCycles = st[1].Value.Uint64()
	s.heapGoal = st[2].Value.Uint64()
	s.heapLive = st[3].Value.Uint64()
	return s
}

// 累积直方图必须做差分，否则读到的是"自进程启动以来"的分布
func stwDelta(prev, cur gcStats) (pauses int, total, maxPause time.Duration) {
	for i := range cur.stwCounts {
		d := cur.stwCounts[i] - prev.stwCounts[i]
		if d == 0 {
			continue
		}
		pauses += int(d)
		upper := cur.stwBounds[i+1] // 桶上界；按上界加权求和是偏高的估计
		if upper > 1 {              // 最后一档是 +Inf，兜一下
			upper = cur.stwBounds[i]
		}
		total += time.Duration(float64(d) * upper * float64(time.Second))
		maxPause = time.Duration(upper * float64(time.Second))
	}
	return
}

func watchGC() {
	prev := readGC()
	for range time.Tick(time.Second) {
		cur := readGC()
		pauses, total, maxPause := stwDelta(prev, cur)
		fmt.Printf("gc=%d stw_n=%d stw_total=%v stw_max=%v goal=%dMiB live=%dMiB\n",
			cur.gcCycles-prev.gcCycles, pauses, total.Round(time.Microsecond),
			maxPause.Round(time.Microsecond), cur.heapGoal>>20, cur.heapLive>>20)
		prev = cur
	}
}

三个容易踩的点：/sched/pauses/total/gc:seconds 与 /sched/latencies:seconds 都是累积直方图（Description.Cumulative 为真），不差分就只能看到开服以来混在一起的一坨；/gc/pauses:seconds 在新版 Go 里已经标记为 deprecated，等价指标是 /sched/pauses/total/gc:seconds，另外还有只统计"决定 STW 到所有 P 停下"那一段的 /sched/pauses/stopping/gc:seconds；/gc/heap/live:bytes 只在 GC 结束时更新——我用 GOGC=off 跑过一次，这个指标一直是 0，而 /memory/classes/total:bytes 已经从 965 MiB 涨到 2673 MiB，所以判断内存要看后者。

同一负载、五种配置，我跑出来的对照（每格是 8 秒运行的汇总或每秒区间，p50/p99 是进程内 time.Now() 前后差值的分位）：

配置	GC 次数	每秒 STW 总时长	单次最大暂停	堆目标	runtime 管理内存	p50	p99	p99.9
`GOGC=100`（默认）	116	5~12 ms	1.57 ms	~130 MiB	148 MiB	1.000 ms	2.510 ms	2.5~3.5 ms
`GOGC=400`	29	0.5~5 ms	1.57 ms	~325 MiB	332 MiB	1.000 ms	2.509 ms	2.52 ms
`GOGC=400` + `GOMEMLIMIT=150MiB`	101	3~15 ms	2.10 ms	141 MiB	152 MiB	1.000 ms	2.509 ms	2.5~3.1 ms
`GOGC=off` + `GOMEMLIMIT=256MiB`	41	2~7 ms	1.57 ms	243 MiB	256 MiB	1.000 ms	2.510 ms	2.5~3.0 ms
`GOGC=off`（跑 3 秒）	0	0	0	MaxInt64	965→2673 MiB	1.000 ms	2.506 ms	2.5~2.9 ms

这张表本身就是结论，我按它调整了排查方向：GC 次数从 116 压到 29（-75%）、STW 总时长从 69 ms 压到 17 ms，p99 一动没动（2.510 → 2.509 ms）。最后一行更狠——GOGC=off、暂停彻底归零，p99 还是 2.5 ms 左右。所以在这个负载上，p99 的一整个尾部都不是 GC 造成的：这台机器上 time.Now() 的分辨率本身只有 0.5 ms 量级（我单独测过一次：200 万次连续读取只出现 18 个不同的差值，最小的 506 µs），1 ms 的基准耗时加上 0.5 ms 的量化误差，P99 自然落在 2.5 ms 附近。如果我不做这个反证，我会花三天去调 GC，而问题在计时和调度抖动上。

二、确认是 GC：gctrace 的每一列

GODEBUG=gctrace=1 是零成本的第一手段，它每个周期往 stderr 打一行。我在 GOGC=100 那次 8 秒运行里捞出几行真实输出：

gc 8 @0.267s 0%: 1.0+0+0 ms clock, 8.0+0/0/0+0 ms cpu, 141->142->64 MB, 154 MB goal, 0 MB stacks, 0 MB globals, 8 P
gc 13 @0.582s 0%: 1.0+0+1.0 ms clock, 8.0+0/0/0+8.0 ms cpu, 121->121->64 MB, 130 MB goal, 0 MB stacks, 0 MB globals, 8 P
gc 15 @0.714s 0%: 1.0+10+0 ms clock, 8.0+0/0/0+0 ms cpu, 126->134->72 MB, 129 MB goal, 0 MB stacks, 0 MB globals, 8 P
gc 119 @7.909s 0%: 0+1.0+0 ms clock, 0+0/0/0+0 ms cpu, 118->118->64 MB, 129 MB goal, 0 MB stacks, 0 MB globals, 8 P

格式是 gc # @#s #%: #+#+# ms clock, #+#/#/#+# ms cpu, #->#-># MB, # MB goal, # MB stacks, #MB globals, # P，逐段对应：

字段	含义	对应的 `runtime/metrics` 指标
`gc 13`	第几个 GC 周期（进程启动起算）	`/gc/cycles/total:gc-cycles` 的差分
`0%`	自进程启动以来 GC 占用的 CPU 比例（累计值，不是本周期）	`/cpu/classes/gc/total:cpu-seconds` ÷ `/cpu/classes/total:cpu-seconds`
`1.0+0+1.0 ms clock`	墙上时间三段：STW sweep termination、并发标记+扫描、STW mark termination	`/sched/pauses/stopping/gc:seconds` 对应两个 STW 段
`8.0+0/0/0+8.0 ms cpu`	CPU 时间：STW（= P 数 × 对应墙上时间）、mark assist、后台+分片标记、idle 标记、末尾 STW	`/cpu/classes/gc/mark/assist:cpu-seconds` 等 `/cpu/classes/gc/*`
`121->121->64 MB`	GC 开始时的堆、GC 结束时的堆、标记结束时的存活	`/gc/scan/heap:bytes`、`/gc/heap/live:bytes`
`130 MB goal`	下一次触发的堆目标	`/gc/heap/goal:bytes`
`0 MB stacks` / `0 MB globals`	可扫描的栈与全局变量估计	`/gc/scan/stack:bytes`、`/gc/scan/globals:bytes`
`8 P`	本次使用的处理器数	`/sched/gomaxprocs:threads`

两个判读技巧是我从数据里抠出来的：

第一，STW 的指纹是"第一个 CPU 数 = P 数 × 第一个墙上数"。 看 gc 8 那行：墙上第一段 1.0 ms，CPU 第一段 8.0 ms，正好是 8 P × 1.0 ms——意思是这 1 毫秒里 8 个 P 全停了，这就是 stop-the-world。后面那些形如 0/0/0 的并发标记时间是摊在整个周期里的，不会直接掐断某个请求。

第二，两侧是 STW，中间才是并发。 gc 15 那行是 1.0+10+0：1 ms 的 STW 清扫终止，10 ms 的并发标记（这段时间业务代码在跑，但要多花 CPU），0 ms 的 STW 标记终止。如果中间那个数很大而两侧很小，说明 GC 是"慢但不卡"；如果第三个数开始变大（像 gc 13 的 1.0+0+1.0），就说明标记终止阶段变重了，通常是存活对象里的指针结构复杂或堆太大，这种停顿会直接体现在 P99 上。

GODEBUG=gctrace=2 会在每个周期后面再打一段扫描统计，排查"扫描热点"时有用。另外注意 util 那个百分比是累计值，我这次全程都是 0%——GC 的 CPU 占比不到 1%，这时候"GC 吃 CPU"这个假设基本可以排除了。

三、runtime/metrics：比 gctrace 更适合做告警

gctrace 适合人看，指标适合接监控。除了上面已经用到的暂停直方图，我在服务里常驻采集这几个：

指标	类型	用它回答什么
`/sched/pauses/total/gc:seconds`	直方图（累积）	每秒暂停次数、总时长、单次最大——判断"毛刺是不是 STW 打的"
`/gc/heap/goal:bytes`	瞬时值	下一次 GC 的触发线，配合堆曲线看 GC 频率为什么变
`/gc/heap/live:bytes`	瞬时值	每次 GC 后的存活量，判断是"分配快"还是"泄漏"
`/sched/latencies:seconds`	直方图（累积）	goroutine 从可运行到真正上 CPU 的等待——GC 之外最常见的毛刺来源
`/cpu/classes/gc/mark/assist:cpu-seconds`	计数器	业务 goroutine 帮 GC 干活的时间；它涨而 STW 不涨时，延迟会被"摊"慢
`/sync/mutex/wait/total:seconds`	计数器	锁竞争的累计等待，用来排除"不是 GC 而是锁"

assist（标记辅助）值得单说：它不产生 STW，但会把 GC 的活摊到正在分配的 goroutine 上，于是表现为"延迟整体抬高、没有明显尖峰"。我这次负载里 assist 基本是 0（8 秒里偶尔出现 0.001 秒），因为我这个堆只有 64 MiB 存活、标记很快；但在大堆 + 快分配的服务里，assist 经常是延迟劣化的主因，此时该做的是减少分配或提高 GOMAXPROCS，而不是继续加 GOGC。

四、go tool trace：看 STW 和 assist 落在谁头上

指标告诉你"有多少暂停"，trace 告诉你"暂停打断了谁"。抓取方式两种，进程内 runtime/trace，或者线上服务直接打 HTTP 端点：

curl -o trace.out 'http://127.0.0.1:6060/debug/pprof/trace?seconds=5'  # 线上服务（已挂 net/http/pprof）
go tool trace trace.out                          # 打开浏览器界面看时间轴
go tool trace -d=footprint trace.out             # 先确认这份 trace 里到底有没有 GC 事件

-d=footprint 的输出是我现在必看的第一步，它按事件类型列出字节数与条数：

Event                Bytes   %       Count  %
ProcStart            116285  30.65%  19725  24.67%
HeapAlloc            315     0.08%   50     0.06%
HeapGoal             6       0.00%   1      0.00%
STWBegin             4       0.00%   1      0.00%
STWEnd               2       0.00%   1      0.00%

体积基本被调度事件（ProcStart/GoStart/GoBlock）吃掉了，GC 事件只占千分之几——但这行计数同时回答了两个问题：这份 trace 里有没有 STWBegin/HeapGoal（没有就是采样期太短或负载太轻），以及 trace 文件大是不是因为事件本身太多。

打开界面后我要看两处：时间轴上由运行时标注的区间，名字分别是 stop-the-world (GC sweep termination)、GC concurrent mark phase、GC incremental sweep、GC mark assist——前两个拼起来就是 gctrace 里那三段；以及 "Goroutine analysis" 页，它按 goroutine 分组给出 Execution time / Network wait / Sync block / Blocking syscall / Scheduler wait，另有一张 "Special ranges" 表统计每个 goroutine 待在 GC mark assist 这类区间里的时间。如果你的毛刺是 assist 造成的，这张表会直接把"谁在帮 GC 干活"指出来。

一个实测踩坑：go tool trace -pprof=sched trace.out > sched.pprof 这条路在我这台机器的 Go 1.25 上没走通，把它喂给 go tool pprof 会报 parsing profile: unrecognized profile format，所以我最后回到"指标 + trace 界面"的组合。工具版本差异这种事，别在故障窗口里去试。

五、三档旋钮，各自拿什么换什么

手段	换到什么	代价	怎么验证
调大 `GOGC`	GC 次数和 STW 总时长成比例下降	堆目标变大，内存占用成比例上升；峰值 RSS 变高	看 `/gc/heap/goal:bytes` 与 `/memory/classes/total:bytes`，再看每秒 STW
设 `GOMEMLIMIT`	内存有硬天花板，不会被容器 OOMKill	逼近限制时 GC 频率飙升，CPU 被 GC 吃掉（延迟抖动变大）	看 `goal` 是否被压到 limit 附近、GC 次数是否回升
对象复用 / 减少分配	从源头减少 GC 次数，内存和延迟同时改善	代码复杂度上升；`sync.Pool` 会被运行时清掉，不能依赖命中	`-gcflags=-m`、`-benchmem` 的 allocs/op、heap profile 的 alloc_space

GOGC 是"内存换延迟"的旋钮。 我这组数据里，GOGC 从 100 到 400，GC 次数 116 → 29，STW 总时长 69 ms → 17 ms，代价是堆目标 130 MiB → 325 MiB、runtime 管理内存 148 MiB → 332 MiB。它是相对值：触发线约等于"上次 GC 后的存活量 × (1 + GOGC/100)"，所以存活堆大的服务，GOGC=400 就是几百 MB 的额外占用。运行时改：

old := debug.SetGCPercent(200) // 返回旧值，出问题时可以立刻回滚
defer debug.SetGCPercent(old)

GOMEMLIMIT 是"内存上限"，不是"内存优化"。 它由 debug.SetMemoryLimit（或同名环境变量）设置，值是软限制，管的是 Go runtime 管理的全部内存——按官方文档的口径，它维护的目标量约等于 MemStats.Sys - MemStats.HeapReleased，换成指标就是 /memory/classes/total:bytes - /memory/classes/heap/released:bytes；它不包含二进制映射、cgo 分配的内存、以及操作系统替进程持有的内存（比如文件页缓存），所以在容器里留 20% 余量是常规做法。

我这次把 GOGC=400 和 GOMEMLIMIT=150MiB 放一起，效果非常直观：GOGC 想要的堆目标是 325 MiB，被软限制一路压到 141 MiB，GC 次数立刻从 29 回升到 101，STW 总时长也跟着回到 57 ms——内存被兜住了，延迟的收益被收回去了一部分。这就是文档里说的"限制设得过低会让 GC 近乎连续运行、进程仍能推进但 CPU 被吃掉"。所以它不是用来降延迟的，它是用来让服务在容器里活着的：

// 传 -1 只读取当前值，不做修改；容器 limit 512MiB 就设 400MiB 左右
debug.SetMemoryLimit(containerLimit * 8 / 10)

顺带一个版本差异：Go 1.25 起 GOMAXPROCS 的默认值会看 cgroup 的 CPU 配额（可以用 GODEBUG=containermaxprocs=0 关掉），但 GOMEMLIMIT 到 1.25 仍然不会自动跟随容器内存 limit，这个数得你显式设。

对象复用的正确姿势是"用完立刻还、还之前先归零长度"，sync.Pool 的每条纪律都有对应的翻车方式：

var bufPool = sync.Pool{New: func() any { return make([]byte, 0, 32<<10) }}

func handle(p []byte) int {
	buf := bufPool.Get().([]byte)[:0]
	defer func() { bufPool.Put(buf[:0]) }() // 先截断长度再放回
	buf = append(buf, p...)
	return len(buf)
}

四类常见误用：把 Get() 出来的对象交给别的 goroutine 长期持有（Put 之后还被引用，等于把内存交给一个随时会被复用的变量）；放回去时不重置状态，下一次 Get 拿到脏数据；往同一个池里塞大小差几十倍的对象，结果是内存放大；以及指望它"一定命中"——池里的对象随时可能被运行时清掉（Go 现在用 victim 缓存让对象最多活过一次 GC），所以只适合"命中是加速、不命中也能正确工作"的场景。

减少分配是唯一没有副作用的旋钮，但要用工具找。go build -gcflags=-m 会打出逃逸分析结论，我拿几个典型写法跑过一次真实的输出：

esc/esc.go:13:9: &Req{...} escapes to heap
esc/esc.go:13:31: make([]byte, n) escapes to heap
esc/esc.go:18:13: make([]byte, 64) does not escape
esc/esc.go:43:16: string(b) escapes to heap

配合 testing.AllocsPerRun 量化（注意必须用运行期才知道的值 + //go:noinline，不然会被常量折叠和"结果没人用"优化掉——我第一版就是这么被骗到全是 0 的）：

make([]byte, 64)  非逃逸: 0.0 allocs/op
make([]byte, n)   非逃逸: 1.0 allocs/op   // 长度是变量 ⇒ 栈帧大小不定，仍走堆
make([]byte, n)   逃逸到堆: 1.0 allocs/op
string(b)         复制:      1.0 allocs/op  // []byte → string 每次都会复制

结论很实用：常量长度、且不逃逸的 make([]byte, 64) 能留在栈上，长度是变量的就不行；[]byte 和 string 之间反复转换每次都复制一次，在热路径上要合并成一次转换或改用 unsafe 之外的其他设计（比如全程用 []byte）。再往上一层是 go tool pprof：

go tool pprof -alloc_space -top ./app heap.prof     # 累计分配量，找"谁在制造垃圾"
go tool pprof -inuse_space -top ./app heap.prof     # 存活量，找泄漏
go tool pprof -base before.prof after.prof ./app    # 看增量，比看绝对值有用

六、我现在的调参顺序

先量化：每秒一行 CSV，把延迟分位、STW 次数/总时长、堆目标、assist 放一起，至少跑十分钟覆盖一次发布或流量峰。
做反证：确认毛刺和 STW 同周期；不确定就短时间 GOGC=off 跑一段（内存可控的窗口），看指标动不动。不动就不是 GC。
找分配源：-alloc_space 看 top，优先砍掉"每请求分配大 buffer"和"热路径上的 string()/[]byte() 转换"，这一步通常让 GC 次数直接降一个档。
设 GOMEMLIMIT：按容器 limit 的 80% 设，先只保证不被 OOMKill，不同时期望它降延迟。
最后调 GOGC：一档一档加（100 → 200 → 400），每档记录 GC 次数、内存占用、P99/P99.9，直到"内存换来的延迟收益"不划算为止。
回归验证：同一份负载脚本重跑，比较的是 STW 总时长和 P99.9，不是"感觉快了"。

七、三个把我带偏过的误区

把 GC 当唯一嫌疑人。 我上面那组数据就是最好的反例：GOGC=off、暂停归零，P99 纹丝不动。区分方法有三个——第一，算量级：每秒 STW 总时长 8 ms（0.8%）和"超阈值请求占比 5%"对不上，就不是 STW 打的；第二，看 /sched/latencies:seconds 和 /sync/mutex/wait/total:seconds，如果 goroutine 的排队时间或锁等待涨了而 GC 指标没涨，嫌疑人换人；第三，用 runtime.SetBlockProfileRate / runtime.SetMutexProfileFraction 打开 block/mutex profile，看是不是某个下游或锁在拖。系统调用、磁盘 IO、DNS 解析这些属于"阻塞型"毛刺，特征是延迟抬高呈尖刺但 CPU 不高、且和 GC 周期无关。

只盯平均值。 我这五组配置的 p50 全是 1.000 ms，一点区分度都没有；真正的区分度在 p99.9 和 max 上（GOGC=400 把 p99.9 从 2.5~3.5 ms 收到 2.52 ms）。而且分位本身会被采样密度骗：QPS 7 千时 p99 是 73 个请求，p99.9 是 7 个，想看清暂停的影响就得看直方图的尾部而不是一个分位点。

在容器里没设 GOMEMLIMIT，然后被 OOMKill。 GC 的触发线只跟"存活量 × GOGC"有关，跟 cgroup limit 没关系。一个存活 200 MiB、GOGC=200 的服务，堆目标是 600 MiB——如果容器 limit 是 512 MiB，它会在 GC 还没来得及触发时被内核杀掉（通常看到 exit code 137）。要固定成一条纪律：只要跑在容器里，GOMEMLIMIT 就必须显式设置，并且它是"上限"而不是"目标"，日常占用应该明显低于它。

小结

这次排查里最值钱的不是调参，而是那张"同一根时间轴"的表：它让我在动 GOGC 之前就发现 P99 的尾部跟 GC 无关。真正落地的顺序是先量化、再反证、然后减少分配、GOMEMLIMIT 兜住内存、最后才用 GOGC 换延迟。GC 调参不是玄学，它只是一道算术题——前提是你手里有每秒的 STW 总时长和分配速率，而不是一条平均值曲线。另外记住两个数字的边界：GOGC 是相对的（跟存活量挂钩），GOMEMLIMIT 是绝对的（跟容器 limit 挂钩），用错了对象，参数怎么调都不会对。

标签：#Go #GC #性能 #调优