现象
-
观察jcmd日志发现内存占用正常。
jcmd日志 - 通过top命令查看,发现进程占用内存越来越大,超过
-XMX
和-XX:MaxDirectMemorySize
内存占用总和。
top内存占用 - 进程运行一段时间后会异常退出,退出时未产生任何异常日志。
猜想
- 堆外内存溢出(jcmd为什么无法跟踪堆外内存请查看后文总结)
- 系统内存不足时,进程被系统杀死(如果是这样,大概率系统运行日志中会有一些进程被异常杀死的信息)
排查过程
- 查看系统日志,grep <pid> /var/log/messages
系统运行日志
日志中可以看出,进程确实被系统kill,同时我发现熟悉的身影pool-1-thread-7
,这应该是某个线程池的线程名,查看线程池默认创建线程的代码发现线程池创建线程时,线程名命名规则为:pool-{poolNumber}-thread-{threadNumber}
,看源码发现同一个线程池的poolNum
是一致的。
线程池创建线程源码
那么我们只要确定这是哪个线程池,就可以定位问题产生的代码段。 - 重启系统一段时间后打印jstack,等待下一次进程退出并查看日志,根据系统日志中的线程名和jstack中的线程名对比找到了线程的堆栈,并定位了具体的线程池。
- 找到问题产生的代码段,事情就变得简单了
仔细阅读代码发现代码中存在未关闭的OutputStream
问题代码
查看GZIPOutputStream.close()
发现close
方法中会调用java.util.zip.Deflater.end()
方法,网上查询资料发现Deflater
会通过jni调用系统底层方法直接分配系统内存,如果不调用end()
方法,内存将不会被回收,会产生堆外内存溢出。 - 通过try with resource方式使用
GZIPOutputStream
后重新上线问题得到解决。
经验总结
常见的分配堆外内存的方式
- ByteBuffer.allocateDirect()
- UnSafe
- 调用native的方法,底层使用了堆外
如何区分堆外内存溢出时以上哪种方式导致的
- 启动脚本增加参数,限制堆外内存大小
-XX:MaxDirectMemorySize=1G
- 启动脚本增加内存追踪参数
-XX:NativeMemoryTracking=detail
- jcmd观察内存占用
jcmd <pid> VM.native_memory detail scale=MB | more
jdk8观察Internal内存占用,jdk11观察other,不同jdk版本有差别,自行搜索。
- 随着系统运行,如果堆外内存占用超过 MaxDirectMemorySize 限制,说明存在UnSafe直接分配内存。
注意:MaxDirectMemorySize仅对ByteBuffer.allocateDirect()方式有效,对UnSafe无效。 - 如果第三步中观察到的堆外内存占用和实际进程占用的内存相差较大,说明存在其它方式分配了堆外内存。
注意:jcmd可以追踪到UnSafe和ByteBuffer分配的直接内存。如果程序直接调用JNI并产生了堆外内存,jcmd无法追踪,比如java.util.zip.Deflater
和java.util.zipInflater
类就会绕过UnSafe直接使用堆外内存。
网友评论