背景
我司商城系统生产服务隔一段时间就挂掉一次,所有的机器都有这个问题,而且问题出现的越来越频繁,从最开始的半个月一次,到后来一周一次、3天一次,一直到最后的1天1次甚至2次,导致服务极其不稳定,查找泄漏源成了迫切要解决的问题
初步排查和猜测
1、首先获取应用pid
ps -ef|grep marketing-center
2、根据pid查询java应用堆内存使用情况,以及应用进程占用系统内存情况
#查看java程序GC情况以及堆内内存使用情况
jstat -gc $pid 2000
#结果如下
[www@idc06-c-marketingcenter-03 ~]$ jstat -gc 14626 2000
S0C S1C S0U S1U EC EU OC OU MC MU CCSC CCSU YGC YGCT FGC FGCT GCT
0.0 65536.0 0.0 65536.0 2068480.0 737280.0 3436544.0 258445.0 98432.0 92081.3 11392.0 10229.1 191 11.714 0 0.000 11.714
0.0 65536.0 0.0 65536.0 2068480.0 925696.0 3436544.0 258445.0 98432.0 92081.3 11392.0 10229.1 191 11.714 0 0.000 11.714
0.0 65536.0 0.0 65536.0 2068480.0 1118208.0 3436544.0 258445.0 98432.0 92081.3 11392.0 10229.1 191 11.714 0 0.000 11.714
0.0 65536.0 0.0 65536.0 2068480.0 1372160.0 3436544.0 258445.0 98432.0 92081.3 11392.0 10229.1 191 11.714 0 0.000 11.714
0.0 65536.0 0.0 65536.0 2068480.0 1554432.0 3436544.0 258445.0 98432.0 92081.3 11392.0 10229.1 191 11.714 0 0.000 11.714
0.0 65536.0 0.0 65536.0 2068480.0 1667072.0 3436544.0 258445.0 98432.0 92081.3 11392.0 10229.1 191 11.714 0 0.000 11.714
0.0 65536.0 0.0 65536.0 2068480.0 1699840.0 3436544.0 258445.0 98432.0 92081.3 11392.0 10229.1 191 11.714 0 0.000 11.714
0.0 65536.0 0.0 65536.0 2068480.0 1839104.0 3436544.0 259483.3 98432.0 92081.3 11392.0 10229.1 191 11.714 0 0.000 11.714
0.0 65536.0 0.0 65536.0 2068480.0 1880064.0 3436544.0 259483.3 98432.0 92081.3 11392.0 10229.1 191 11.714 0 0.000 11.714
0.0 51200.0 0.0 51200.0 2082816.0 274432.0 3436544.0 245594.6 98432.0 92081.3 11392.0 10229.1 192 11.786 0 0.000 11.786
0.0 51200.0 0.0 51200.0 2082816.0 321536.0 3436544.0 245594.6 98432.0 92081.3 11392.0 10229.1 192 11.786 0 0.000 11.786
#查看应用进程占用系统内存情况,可以用top代替
ps -p $pid -o rss,vsz
#结果如下:
[www@idc06-c-marketingcenter-03 ~]$ ps -p 14626 -o rss,vsz
RSS VSZ
12303720 19423396
根据以上信息可以看出,堆内内存使用也就5G左右,但是Java应用实际占用内存却高达12G左右,而且堆内内存一切正常,Young GC也比较正常平稳,Full GC也保持在一个较低的频率,通过以上数据基本可以断定发生了Java堆外内存泄漏,为了验证我的猜想,使用pmap命令查看一下系统内存分配
#查看系统内存分配情况
pmap -x $pid | sort -k3 -n
#结果如下,内容较多,截取关键部分展示
[www@idc06-c-marketingcenter-03 ~]$ pmap -x 14626 | sort -k3 -n
...
00007f44d8000000 65536 64712 64712 rw--- [ anon ]
00007f4578000000 65508 64744 64744 rw--- [ anon ]
00007f44d4000000 65524 64860 64860 rw--- [ anon ]
00007f43fc000000 65536 64996 64996 rw--- [ anon ]
00007f4464000000 65508 65004 65004 rw--- [ anon ]
00007f4528000000 65536 65044 65044 rw--- [ anon ]
00007f43dc000000 65536 65060 65060 rw--- [ anon ]
00007f45a4000000 65524 65148 65148 rw--- [ anon ]
00007f43d0000000 65508 65156 65156 rw--- [ anon ]
00007f45a0000000 65516 65180 65180 rw--- [ anon ]
...
发现大量64MB左右的内存块,且分配地址在堆外,以上内容验证了我的猜想,确实有堆外内存泄漏
详细排查经过
由于是堆外内存泄漏,JDK自带的工具已经不好用了,首先借助谷歌的内存分配监测工具gperftools
来排查具体哪段代码进行了堆外内存申请,具体安装使用请参考:Java直接内存泄漏排查工具gperftools使用方法
#结果较多,截取部分
Total: 125704.3 MB
94257.6 75.0% 75.0% 94257.6 75.0% updatewindow
20573.0 16.4% 91.3% 20573.0 16.4% inflateInit2_
9946.9 7.9% 99.3% 9946.9 7.9% os::malloc@91de80
457.8 0.4% 99.6% 457.8 0.4% init
253.1 0.2% 99.8% 20826.1 16.6% Java_java_util_zip_Inflater_init
149.0 0.1% 99.9% 149.0 0.1% readCEN
38.4 0.0% 100.0% 38.4 0.0% __GI__dl_allocate_tls
14.7 0.0% 100.0% 14.7 0.0% deflateInit2_
3.8 0.0% 100.0% 156.2 0.1% ZIP_Put_In_Cache0
2.4 0.0% 100.0% 2.4 0.0% _dl_new_object
2.2 0.0% 100.0% 2.2 0.0% newEntry
1.3 0.0% 100.0% 1.3 0.0% __GI___strdup
0.9 0.0% 100.0% 0.9 0.0% __res_context_send
0.7 0.0% 100.0% 0.7 0.0% JLI_MemAlloc
...
通过分析结果我们可以将目光聚焦在updatewindow
与Java_java_util_zip_Inflater_init
上,由于updatewindow
不是Java方法申请的内存,我们可以忽略不计,将重心放在Java Native 方法Java_java_util_zip_Inflater_init
上,根据这个结果我们可以去项目中搜索所有使用Inflater类的代码,最终将范围缩小到GZIPInputStream
与GZIPOutputStream
这两个类,但是由于项目中使用这些类的地方还是比较多,所以依然无法确认问题代码
定位问题代码并解决
使用 gdb
命令 dump
出了那些64M的内存块,然后通过查看dump出来的结果最终定位到问题
注意:dump内存会挂起应用进程,一定要确保没有流量流入再使用
1、找出那些64MB内存的地址
#命令
less /proc/$pid/smaps
#结果
[www@idc06-c-marketingcenter-07 ~]$ less /proc/14626/smaps
7f43dc000000-7f440e000000 ---p 00000000 00:00 0
Size: 65536 kB
Rss: 65536 kB
Pss: 65044 kB
Shared_Clean: 0 kB
Shared_Dirty: 0 kB
Private_Clean: 0 kB
Private_Dirty: 0 kB
Referenced: 0 kB
Anonymous: 65536 kB
AnonHugePages: 0 kB
Swap: 0 kB
KernelPageSize: 4 kB
MMUPageSize: 4 kB
Locked: 0 kB
VmFlags: rd wr mr mw me ac sd
...
2、使用gdb
命令dump
出内存
#先连接程序
gdb -pid $pid
#进入gdb调试模式dump内存
dump memory mem.bin 7f43dc000000 7f440e000000
#mem.bin是内存dump出来的文件,后面是地址
strings mem.bin > mem.log #将二进制文件读取成字符串并输出到文件,方便查阅
less mem.log
内存dump文件内容如下:
[www@idc06-c-marketingcenter-03 ~]$ less mem.log
...
com.xxx.marketing.domain.dto.GroupProductItemAi&$*^@($)-jtsjrns?:]][\\..,;0&^(
=-com.xxx.marketing.domain.dto.GroupProductItemAi&$*^@($)-jtsjrns?:]][\\..,;0&^(
=-com.xxx.marketing.domain.dto.GroupProductItemAi&$*^@($)-jtsjrns?:]][\\..,;0&^(
=-&$*^@($)-jtsjrns?:]][\\..,;0&^(=-com.xxx.marketing.domain.dto.GroupProductItemAi
...
上图省略了一部分内容,我发现很多个64MB文件全都是GroupProductItemAi
对象,最后终于肯定泄漏的对象就是 marketing-center
中的 POJO
com.mryt.marketing.center.domain.GroupProductItemAi
然后在项目中全局搜索该POJO
然后根据上面得到的GZIPInputStream
与GZIPOutputStream
直接申请内存等关键信息定位到最终的问题代码
/**
* 问题代码
*/
public Map<String, T> hgetAllObject(String key, int seconds) {
if (key == null) {
return null;
}
Map<byte[], byte[]> hMap = null;
ShardedJedis commonJedis = null;
Map<String, T> returnMap = null;
T object = null;
try {
commonJedis = jedisPool.getResource();
hMap = commonJedis.hgetAll(key.getBytes());
if (hMap == null) {
return null;
}
returnMap = new HashMap<String, T>();
Set<byte[]> keySet = hMap.keySet();
ByteArrayInputStream i = null;
GZIPInputStream gzin = null;
ObjectInputStream in = null;
// 这里循环创建了i gzin in等三个对象的多个副本
for (Iterator<byte[]> it = keySet.iterator(); it.hasNext(); ) {
byte[] keyItem = it.next();
byte[] valueItem = hMap.get(keyItem);
// 建立字节数组输入流
i = new ByteArrayInputStream(valueItem);
// 建立gzip解压输入流
gzin = new GZIPInputStream(i);
// 建立对象序列化输入流
in = new ObjectInputStream(gzin);
// 按制定类型还原对象
object = (T) in.readObject();
returnMap.put(new String(keyItem), object);
}
// 这里只释放了最后一个,造成了中间对象没有调用close方法释放内存
if (i != null && gzin != null && in != null) {
i.close();
gzin.close();
in.close();
}
if (seconds > 0) {
commonJedis.expire(key, getRealCacheTime(seconds));
}
} catch (Exception e) {
jedisPool.returnBrokenResource(commonJedis);
RedisException.exceptionJedisLog(logger, key, commonJedis, e, "hgetAllObject");
commonJedis = null;
} finally {
if (commonJedis != null) {
jedisPool.returnResource(commonJedis);
}
}
return returnMap;
}
上面的代码在for
循环里创建了多个GZIPInputStream
但是却只在for
循环之后释放了最后一个GZIPInputStream
对象,所以造成了大量的内存泄漏,至此,终于找到了泄露源,然后根据业务情况选择修复方式即可。