一次线上Java应用内存泄漏分析实例

由于JVM的内存管理采用GC垃圾自动回收机制,这使得Java程序员在编程的时候确实可以从内存管理中释放出来,但这也引发了另外一个大问题,一旦Java应用出现内存泄漏的时候,常常让人措手不及,陷入无从下手的尴尬境地,我们总不能一句话重启吧(苦笑)。

内存问题可能是大多数Java程序员心中都曾有过的伤,因为太容易遇见了

下面这篇文章是我去年写在个人微信公众号上的,今天早上回头再看心中不免有些嘘嘘感慨,于是决定重新整理把它发到简书上来,以下为正文:

前2天负责的一个线上系统在早上9点20分接到大量用户反馈系统很卡,页面无响应。我联系运维及时查看后台服务器,发现WAS(Websphere) server bin目录下生成了javacore 和heapdump,这个消息让我整个人都不好了,项目推广关键时期居然来这么一出,可谓多事之秋,搞事情啊!

 好吧,既然程序运行时遇到了坑,那我们就先来找到这个坑,再把坑填好(围笑)。

 简单介绍下,线上应用运行在power linux OS平台之上,web容器为IBM WebSphere ,JDK  ibm j9vm 64 位。

 首先开始通过ibm ha456.jar 分析线上dump 文件

一次线上Java应用内存泄漏分析实例
一次线上Java应用内存泄漏分析实例

 上图Heap usage,堆内存已使用约3.7G,且41.95%的内存都被rootobject 和它的引用吃掉了,接下来我再查看rootobject ,如下图:

一次线上Java应用内存泄漏分析实例

内存主要是被2个LinkedHashMap吃掉了,于是仔细查找项目源码中会用到LinkedHashMap的地方,无果。

接下来再来看一下这些LinkedHashMap当中都包含什么对象,看看它们会指向哪些东西呢,如下图:

一次线上Java应用内存泄漏分析实例

这里发现有一个org.xhtmlrender.resource.ImageResource类,且点开所有节点LinkedHashMap 都有此类的实例及强引用,如下图显示第一个root  LinkedHashMap 有178个此类实例

一次线上Java应用内存泄漏分析实例

于是继续分析下ImageResource 类节点,如下图:

一次线上Java应用内存泄漏分析实例

此对象节点只有一个parentes node,且这个parentes node 对象就是LinkedHashMap

接着我查看项目源码,发现 org.xhtmlrender.resource.ImageResource类属于如下图:

一次线上Java应用内存泄漏分析实例

Maven 引用如下:

一次线上Java应用内存泄漏分析实例

分析项目代码,上面3个jar包是用来将html文件转成pdf文件,目前能推断出的结论是此功能模块耗用尽了jvm 堆内存,由此导致线上应用崩溃了。。。

仔细检查这一功能块区域的代码发现不存在有大规模瞬时加载大量数据到内存中的潜在代码,由此判断不是瞬时某个交易功能导致,应该是此功能区域的某个方法执行时存在内存泄漏的可能

线上应用架构是集群 F5部署,因此有另外一台尚没有生成javacore 的was服务做对比,于是在当晚非作业时间,kill -3 [pid]生成dump 文件进一步分析,发现这台应用的堆内存也用到3.6G,只是还没有到崩溃的临界点而已,且都是被同样的LinkedHashMap 吃掉大半以上。

内存泄漏点几乎已确定在此处了,于是让同事写了一个客户端测试小程序并发的对此功能区方法Action发起请求,以下为测试环境请求我自己本地服务JVM监控图示:

一次线上Java应用内存泄漏分析实例
1

上部左边图可看出垃圾回收活动越来越频繁,上部右边图堆内存的已使用占比也在缓慢递增,典型的内存有泄漏,GC每次回收都不完全,导致GC回收的复杂度越来越高,离out of memory 只是时间问题。

再对测试环境中的was服务器进行压测,以进一步验证此问题点,发现was体系内存的开销更明显,如下图,看到内存呈现阶梯式递增

一次线上Java应用内存泄漏分析实例
2

对比上面2图,在客户端测试程序压力一定情况下,was服务器(1.6jdk)的表现比我本机还要糟糕,这可能是我本机Mac用的1.8 jdk JVM GC相对于1.6有优化吧。

服务端在运行4小时之后,内存耗尽,程序Over,且在was应用目录下生成了javacore(这期间暂停过很多次客户端压力程序,但服务端JVM堆内存的占用一直是居高不下,无法回收)。

一次线上Java应用内存泄漏分析实例
3

