百度360必应搜狗淘宝本站头条
当前位置:网站首页 > 技术教程 > 正文

JVM 堆外内存泄漏排查

csdh11 2025-03-03 18:11 30 浏览

现象:

operation服务持续内存增长不释放导致超过80%阈值告警,通过观察内存不会下降,而且占用内存为14G超过了jvm 参数 -Xmx10G 的限制

排查

查看容器内存监控发现:内存确实从启动之后就开始一直增长,并且不释放

top命令也能看到java进程确实占用了14G物理内存

当前jvm启动参数如下:

-Xms10g -Xmx10g -server -verbose:gc 
-Xloggc:/home/work/logs/applogs/gc_%t.log 
-XX:ErrorFile=vmerr.log 
-XX:+HeapDumpOnOutOfMemoryError 
-XX:HeapDumpPath=/home/work/logs/applogs/
-XX:+DisableExplicitGC 
-XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps
-XX:+PrintHeapAtGC -XX:+PrintTenuringDistribution -XX:+PrintReferenceGC 
-XX:MetaspaceSize=512m -XX:MaxMetaspaceSize=512m -XX:ReservedCodeCacheSize=256m 
-XX:InitialCodeCacheSize=256m -XX:+PrintAdaptiveSizePolicy -XX:+UseG1GC 
-XX:MaxGCPauseMillis=200 -XX:+UnlockExperimentalVMOptions -XX:G1LogLevel=finest  
-XX:CompressedClassSpaceSize=128m 
-Djava.library.path=/opencv-3.4.3/build/lib 
-XX:+UseStringDeduplication 
-XX:ParallelGCThreads=4 -XX:+AlwaysPreTouch

从上面的现象结合启动参数我们很容易判断这是堆外内存泄漏了(为什么?因为启动参数只分配了10g的堆,加上metadata 512m 也不过11g以内,现在用了14g肯定是还有其他堆外内存使用)。

为了弄清楚14g花在哪里了,我们需要跟踪一下Native Memory,在jvm启动参数里增加参数

-XX:NativeMemoryTracking=detail ,此参数能跟踪整个jvm的native层面的内存分配详情,部署上线后,我们去看看 native memory的分布。

使用jcmd命令查看一下Native内存的情况(jcmd 命令使用说明见 Native Memory Tracking)

从图上能明显的看出两部分有问题:

(1)线程数量4677个,committed 4806928KB 物理内存

(2)Internal部分 committed=2064420KB

线程数量多

我们知道每个线程的stack默认是1M,请注意并不是说线程一创建就会占用1M物理内存,实际上线程的stack默认1M是最大值,实际占用多少会随着stack的增长而增长。4677个线程就会占用 4677 * 1024 = 4789248KB,我们从图上能看到 Thread 部分总 committed=4829222KB,stack 的 committed=4806928KB,数据有点对不上,这说明JVM内部除了我们Java层面的stack之外,还有一些其他的辅助数据结构占用内存,我们用 jcmd 1 VM.native_memory detail命令详细看看thread stack部分的内存分配,可以看到reserved and committed 1028KB for Thread Stack,一个线程分配 1028K,确实比1M多一点。

总之是因为thread count太多了导致占用4.5G物理内存,我们要看看是什么线程这么多,用 jstack 1 将线程dump下来,结果如下:

为了找出每一种类线程的个数,需要做一定的分析工作,以下结果为正则表达式+手工处理得出:第一列为数量,第二列为线程代表名称(这个名字是我自己起的,意思是代表这一类线程,因为很多线程有相同的前缀后面是数字)

可以看到是 NettyClientPublicExecutor 线程太多了,其次 DubboServerHandler 线程也不少,我们需要处理这2类。

先看看NettyClientPublicExecutor线程,从代码里搜索发现这是rocketmq的netty client相关的线程,但是这个线程默认是cpu核数,除非我们自己指定,一般情况下我们很少去改它

