# 向Log4j中记录大对象日志导致系统宕机
# 问题现象
客户昨天出现两次系统卡顿不可用,重启后临时恢复了。
今天又出现一次系统崩溃,崩溃后,控制台显示java.lang.OutOfMemoryError: Java heap space
异常,并且生成了java_pidxxxx.hprof文件。
# 分析过程
# 第一步:分析JVM内存配置合理性
以上信息已经非常明确:Java heap space 错误表示Java虚拟机(JVM)中的堆内存区域不足,无法为新对象分配空间。
首先,了解客户的日常在线人数在200多人,这个在线正常情况下16G堆内存就够用。再检查服务器总内存128G,分配给JVM配置-Xms32G -Xmx32G
,堆内存是32G,大于预期的16G,说明配置是没问题的。
那么,下一步重点是分析程序代码,应该是有不合理的程序代码导致内存申请巨大,从而引发系统宕机。
控制台显示生成了java_pidxxxx.hprof文件,这个是崩溃时的堆内存占用信息,通过分析该文件就能绝对定位问题。此文件生成路径在:ApacheJetspeed\bin目录下。
# 第二步:分析周边异常
由于hprof文件分析需要一个非常大内存的服务器,以及MAT分析工具,准备工作比较复杂。
此时可以先分析下服务器周边数据,看下是否存在什么异常,从异常点分析潜在原因。
本次发生系统性能问题的时候,我们发现logs_sy下产生了海量的日志(一个小时不到产生了80G的日志文件)。
通过分析文件发现是form.log日志巨量生成:
进一步查看日志内容,发现全部都是客开日志:
反编译源码,发现客开将组织机构对象都打印到日志中了,这个是开发的忌讳,组织对象会很大,盲目写入日志会造成内存溢出风险:
以上分析,可以怀疑:写入日志是一个可能性!
# 第三步:分析hprof文件,定位根因
下一步,为了印证问题,就要彻底分析hprof文件,分析该文件需要准备如下内容:
1、一台独立的Windows服务器,内存需要大于hprof文件大小,比如本次java_pidxxxx.hprof文件是64G,则需要一个64G以上内存的服务器分析。
2、下载分析工具,通过MemoryAnalyzer(俗称MAT)工具可以分析当时的内存占用,下载地址: https://www.eclipse.org/mat/downloads.php https://www.eclipse.org/mat/previousReleases.php
3、服务器下需要安装JDK8
分析过程不赘述,分析结果如下,可以看到一块55.6G堆空间是存在问题的:
再下钻分析,发现全部是log4j占用内存:
实际,可以通过服务器上的分析报告thread也能定位到具体调用log4j的地方。
# 第四步:明确结论
通过以上分析,可以确认是Log.info记录了大对象导致内存溢出,联系客开去掉代码后问题解决。