这篇文章成文于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