Java应用堆外内存泄漏排查

背景

我司商城系统生产服务隔一段时间就挂掉一次,所有的机器都有这个问题,而且问题出现的越来越频繁,从最开始的半个月一次,到后来一周一次、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
...

通过分析结果我们可以将目光聚焦在updatewindowJava_java_util_zip_Inflater_init上,由于updatewindow不是Java方法申请的内存,我们可以忽略不计,将重心放在Java Native 方法Java_java_util_zip_Inflater_init上,根据这个结果我们可以去项目中搜索所有使用Inflater类的代码,最终将范围缩小到GZIPInputStreamGZIPOutputStream这两个类,但是由于项目中使用这些类的地方还是比较多,所以依然无法确认问题代码

定位问题代码并解决

使用 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然后根据上面得到的GZIPInputStreamGZIPOutputStream直接申请内存等关键信息定位到最终的问题代码

/**
 * 问题代码
 */
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对象,所以造成了大量的内存泄漏,至此,终于找到了泄露源,然后根据业务情况选择修复方式即可。

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 203,324评论 5 476
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 85,303评论 2 381
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 150,192评论 0 337
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 54,555评论 1 273
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 63,569评论 5 365
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 48,566评论 1 281
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 37,927评论 3 395
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 36,583评论 0 257
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 40,827评论 1 297
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 35,590评论 2 320
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 37,669评论 1 329
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 33,365评论 4 318
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 38,941评论 3 307
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 29,928评论 0 19
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 31,159评论 1 259
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 42,880评论 2 349
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 42,399评论 2 342

推荐阅读更多精彩内容