对页游《小兵大战》服务器DM内存溢出的排错过程总结

Posted 2022-10-13 流子

这篇文章成文于2012年公司内存论坛交流，现和大家分享一下！--流子

这个事件发生在前一阵子，总结为了给项目组的同事和自己遇到类似问题时少走冤枉路，定位问题的思路如果能给你的工作带来一点点帮助，我会非常开心！

背景：

项目名：《小兵大战》  欢迎试玩，-->传送门<--

合作平台:腾讯QQ空间，朋友网，新浪微游戏等

托管模式:使用腾讯云平台托管/部署服务(hosting) 或者自己出服务器

模式:大区单服

游戏服务器硬件配置：

资源类型	硬件	型号/版本/配置
VC3	CPU	8核，相当于2.0GHZ的Xeon处理器或Opteron处理器
	内存	7G 相当于DDR3 1066MHZ
	硬盘	300G SATA raid0 结构单盘硬盘
	OS	Linux 2.6 (suse 10,64位)

跑的都是JAVA应用(JDK 1.6)，用的数据库为mysql5.5.13,缓存数据库为Redis 2.6.11

事件:

19:35 事件信息:腾讯云监控-系统内存将占满

手机收到消息【腾讯云监控，系统内存将占满】app100630301|19:35|10.190.*.*|系统内存使用达到95%，剩余0.35G【腾讯科技】

19:50  事件信息:通过跳板机登录不了游戏服务器

怀疑整台虚拟机宕掉，通过腾讯运维重启解决

21:37 事件信息:应用游戏逻辑 game server和gate server停掉

重启所有应用解决，并开始监控分析

分析： 

step 1. 查看服务器应用的日志，没有抛出任何异常，有点诡异！

Step 2. 莫非是JVM crash 了，这样的话，应该能在几个应用的当前目录下能找到hs_err_pid*******.log 的crash log.，也没有找到，迷茫！

step 3 查看系统日志

app100630301@Tencent64:~>cat /var/log/messages |grep -i "killed process"

<span style="color:#000066">Jun 28 21:36:08 VM_235_15 kernel:out of memory:killed process [pid](java)
................

................</span>

sudo dmesg|grep -i kill|less

[6710782.021013] java invoked oom-killer: gfp_mask=0xd0, order=0, oom_adj=0, oom_scoe_adj=0
[6710782.070639] [<ffffffff81118898>] ? oom_kill_process+0x68/0x140 
[6710782.257588] Task in /LXC011175068174 killed as a result of limit of /LXC011175068174 
[6710784.698347] Memory cgroup out of memory: Kill process 215701 (java) score 854 or sacrifice child 
[6710784.707978] Killed process 215701, UID 679, (java) total-vm:11017300kB, anon-rss:7152432kB, file-rss:1232kB

以上表明，对应的java进程被系统的OOM Killer给干掉了，得分为854.

解释一下OOM killer（Out-Of-Memory killer），该机制会监控机器的内存资源消耗。当机器内存耗尽前，该机制会扫描所有的进程（按照一定规则计算，内存占用，时间等），挑选出得分最高的进程，然后杀死，从而保护机器。

dmesg日志时间转换公式:
log实际时间=格林威治1970-01-01+(当前时间秒数-系统启动至今的秒数+dmesg打印的log时间)秒数：

date -d "1970-01-01 UTC `echo "$(date +%s)-$(cat /proc/uptime|cut -f 1 -d' ')+12288812.926194"|bc ` seconds"

内存总占用超过系统内存，然后系统优先kill掉相对耗内存的进程，这种情况下既不会有crash log,也不会有core dump,推断Game server和gate server就是这样被OOM killer 灭掉的！定位到Game server 或Gate server有内存泄漏。

step 4 开始监控重启后的应用，发现gate 的内存占用有问题！

app100630301@Tencent64:~>t:~ # ps -ef|grep java

root     25936     1  0 Apr19 ?        00:17:29 java -server -Xms1G -Xmx1G -Xmn256m -XX:PermSize=64m -XX:MaxPermSize=64m -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCApplicationStoppedTime -XX:+HeapDumpOnOutOfMemoryError -Xloggc:gate_gc_1_201304191211.log -jar /data/ztgame/S20120712R1/gate/gate.jar 1

app100630301@Tencent64:~>top p 18202

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND 
 25936 root      18   0 4359m 492m 7856 S    0  64.0  17:29.21 java 

进程占用了4G多，单个进程占用达到了60%多(总共7G) 问题定位到了进程gate 以前也遇到过内存溢出的情况，但应用都会抛出java.lang.OutOfMemoryException,而这次却没有，但为何 gate苑苑超出了JVM内存配置的2G的上限呢？

Step 5 查看堆的占用

app100630301@Tencent64:~>jmap -heap 18202