既然一个 NettyRemotingClient 的线程是cpu核数,那么是不是因为 NettyRemotingClient 对象太多导致 NettyClientPublicExecutor 线程多呢?用 jmap -histo 1 | grep 'NettyRemotingClient'看看,结果如下:

只有21个 NettyRemotingClient 对象,但是 NettyClientPublicExecutor 线程有2589个,2589 / 21 = 123,这说明下面这行源码返回的cpu核数绝对不是我们容器的核数(容器规则4C16G)

private int clientCallbackExecutorThreads = Runtime.getRuntime().availableProcessors();

去看看容器宿主机的规格:128C,我们猜测是 Runtime.getRuntime().availableProcessors()拿到了宿主机的核数而不是容器本身的。

通过搜索我们发现 1.8.0_131 版本之前的jdk有bug(见谈JVM参数GC线程数ParallelGCThreads合理性设置-京东云开发者社区),无法识别容器环境。

查看我们使用的版本正是1.8.0_131,但是看起来仍然有问题。

Internal占用大

从 jcmd 1 VM.native_memory detail的结果看Internal部分内存通过mmap方式分配了32k,并且分配的内存起始地址有记录,但是通过malloc调用分配的2081504KB内存没有具体的地址,所以我们无法通过gdb工具去dump这部分内存,不太好排查。

从官网上看NMT无法跟踪非JVM代码分配的内存,也就是说 2081504KB 不是JVM 代码分配的,那么还有什么地方会分配呢?

operation项目比较特殊,它使用了opencv库,猜测是opencv库自己通过native方法分配了内存,从代码上看,使用了opencv实现人脸检测,可以看到使用的 opencv 相关的native 对象都没有主动进行销毁,但是这些类重写了finalize方法进行堆外内存释放,也就是说必须等gc的时候才有可能释放内存,先主动释放内存处理看看效果。

效果:

升级jdk版本后,由于jdk bug导致线程多的问题已解决,升级后线程数量在1k多,已符合预期。

opencv 对象主动释放后,内存变化从 90.7% -> 74.7% ,有明显的下降。但是单看灰度机器的内存仍然是缓慢持续增长,一直在74%左右,top命令也能看到res:0.013t,比我们配置的Xmx10G高出不少。


jcmd观察灰度机器,Thread数量已正常,Internal部分(255M)跟之前 2G 比也下降了不少,但是总committed=13263166KB(12.6G)跟容器内存占用 0.013T相比数据对不上。

再排查

由于jcmd观察到的committed=13263166KB(12.6G),与top命令观察到的0.013t(13.312G) 有差距,那容器内存持续缓慢增长到底是JVM之外的内存在长还是JVM内部内存在长?目前我们不得而知。

我们先使用 jcmd 1 VM.native_memory baseline 获取基线,等容器内存占用再增长一些后,我们再使用jcmd 1 VM.native_memory detail.diff 观察下这段时间 native memory的变化,这样大致可以判断出是jvm的native memory增长导致容器内存增长还是其他的。

2024-06-24 发现容器内存涨了接近1G,jcmd 1 VM.native_memory detail.diff发现JVM native memory上涨了227917KB=222MB,其中Thread上涨了140MB

JVM native memory增长比容器内存增长少很多,这说明可能存在其他的堆外内存泄漏。

用 pmap -x 1 | sort -n -k 3 -r 看一下进程的内存映射,结果如下,RSS=15414964KB

从网上能搜到的java 堆外内存泄漏大多是64M问题,但是我们这个并不是,从pmap结果看并没有很多64M内存分配。

持续跟踪了2天,通过pmap分配的地址和jvm native memory地址进行对比能确认就是因为堆外内存申请导致内存增长,期间多次使用pmap保存结果进行对比能发现有一定规律,容器内存增长一些后,通过两次的pmap结果对比能发现大部分是因为18~20M的内存块分配导致,用gdb dump此部分内存后strings命令看不出什么东西,都是乱码,排查就此陷入僵局。

等后面有时间了用gperftools再次跟踪下此问题。

相关推荐

探索Java项目中日志系统最佳实践:从入门到精通

