# 向Log4j中记录大对象日志导致系统宕机

# 问题现象

客户昨天出现两次系统卡顿不可用,重启后临时恢复了。

今天又出现一次系统崩溃,崩溃后,控制台显示java.lang.OutOfMemoryError: Java heap space异常,并且生成了java_pidxxxx.hprof文件。

1725526429141.png

# 分析过程

# 第一步:分析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日志巨量生成:

1725529230530.png

进一步查看日志内容,发现全部都是客开日志:

1725529352243.png

1725529385896.png

反编译源码,发现客开将组织机构对象都打印到日志中了,这个是开发的忌讳,组织对象会很大,盲目写入日志会造成内存溢出风险:

1725529418028.png

以上分析,可以怀疑:写入日志是一个可能性!

# 第三步:分析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堆空间是存在问题的:

1725527376925.png

再下钻分析,发现全部是log4j占用内存:

1725527956621.png

实际,可以通过服务器上的分析报告thread也能定位到具体调用log4j的地方。

1725527711209.png

# 第四步:明确结论

通过以上分析,可以确认是Log.info记录了大对象导致内存溢出,联系客开去掉代码后问题解决。

创建人:het
修改人:het