同样使用ha456分析javacore,发现堆内存的耗用情况与生产几乎一致,堆内存大部分都是耗用在LinkedHashMap和commons pool中


一次线上Java应用内存泄漏分析实例
4

至此断定问题一定是出在html转pdf方法体中,查阅项目源码及用到的开源jar包说明文档,定位到出问题的关键代码块如下:

一次线上Java应用内存泄漏分析实例

初步分析应该是ITextRenderObjctFactory中ObjctPool池的ITextRender对象资源不释放导致的,对象池Factory关键配置如下:

一次线上Java应用内存泄漏分析实例

查阅相关资料说明,我分析应该是ITextRende对象一直活跃在对象池pool中(pool默认配置:空闲对象可存活30分钟),应用在白天作业期间对htmlToPdf方法的调用几乎不会有空闲时间,所以render一直处于被外围重复调用的情况,导致render持有的资源一直无法得到释放的机会,进而使程序内存耗尽

调研过其他项目组源码也有类似实现的写法,但是未出现内存耗尽的情况,对比源码分析区别在于其他项目组render渲染html为pdf 时并未涉及到html文件中有可变图片url引用的链入,而我们项目组每次html转pdf 时存在可变路径的图片引用,导致render需要每次动态创建ImageResource类来动态加载外部图片URL链接,而动态创建的ImageResource 实例并未能释放。

因此对以上关键代码进行优化如下:

一次线上Java应用内存泄漏分析实例

第一个红色箭头修改部分改为document 由原来的url加载方式改为file

第二个红色箭头为新添加代码,用于把ITextRender共享上下文Context内容重置,以便于单个render对象中的资源及时释放;

同时对于ObjectPool池config配置优化如下,关键代码:

一次线上Java应用内存泄漏分析实例

修改参数说明如下:

1、空闲对象获取策略修改为FIFO,先进先出,便于对象池中的对象公平共享使用,便于空闲未使用到的对象及时释放


一次线上Java应用内存泄漏分析实例

2、timeBetweenEvictionRunsMillis为每间隔5秒检查一下是否存在空闲Idle对象

3、minEvictableIdleTimeMillis空闲对象存在1分钟未被调用即销毁

OK,优化之后,更新was服务,使用之前的客户端测试程序发起压力测试,将堆内存上限设定为1G,结果表现如下:


一次线上Java应用内存泄漏分析实例

持续压测2小时,内存耗用稳定在1G以内,当客户端压力撤去,3分钟之后内存稳稳回收到200M左右,如下:


一次线上Java应用内存泄漏分析实例

接下来稳定性测试6小时,持续压测,压力撤去之后,内存占用逐渐回归到600M左右


一次线上Java应用内存泄漏分析实例

更新线上应用程序不再出现问题,至此,总算把此问题解决。在这期间收集用于分析的javacore和dump文件约5G(包含测试环境was、生产环境was、本机tomcat)

一次线上Java应用内存泄漏分析实例

以上从定为问题、找到原因、测试复现、解决问题到复测通过我断断续续用了2天时间,这2天放下了手头一切工作上相对来说优先级没有此问题高的事情,可能有的朋友会感觉我最近工作不走心了呢,其实不然,不会了(围笑)。

软件系统最常见的就是系统故障,人非圣贤孰能无过,程序员都是人,是人就会写Bug,写了Bug系统就会出问题,出了问题系统就可能宕机。即使你什么事都没干正在家里陪老丈人喝酒,人家在微博上说,大家好,给大家介绍一下,这是我的女盆友。哐当,系统挂了,这特么能怪谁呢?真出了问题,慌,骂人,处罚都是后话,没用的,重要的是解决问题,梳理流程,增加监控,减少损失,最后复盘问题才是牛批。

现在我们的项目正处于大力推广前的关键时期,软件将迎来最终用户的快速增长,保持服务的稳定是重中之重。

前段时间看到Mac Talk公众号池建强老师发的一篇原创文章,大意讲的是我们每个人在临大战前应有静气,何意?就是你面临压力和挑战的时候,一方面心跳加速血管收缩手心冒汗,但你感到的是兴奋而不是焦虑,内心深处是安静的,沉着的。

最后大家要是觉得本文还OK,对你的工作学习有所帮助的话请给点个赞️!笔芯

如果你对设计模式学习感兴趣的话,请关注下我,因为我最近正在编写一部《从零开始学设计模式》系列。

上一篇:python基础1-3:heapq 模块的nlargest() 和 nsmallest()


下一篇:从零开始学设计模式(六)—适配器模式(Adapter Pattern)