开启GODEBUG=gctrace=1后,GC触发时输出固定格式快照:gc 1 @0.024s 0%: 0.020+0.19+0.014 ms clock, 0.16+0.19/0.057/0.014+0.11 ms cpu, 4->4->2 MB, 5 MB goal, 8 P,各字段分别表示GC序号、启动后时间、CPU占比、各阶段挂钟/CPU耗时、堆大小变化、下轮GC目标及P数量。

gctrace=1 输出内容怎么看
开启 GODEBUG=gctrace=1 后,每次 GC 触发时会在标准错误输出一行类似这样的信息:gc 1 @0.024s 0%: 0.020+0.19+0.014 ms clock, 0.16+0.19/0.057/0.014+0.11 ms cpu, 4->4->2 MB, 5 MB goal, 8 P
这行不是日志级别,而是固定格式的快照。关键字段含义如下:
-
gc 1:第 1 次 GC(从 0 开始计数) -
@0.024s:程序启动后 0.024 秒发生 -
0%:GC 占用 CPU 时间占比(当前采样窗口内) -
0.020+0.19+0.014 ms clock:STW 阶段耗时 + 并发标记耗时 + STW 清扫耗时(真实挂钟时间) -
0.16+0.19/0.057/0.014+0.11 ms cpu:各阶段 CPU 时间,中间斜杠分隔的是并发标记中“辅助标记”、“后台标记”、“唤醒标记”的细分 -
4->4->2 MB:GC 前堆大小 → GC 中堆大小 → GC 后堆大小 -
5 MB goal:下一次触发 GC 的目标堆大小(基于 GOGC 计算) -
8 P:当时运行时使用的 P(Processor)数量
为什么开了 gctrace=1 却没看到输出
最常见原因是程序太短、没触发 GC,或者输出被重定向/丢弃了。Golang 的 GC 不是定时跑,而是按堆增长比例(默认 GOGC=100)触发。小 demo 程序往往分配不到几 MB 就结束了,根本不会 GC。
- 确保程序持续分配内存,比如用
make([]byte, 1 循环申请 1MB 切片 - 检查是否把 stderr 重定向了(如
2>/dev/null),gctrace只写到 stderr - 在容器或 systemd 服务里运行时,stderr 可能被日志系统截断或缓冲,加
stdbuf -eL强制行缓存 - Go 1.21+ 默认启用异步预emption,但
gctrace输出仍依赖 GC 实际发生,不是“每秒固定打点”
GODEBUG=gctrace=2 和 =1 有啥区别
gctrace=2 会额外打印每个 P 上的标记任务分布和对象扫描统计,信息量陡增,适合排查标记不均、辅助标记不足等问题;gctrace=1 是日常观察 GC 频率和耗时的合理起点。
立即学习“go语言免费学习笔记(深入)”;
-
=1:只输出汇总行(如上例),每轮 GC 一行 -
=2:每轮 GC 多出若干行,包含mark assist time、scanned、span分布等细节 - 值为 0 表示关闭(默认);设为非数字(如
gctrace=abc)会被忽略,退化为 0 - 注意:高频率 GC 下
=2可能产生大量输出,影响性能,别在生产环境长期开着
想持久记录 GC 日志该怎么做
GODEBUG=gctrace=1 只往 stderr 打印,没法直接存文件或结构化。得靠外部手段捕获和解析。
- 启动时重定向 stderr:
GODEBUG=gctrace=1 ./myapp 2>gc.log - 用
script命令录屏式捕获(含时间戳):script -c "GODEBUG=gctrace=1 ./myapp" gc-session.log - 写 wrapper 脚本,用
awk或go tool trace解析原始输出(后者需配合runtime/trace) - 注意:不要用
log.SetOutput(os.Stderr)之类去接管——gctrace是 runtime 内部直写 fd 2,不走 Go 的 log 包
真正难的不是记下来,是怎么从一堆时间戳混乱、无结构的 gc N @X.s ... 行里看出趋势。比如连续多行 goal 不涨,说明对象没释放,大概率有内存泄漏;clock 里 STW 时间突然拉长,可能是某次清扫遇到大量 finalizer。这些信号得自己盯,工具只负责吐数据。










