游戏服务器内存持续上涨排查实录:GC"调优"救不了你,JProfiler 两轮定位真凶
压测期间发现服务器堆内存持续上涨、GC 停顿很差。第一反应是调 GC 参数——调完发现增速纹丝不动,这才意识到方向错了:这不是 GC 配置问题,是分配速率问题。本文完整记录用 JProfiler 两轮定位、揪出两个真凶的过程,以及沉淀下来的排查方法论。
一、背景:压测中的 GC 表现
游戏服务器压测期间,GC 表现不理想。当时的关键 JVM 参数(G1 收集器,已脱敏清理):
java -server
-Xms26g -Xmx26g # 大堆
-XX:+UseG1GC
-XX:G1NewSizePercent=40 # 年轻代下限 40%(≈10G+)
-XX:MaxGCPauseMillis=200
-XX:MetaspaceSize=256m -XX:MaxMetaspaceSize=256m
-XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:gc.log
-XX:+HeapDumpOnOutOfMemoryError
-XX:NativeMemoryTracking=summary
-jar gameserver.jar
GC 日志统计出来的数据(压测负载下):
| 指标 | 数值 |
|---|---|
| YGC 频率 | 约每 15 秒一次 |
| YGC 平均单次耗时 | 421ms(远超 200ms 目标) |
| FGC 频率 | 约每 55 分钟一次 |
| FGC 平均单次耗时 | 接近 20 秒 |
顺带一句复盘:26G 的大堆配 G1NewSizePercent=40,年轻代下限就有 10G+,单次 YGC 想快也快不起来——这个参数组合本身值得商榷。但当时真正要命的问题还不在这,而在下面这个现象。
二、现象:空跑的机器,内存一路狂飙
服务器没有任何玩家、自然空跑的情况下,堆内存曲线是标准的锯齿,但锯齿周期大得离谱:
- 从最低约 0.2G 一路涨到 8G,耗时约 107 分钟;
- 涨满触发 YGC,回到 0.2G 附近,然后开始下一轮。
先说结论性的判读:内存能被 GC 正常回收,说明没有内存泄漏;锯齿周期这么长,说明有个东西在持续高速创建对象——空跑的服务器,哪来的这么大分配量?
三、第一反应:调参(然后被现实教育)
当时的第一直觉还是从 GC 参数下手:把 G1NewSizePercent 从 40 调到 30,让年轻代小一点、YGC 来得勤一点。
结果:
| 调整前 | 调整后 | |
|---|---|---|
| G1NewSizePercent | 40 | 30 |
| 内存涨到触发 YGC 的水位 | ~8G | ~3.7G |
| 一个上涨周期的耗时 | 约 107 分钟 | 约 32 分钟 |
触发水位变了、周期变了,但曲线的爬升斜率——单位时间的内存增长速度——没有任何变化。
这一下把"GC 配置问题"这个假设证伪了:调参只能改变"什么时候回收",改变不了"垃圾产生的速度"。对象分配的速率是业务代码决定的——必须去找到谁在分配。
排查技巧:遇到"内存持续上涨",先看锯齿能不能回到底。能回收 = 不是泄漏,是分配速率问题,别在 GC 参数上浪费时间;回不到底 = 泄漏,往引用链上查。两个方向的工具和方法完全不同。
四、第一轮定位:AQS 的 Node 在飞涨(JProfiler)
工具链:JProfiler(arthas + jmap 也能做类似的事,JProfiler 的对象分配记录更顺手)。
第 1 步:看堆内对象排行。 连上进程,观察各类型对象数量的变化,很快发现异常:java.util.concurrent.locks.AbstractQueuedSynchronizer$Node 的数量在飞快增长,一骑绝尘。
第 2 步:记录分配栈。 打开 JProfiler 的对象分配记录(Record Object),针对 Node 记录一段时间,然后看分配树(Allocation Tree)——不看存量、看增量是从哪段代码分配出来的。
分配树指向:某个业务模块的 worker 线程,正在一个自研延时队列(参考 JDK DelayQueue 的 leader 设计)的 poll 逻辑里疯狂 new Node。
第 3 步:读代码。 该逻辑里能 new Node 的位置只有三处,本地断点跑一遍,确认线程在反复走第三处。进入该分支的条件是:
if (nanos >= delay && leader == null) { ... }
对着这两个变量一算,问题明牌了:
nanos是外部传入的超时 30 秒,换算成了纳秒:3 × 10¹⁰;delay是任务的延迟时间,用毫秒算的:3 × 10⁴;- 两个单位差了 100 万倍,
nanos >= delay恒成立 → 本该await挂起的线程变成了自旋空转,每一圈循环都 new 一个 Node。
一个低级到不好意思承认的单位 bug,让一个线程以全速空转生产垃圾。修复方式很朴素:统一单位。
这类"单位不一致"的 bug 有个可怕之处:功能上几乎无感(延时任务照样执行),唯一的表现就是 CPU 和内存的缓慢异常——不压测根本发现不了。
修复后观察:Node 暴涨的现象消失了,内存增速明显放缓。但是,曲线还在涨——说明还有别的对象在持续产生。收口第一个问题,马上开第二轮。
五、第二轮定位:每 5 分钟一次的 Kryo 洪峰(diff 大法)
这次现象更细:内存增长呈周期性,每 5 分钟涨约 120M,折合每小时约 1.4G。周期性 = 有个定时逻辑在批量产生对象。
用 JProfiler 的 diff 功能:选择 All Objects → 点 Mark Current 打个标 → 等 15 分钟 → 看增量。结果:Kryo 序列化相关的对象每 5 分钟增长 33%,15 分钟翻倍,增量全部指向它。
继续看分配树,指向主循环的 tick 线程里的一段配置热更检测逻辑:
每 5 分钟执行一次
→ 遍历所有配置表的每一行
→ 对每行对象做序列化 + md5 比对,判断配置是否变化
→ 每次执行产生的临时对象数 = 表数量 × 每表行数
几十张配置表 × 每张几百行,每 5 分钟全部序列化一遍——这就是 120M 洪峰的来源。
修复决策更快:这段检测逻辑只在 debug 模式下才有意义,线上和常规开发都不需要——直接关闭。
两次修复后的内存曲线:增速大幅下降,空跑状态下的分配量回归正常水位。YGC 频率随之下降,压测的 GC 停顿数据也跟着好转——分配速率下来,一切都会好。
六、方法论沉淀
这次排查比"解决了两个 bug"更值钱的是套路:
1. 先分类,再动手
内存持续上涨
├─ GC 后能回到底 → 分配速率问题 → 找"谁在分配"(分配树/diff)
└─ GC 后回不到底 → 内存泄漏 → 找"谁在持有"(支配树/引用链)
2. 两个 JProfiler 核心操作要形成肌肉记忆
- 分配记录 + 分配树:回答"这批对象从哪行代码来"(针对存量异常的对象);
- Mark Current + diff:回答"这段时间内新增了什么"(针对周期性/缓慢增长,比看绝对数敏感得多)。
3. 备两个概念,看报告不懵
- 浅堆(Shallow Heap):对象自身占用的内存;
- 深堆(Retained Heap):回收这个对象能真正释放的内存(只算被它独占支配的部分,共享引用不算)。排查泄漏时按 Retained 排序,按浅堆排序容易被大数组带偏。
4. 修复一个收口一个,再看下一个——多线并进必然互相干扰。
七、附:游戏服 JVM 进程"悄无声息退出"的四种原因
排查内存问题时常碰到进程直接没了,按这四类查:
| 原因 | 特征 | 查什么 |
|---|---|---|
| JVM 自身 OOM | 有 hs_err / heap dump | -XX:+HeapDumpOnOutOfMemoryError 的产物 |
| JNI 崩溃 | 有 hs_err 日志,含 C++ 栈 | hs_err 里的 native 栈;开了 ulimit -c 的可用 gdb 分析 core 文件 |
| OS 内存不足被 kill | 无任何日志,悄无声息 | /var/log/messages 找 OOM killed 记录 |
| 机器重启/关机 | 进程没了,uptime 归零 | 运维查关机原因(人为/定时/硬件/内核) |
第三种最容易被当成"玄学崩溃"——进程消失得干干净净,答案往往在操作系统日志里。
八、写在最后
回头看,这次"JVM 调优"里真正起作用的没有一个是 GC 参数:一个是单位不一致的自旋,一个是本该关掉的检测逻辑。GC 调优的前提是分配行为合理,否则就是在给漏水的水池换更大的水泵。