<span style="color:#330099">Heap Configuration:
   MinHeapFreeRatio = 40
   MaxHeapFreeRatio = 70
   MaxHeapSize      = 1073741824 (1024.0MB)
   NewSize          = 268435456 (256.0MB)
   MaxNewSize       = 268435456 (256.0MB)
   OldSize          = 5439488 (5.1875MB)
   NewRatio         = 2
   SurvivorRatio    = 8
   PermSize         = 67108864 (64.0MB)
   MaxPermSize      = 67108864 (64.0MB)

Heap Usage:
New Generation (Eden + 1 Survivor Space):
   capacity = 241631232 (230.4375MB)
   used     = 43095400 (41.098976135253906MB)
   free     = 198535832 (189.3385238647461MB)
   17.835194417251493% used
Eden Space:
   capacity = 214827008 (204.875MB)
   used     = 41506656 (39.583831787109375MB)
   free     = 173320352 (165.29116821289062MB)
   19.320967315245575% used
From Space:
   capacity = 26804224 (25.5625MB)
   used     = 1588744 (1.5151443481445312MB)
   free     = 25215480 (24.04735565185547MB)
   5.927215053866137% used
To Space:
   capacity = 26804224 (25.5625MB)
   used     = 0 (0.0MB)
   free     = 26804224 (25.5625MB)
   0.0% used
concurrent mark-sweep generation:
   capacity = 805306368 (768.0MB)
   used     = 265440944 (253.1442108154297MB)
   free     = 539865424 (514.8557891845703MB)
   32.96148578325907% used
Perm Generation:
   capacity = 67108864 (64.0MB)
   used     = 26712504 (25.47502899169922MB)
   free     = 40396360 (38.52497100830078MB)
   39.80473279953003% used</span>

算了下，实际堆内存占用才1G左右，苑苑没有达到JVM的内存占用上限，那么，那3G多的内存是从哪里泄漏的呢？

Step 6. JVM除了堆内存外，就只有栈内存和Direct Memory了，栈空间每个线程是固定的，而占用大小基本固定而且可以忽略，而Direct Memory或者叫直接内存，并不是虚拟机运行时数据区的一部分，不受JVM的GC管理，其中Java的nio中Buffer直接在堆外分配的就属于这个部分，直接以native的方式分配内存，这是为了提高网络和文件的IO效率，避免过度的内存拷贝而出现的，那么，怀疑的目标就只剩下Direct Memory了。

Direct Memory 占用的大小没有直接的工具或者API可以查看，不过，我们可以通过反射在某个类里拿到这个数据。

<span style="color:#000066">Class<?> c = Class.forName("java.nio.Bits");
Field maxMemory = c.getDeclaredField("maxMemory");
maxMemory.setAccessible(true);
Field reservedMemory = c.getDeclaredField("reservedMemory");
reservedMemory.setAccessible(true);
Long maxMemoryValue = (Long)maxMemory.get(null);
Long reservedMemoryValue = (Long)reservedMemory.get(null);</span>

如果不想反射获得，那么，netty已经给我们提供了一个方法，

io.netty.util.internal.PlatformDependent#maxDirectMemory()直接用就行，感谢netty

参考来源:JVM的DirectMemory设置

reservedMemoryValue 表示直接内存的已占用大小，结果明显正式了我的猜测！Direct Memory增长失控了，那么，是什么导致了Direct Memory内存泄漏呢?

Step 7.记得为了减少和客户端的数据通信量大小，协议的来往都会通过zlib进行压缩和解压，而 zlib codec为了提高压缩和解压的效率采用了nio包的direct-buffers.那么，如果猜测是对的话，如果暂时关闭压缩和解压的功能，应该停止内存泄漏，于是吧服务器的压缩开关关闭。

<span style="color:#000066">14:06 400M 5.6%
14:10 511M,7.3% 
15:08 606M 8.7%
15:14 626M 8.9%
16:17 629M 9.0% </span>

基本已经不变，稳定！

Step 8 知道了根本原因，修改代码，zlib codec的Deflater 和Inflater在压缩和解压后都需要关闭，才能保证内存不会泄漏！

<span style="color:#000066">Inflater decompresser=null;
解压加上 finally
decompresser.end();

Deflater compresser=null;
压缩加上 
解压加上 finally
compresser.end();
</span>

Step 9.修改完毕，发出版本，搞定！

总结

综上，分析问题的定位思路，从确定应用Game server或者gate server --> 锁定 Gate server -> Gate Server -> 锁定Direct Memory的溢出->最终确定是Zlib的压缩和解压为内存溢出的根本原因，层层分析，顺藤摸瓜，希望大家看到后都能得到一些收获！

有什么问题想交流的，请随时和我联系，谢谢！

QQ：41157121