探索Java项目中日志系统最佳实践:从入门到精通在现代软件开发中,日志系统如同一位默默无闻却至关重要的管家,它记录了程序运行中的各种事件,为我们排查问题、监控性能和优化系统提供了宝贵的依据。在Java...

用了这么多年的java日志框架,你真的弄懂了吗?

在项目开发过程中,有一个必不可少的环节就是记录日志,相信只要是个程序员都用过,可是咱们自问下,用了这么多年的日志框架,你确定自己真弄懂了日志框架的来龙去脉嘛?下面笔者就详细聊聊java中常用日志框架的...

物理老师教你学Java语言(中篇)(物理专业学编程)

第四章物质的基本结构——类与对象...

一文搞定!Spring Boot3 定时任务操作全攻略

各位互联网大厂的后端开发小伙伴们,在使用SpringBoot3开发项目时,你是否遇到过定时任务实现的难题呢?比如任务调度时间不准确,代码报错却找不到方向,是不是特别头疼?如今,随着互联网业务规模...

你还不懂java的日志系统吗 ?(java的日志类)

一、背景在java的开发中,使用最多也绕不过去的一个话题就是日志,在程序中除了业务代码外,使用最多的就是打印日志。经常听到的这样一句话就是“打个日志调试下”,没错在日常的开发、调试过程中打印日志是常干...

谈谈枚举的新用法--java(java枚举的作用与好处)

问题的由来前段时间改游戏buff功能,干了一件愚蠢的事情,那就是把枚举和运算集合在一起,然后运行一段时间后buff就出现各种问题,我当时懵逼了!事情是这样的,做过游戏的都知道,buff,需要分类型,且...

你还不懂java的日志系统吗(javaw 日志)

一、背景在java的开发中,使用最多也绕不过去的一个话题就是日志,在程序中除了业务代码外,使用最多的就是打印日志。经常听到的这样一句话就是“打个日志调试下”,没错在日常的开发、调试过程中打印日志是常干...

Java 8之后的那些新特性(三):Java System Logger

去年12月份log4j日志框架的一个漏洞,给Java整个行业造成了非常大的影响。这个事情也顺带把log4j这个日志框架推到了争议的最前线。在Java领域,log4j可能相对比较流行。而在log4j之外...

Java开发中的日志管理:让程序“开口说话”

Java开发中的日志管理:让程序“开口说话”日志是程序员的朋友,也是程序的“嘴巴”。它能让程序在运行过程中“开口说话”,告诉我们它的状态、行为以及遇到的问题。在Java开发中,良好的日志管理不仅能帮助...

吊打面试官(十二)--Java语言中ArrayList类一文全掌握

导读...

OS X 效率启动器 Alfred 详解与使用技巧

问:为什么要在Mac上使用效率启动器类应用?答:在非特殊专业用户的环境下,(每天)用户一般可以在系统中进行上百次操作,可以是点击,也可以是拖拽,但这些只是过程,而我们的真正目的是想获得结果,也就是...

Java中 高级的异常处理(java中异常处理的两种方式)

介绍异常处理是软件开发的一个关键方面,尤其是在Java中,这种语言以其稳健性和平台独立性而闻名。正确的异常处理不仅可以防止应用程序崩溃,还有助于调试并向用户提供有意义的反馈。...

【性能调优】全方位教你定位慢SQL,方法介绍下!

1.使用数据库自带工具...

全面了解mysql锁机制(InnoDB)与问题排查

MySQL/InnoDB的加锁,一直是一个常见的话题。例如,数据库如果有高并发请求,如何保证数据完整性?产生死锁问题如何排查并解决?下面是不同锁等级的区别表级锁:开销小,加锁快;不会出现死锁;锁定粒度...

看懂这篇文章,你就懂了数据库死锁产生的场景和解决方法

一、什么是死锁加锁(Locking)是数据库在并发访问时保证数据一致性和完整性的主要机制。任何事务都需要获得相应对象上的锁才能访问数据,读取数据的事务通常只需要获得读锁(共享锁),修改数据的事务需要获...