前言
记录一次线上JVM堆外内存透露问题的排查过程与思路,其中夹带一些JVM内存分配机制以及罕用的JVM问题排查指令和工具分享,心愿对大家有所帮忙。
在整个排查过程中,我也走了不少弯路,然而在文章中我依然会把残缺的思路和想法写进去,当做一次经验教训,给前人参考,文章最初也总结了下内存透露问题疾速排查的几个准则。
本文的次要内容:
- 故障形容和排查过程
- 故障起因和解决方案剖析
- JVM堆内内存和堆外内存调配原理
- 罕用的过程内存透露排查指令和工具介绍和应用
文章撰写不易,请大家多多反对我的原创技术公众号:后端技术漫谈
故障形容
8月12日中午午休工夫,咱们商业服务收到告警,服务过程占用容器的物理内存(16G)超过了80%的阈值,并且还在一直回升。
监控零碎调出图表查看:
像是Java过程产生了内存透露,而咱们堆内存的限度是4G,这种大于4G快要吃满内存应该是JVM堆外内存透露。
确认了下过后服务过程的启动配置:
-Xms4g -Xmx4g -Xmn2g -Xss1024K -XX:PermSize=256m -XX:MaxPermSize=512m -XX:ParallelGCThreads=20 -XX:+UseConcMarkSweepGC -XX:+UseParNewGC -XX:+UseCMSCompactAtFullCollection -XX:CMSInitiatingOccupancyFraction=80
尽管当天没有上线新代码,然而当天上午咱们正在应用音讯队列推送历史数据的修复脚本,该工作会大量调用咱们服务其中的某一个接口,所以初步狐疑和该接口无关。
下图是该调用接口当天的访问量变动:
能够看到案发过后调用量相比失常状况(每分钟200+次)进步了很多(每分钟5000+次)。
咱们临时让脚本进行发送音讯,该接口调用量降落到每分钟200+次,容器内存不再以极高斜率回升,所有仿佛复原了失常。
接下来排查这个接口是不是产生了内存透露。
排查过程
首先咱们先回顾下Java过程的内存调配,不便咱们上面排查思路的论述。
以咱们线上应用的JDK1.8版本为例。JVM内存调配网上有许多总结,我就不再进行二次创作。
JVM内存区域的划分为两块:堆区和非堆区。
- 堆区:就是咱们熟知的新生代老年代。
- 非堆区:非堆区如图中所示,有元数据区和间接内存。
这里须要额定留神的是:永恒代(JDK8的原生去)寄存JVM运行时应用的类,永恒代的对象在full GC时进行垃圾收集。
温习完了JVM的内存调配,让咱们回到故障上来。
堆内存剖析
虽说一开始就根本确认与堆内存无关,因为泄露的内存占用超过了堆内存限度4G,然而咱们为了保险起见先看下堆内存有什么线索。
咱们察看了新生代和老年代内存占用曲线以及回收次数统计,和平常一样没有大问题,咱们接着在事故现场的容器上dump了一份JVM堆内存的日志。
堆内存Dump
堆内存快照dump命令:
jmap -dump:live,format=b,file=xxxx.hprof pid
画外音:你也能够应用jmap -histo:live pid间接查看堆内存存活的对象。
导出后,将Dump文件下载回本地,而后能够应用Eclipse的MAT(Memory Analyzer)或者JDK自带的JVisualVM关上日志文件。
应用MAT关上文件如图所示:
能够看到堆内存中,有一些nio无关的大对象,比方正在接管音讯队列音讯的nioChannel,还有nio.HeapByteBuffer,然而数量不多,不能作为判断的根据,先放着察看下。
下一步,我开始浏览该接口代码,接口外部次要逻辑是调用团体的WCS客户端,将数据库表中数据查表后写入WCS,没有其余额定逻辑
察觉没有什么非凡逻辑后,我开始狐疑WCS客户端封装是否存在内存透露,这样狐疑的理由是,WCS客户端底层是由SCF客户端封装的,作为RPC框架,其底层通信传输协定有可能会申请间接内存。
是不是我的代码登程了WCS客户端的Bug,导致一直地申请间接内存的调用,最终吃满内存。
我分割上了WCS的值班人,将咱们遇到的问题和他们形容了一下,他们回复咱们,会在他们本地执行下写入操作的压测,看看能不能复现咱们的问题。
既然期待他们的反馈还须要工夫,咱们就筹备先本人推敲下起因。
我将狐疑的眼光停留在了间接内存上,狐疑是因为接口调用量过大,客户端对nio使用不当,导致应用ByteBuffer申请过多的间接内存。
画外音:最终的后果证实,这一个先入为主的思路导致排查过程走了弯路。在问题的排查过程中,用正当的猜想来放大排查范畴是能够的,但最好先把每种可能性都列分明,在发现自己深刻某个可能性无果时,要及时回头认真扫视其余可能性。
沙箱环境复现
为了能还原过后的故障场景,我在沙箱环境申请了一台压测机器,来确保和线上环境统一。
首先咱们先模仿内存溢出的状况(大量调用接口):
咱们让脚本持续推送数据,调用咱们的接口,咱们继续察看内存占用。
当开始调用后,内存便开始持续增长,并且看起来没有被限制住(没有因为限度触发Full GC)。
接着咱们来模仿下平时失常调用量的状况(失常量调用接口):
咱们将该接口平时失常的调用量(比拟小,且每10分钟进行一次批量调用)切到该压测机器上,失去了下图这样的老生代内存和物理内存趋势:
问题来了:为何内存会一直往上走吃满内存呢?
过后猜想是因为JVM过程并没有对于间接内存大小进行限度(-XX:MaxDirectMemorySize),所以堆外内存一直上涨,并不会触发FullGC操作。
上图可能得出两个论断:
- 在内存泄露的接口调用量很大的时候,如果恰好堆内老生代等其余状况始终不满足FullGC条件,就始终不会FullGC,间接内存一路上涨。
- 而在平时低调用量的状况下, 内存透露的比较慢,FullGC总会到来,回收掉泄露的那局部,这也是平时没有出问题,失常运行了很久的起因。
因为下面提到,咱们过程的启动参数中并没有限度间接内存,于是咱们将-XX:MaxDirectMemorySize配置加上,再次在沙箱环境进行了测验。
后果发现,过程占用的物理内存仍然会一直上涨,超出了咱们设置的限度,“看上去”配置仿佛没起作用。
这让我很讶异,难道JVM对内存的限度呈现了问题?
到了这里,可能看出我排查过程中思路执着于间接内存的泄露,一去不复返了。
画外音:咱们应该置信JVM对内存的把握,如果发现参数生效,多从本人身上找起因,看看是不是本人应用参数有误。
间接内存剖析
为了更进一步的考察分明间接内存里有什么,我开始对间接内存下手。因为间接内存并不能像堆内存一样,很容易的看出所有占用的对象,咱们须要一些命令来对间接内存进行排查,我有用了几种方法,来查看间接内存里到底呈现了什么问题。
查看过程内存信息 pmap
pmap - report memory map of a process(查看过程的内存映像信息)
pmap命令用于报告过程的内存映射关系,是Linux调试及运维一个很好的工具。
pmap -x pid 如果须要排序 | sort -n -k3**
执行后我失去了上面的输入,删减输入如下:
..00007fa2d4000000 8660 8660 8660 rw--- [ anon ]00007fa65f12a000 8664 8664 8664 rw--- [ anon ]00007fa610000000 9840 9832 9832 rw--- [ anon ]00007fa5f75ff000 10244 10244 10244 rw--- [ anon ]00007fa6005fe000 59400 10276 10276 rw--- [ anon ]00007fa3f8000000 10468 10468 10468 rw--- [ anon ]00007fa60c000000 10480 10480 10480 rw--- [ anon ]00007fa614000000 10724 10696 10696 rw--- [ anon ]00007fa6e1c59000 13048 11228 0 r-x-- libjvm.so00007fa604000000 12140 12016 12016 rw--- [ anon ]00007fa654000000 13316 13096 13096 rw--- [ anon ]00007fa618000000 16888 16748 16748 rw--- [ anon ]00007fa624000000 37504 18756 18756 rw--- [ anon ]00007fa62c000000 53220 22368 22368 rw--- [ anon ]00007fa630000000 25128 23648 23648 rw--- [ anon ]00007fa63c000000 28044 24300 24300 rw--- [ anon ]00007fa61c000000 42376 27348 27348 rw--- [ anon ]00007fa628000000 29692 27388 27388 rw--- [ anon ]00007fa640000000 28016 28016 28016 rw--- [ anon ]00007fa620000000 28228 28216 28216 rw--- [ anon ]00007fa634000000 36096 30024 30024 rw--- [ anon ]00007fa638000000 65516 40128 40128 rw--- [ anon ]00007fa478000000 46280 46240 46240 rw--- [ anon ]0000000000f7e000 47980 47856 47856 rw--- [ anon ]00007fa67ccf0000 52288 51264 51264 rw--- [ anon ]00007fa6dc000000 65512 63264 63264 rw--- [ anon ]00007fa6cd000000 71296 68916 68916 rwx-- [ anon ]00000006c0000000 4359360 2735484 2735484 rw--- [ anon ]
能够看出,最上面一行是堆内存的映射,占用4G,其余下面有十分多小的内存占用,不过通过这些信息咱们仍然看不出问题。
堆外内存跟踪 NativeMemoryTracking
Native Memory Tracking (NMT) 是Hotspot VM用来剖析VM外部内存应用状况的一个性能。咱们能够利用jcmd(jdk自带)这个工具来拜访NMT的数据。
NMT必须先通过VM启动参数中关上,不过要留神的是,关上NMT会带来5%-10%的性能损耗。
-XX:NativeMemoryTracking=[off | summary | detail]# off: 默认敞开# summary: 只统计各个分类的内存应用状况.# detail: Collect memory usage by individual call sites.
而后运行过程,能够应用上面的命令查看间接内存:
jcmd <pid> VM.native_memory [summary | detail | baseline | summary.diff | detail.diff | shutdown] [scale= KB | MB | GB] # summary: 分类内存应用状况.# detail: 具体内存应用状况,除了summary信息之外还蕴含了虚拟内存应用状况。# baseline: 创立内存应用快照,不便和前面做比照# summary.diff: 和上一次baseline的summary比照# detail.diff: 和上一次baseline的detail比照# shutdown: 敞开NMT
咱们应用:
jcmd pid VM.native_memory detail scale=MB > temp.txt
失去如图后果:
上图中给咱们的信息,都不能很显著的看出问题,至多我过后仍然不能通过这几次信息看出问题。
排查仿佛陷入了僵局。
山重水复疑无路
在排查陷入停滞的时候,咱们失去了来自WCS和SCF方面的回复,两方都确定了他们的封装没有内存透露的存在,WCS方面没有应用间接内存,而SCF尽管作为底层RPC协定,然而也不会遗留这么显著的内存bug,否则应该线上有很多反馈。
查看JVM内存信息 jmap
此时,找不到问题的我再次新开了一个沙箱容器,运行服务过程,而后运行jmap命令,看一看JVM内存的理论配置:
jmap -heap pid
失去后果:
Attaching to process ID 1474, please wait...Debugger attached successfully.Server compiler detected.JVM version is 25.66-b17using parallel threads in the new generation.using thread-local object allocation.Concurrent Mark-Sweep GCHeap Configuration: MinHeapFreeRatio = 40 MaxHeapFreeRatio = 70 MaxHeapSize = 4294967296 (4096.0MB) NewSize = 2147483648 (2048.0MB) MaxNewSize = 2147483648 (2048.0MB) OldSize = 2147483648 (2048.0MB) NewRatio = 2 SurvivorRatio = 8 MetaspaceSize = 21807104 (20.796875MB) CompressedClassSpaceSize = 1073741824 (1024.0MB) MaxMetaspaceSize = 17592186044415 MB G1HeapRegionSize = 0 (0.0MB)Heap Usage:New Generation (Eden + 1 Survivor Space): capacity = 1932787712 (1843.25MB) used = 1698208480 (1619.5378112792969MB) free = 234579232 (223.71218872070312MB) 87.86316621615607% usedEden Space: capacity = 1718091776 (1638.5MB) used = 1690833680 (1612.504653930664MB) free = 27258096 (25.995346069335938MB) 98.41346682518548% usedFrom Space: capacity = 214695936 (204.75MB) used = 7374800 (7.0331573486328125MB) free = 207321136 (197.7168426513672MB) 3.4349974840697497% usedTo Space: capacity = 214695936 (204.75MB) used = 0 (0.0MB) free = 214695936 (204.75MB) 0.0% usedconcurrent mark-sweep generation: capacity = 2147483648 (2048.0MB) used = 322602776 (307.6579818725586MB) free = 1824880872 (1740.3420181274414MB) 15.022362396121025% used29425 interned Strings occupying 3202824 bytes
输入的信息中,看得出老年代和新生代都蛮失常的,元空间也只占用了20M,间接内存看起来也是2g...
嗯?为什么MaxMetaspaceSize = 17592186044415 MB
?看起来就和没限度一样。
再认真看看咱们的启动参数:
-Xms4g -Xmx4g -Xmn2g -Xss1024K -XX:PermSize=256m -XX:MaxPermSize=512m -XX:ParallelGCThreads=20 -XX:+UseConcMarkSweepGC -XX:+UseParNewGC -XX:+UseCMSCompactAtFullCollection -XX:CMSInitiatingOccupancyFraction=80
配置的是-XX:PermSize=256m -XX:MaxPermSize=512m
,也就是永恒代的内存空间。而1.8后,Hotspot虚拟机曾经移除了永恒代,应用了元空间代替。 因为咱们线上应用的是JDK1.8,所以咱们对于元空间的最大容量基本就没有做限度,-XX:PermSize=256m -XX:MaxPermSize=512m
这两个参数对于1.8就是过期的参数。
上面的图形容了从1.7到1.8,永恒代的变更:
那会不会是元空间内存泄露了呢?
我抉择了在本地进行测试,不便更改参数,也方便使用JVisualVM工具直观的看出内存变动。
应用JVisualVM察看过程运行
首先限制住元空间,应用参数-XX:MetaspaceSize=64m -XX:MaxMetaspaceSize=128m
,而后在本地循环调用出问题的接口。
失去如图:
能够看出,在元空间耗尽时,零碎登程了Full GC,元空间内存失去回收,并且卸载了很多类。
而后咱们将元空间限度去掉,也就是应用之前出问题的参数:
-Xms4g -Xmx4g -Xmn2g -Xss1024K -XX:ParallelGCThreads=20 -XX:+UseConcMarkSweepGC -XX:+UseParNewGC -XX:+UseCMSCompactAtFullCollection -XX:CMSInitiatingOccupancyFraction=80 -XX:MaxDirectMemorySize=2g -XX:+UnlockDiagnosticVMOptions
失去如图:
能够看出,元空间在一直上涨,并且已装入的类随着调用量的减少也在一直上涨,出现正相干趋势。
柳暗花明又一村
问题一下子清朗了起来,随着每次接口的调用,极有可能是某个类都在一直的被创立,占用了元空间的内存。
察看JVM类加载状况 -verbose
在调试程序时,有时须要查看程序加载的类、内存回收状况、调用的本地接口等。这时候就须要-verbose命令。在myeclipse能够通过右键设置(如下),也能够在命令行输出java -verbose来查看。
-verbose:class 查看类加载状况-verbose:gc 查看虚拟机中内存回收状况-verbose:jni 查看本地办法调用的状况
咱们在本地环境,增加启动参数-verbose:class
循环调用接口。
能够看到生成了有数com.alibaba.fastjson.serializer.ASMSerializer_1_WlkCustomerDto
:
[Loaded com.alibaba.fastjson.serializer.ASMSerializer_1_WlkCustomerDto from file:/C:/Users/yangzhendong01/.m2/repository/com/alibaba/fastjson/1.2.71/fastjson-1.2.71.jar][Loaded com.alibaba.fastjson.serializer.ASMSerializer_1_WlkCustomerDto from file:/C:/Users/yangzhendong01/.m2/repository/com/alibaba/fastjson/1.2.71/fastjson-1.2.71.jar][Loaded com.alibaba.fastjson.serializer.ASMSerializer_1_WlkCustomerDto from file:/C:/Users/yangzhendong01/.m2/repository/com/alibaba/fastjson/1.2.71/fastjson-1.2.71.jar][Loaded com.alibaba.fastjson.serializer.ASMSerializer_1_WlkCustomerDto from file:/C:/Users/yangzhendong01/.m2/repository/com/alibaba/fastjson/1.2.71/fastjson-1.2.71.jar][Loaded com.alibaba.fastjson.serializer.ASMSerializer_1_WlkCustomerDto from file:/C:/Users/yangzhendong01/.m2/repository/com/alibaba/fastjson/1.2.71/fastjson-1.2.71.jar][Loaded com.alibaba.fastjson.serializer.ASMSerializer_1_WlkCustomerDto from file:/C:/Users/yangzhendong01/.m2/repository/com/alibaba/fastjson/1.2.71/fastjson-1.2.71.jar]
当调用了很屡次,积攒了肯定的类时,咱们手动执行Full GC,进行类加载器的回收,咱们发现大量的fastjson相干类被回收。
如果在回收前,应用jmap查看类加载状况,同样也能够发现大量的fastjson相干类:
jmap -clstats 7984
这下有了方向,这次认真排查代码,查看代码逻辑里哪里用到了fastjson,发现了如下代码:
/** * 返回Json字符串.驼峰转_ * @param bean 实体类. */public static String buildData(Object bean) { try { SerializeConfig CONFIG = new SerializeConfig(); CONFIG.propertyNamingStrategy = PropertyNamingStrategy.SnakeCase; return jsonString = JSON.toJSONString(bean, CONFIG); } catch (Exception e) { return null; }}
问题根因
咱们在调用wcs前将驼峰字段的实体类序列化成下划线字段,**这须要应用fastjson的SerializeConfig,而咱们在静态方法中对其进行了实例化。SerializeConfig创立时默认会创立一个ASM代理类用来实现对指标对象的序列化。也就是下面被频繁创立的类com.alibaba.fastjson.serializer.ASMSerializer_1_WlkCustomerDto
,如果咱们复用SerializeConfig,fastjson会去寻找曾经创立的代理类,从而复用。然而如果new SerializeConfig(),则找不到原来生成的代理类,就会始终去生成新的WlkCustomerDto代理类。
上面两张图时问题定位的源码:
咱们将SerializeConfig作为类的动态变量,问题失去了解决。
private static final SerializeConfig CONFIG = new SerializeConfig();static { CONFIG.propertyNamingStrategy = PropertyNamingStrategy.SnakeCase;}
fastjson SerializeConfig 做了什么
SerializeConfig介绍:
SerializeConfig的次要性能是配置并记录每种Java类型对应的序列化类(ObjectSerializer接口的实现类),比方Boolean.class应用BooleanCodec(看命名就晓得该类将序列化和反序列化实现写到一起了)作为序列化实现类,float[].class应用FloatArraySerializer作为序列化实现类。这些序列化实现类,有的是FastJSON中默认实现的(比方Java根本类),有的是通过ASM框架生成的(比方用户自定义类),有的甚至是用户自定义的序列化类(比方Date类型框架默认实现是转为毫秒,利用须要转为秒)。当然,这就波及到是应用ASM生成序列化类还是应用JavaBean的序列化类类序列化的问题,这里判断依据就是是否Android环境(环境变量"java.vm.name"为"dalvik"或"lemur"就是Android环境),但判断不仅这里一处,后续还有更具体的判断。
实践上来说,每个SerializeConfig实例若序列化雷同的类,都会找到之前生成的该类的代理类,来进行序列化。们的服务在每次接口被调用时,都实例化一个ParseConfig对象来配置Fastjson反序列的设置,而未禁用ASM代理的状况下,因为每次调用ParseConfig都是一个新的实例,因而永远也查看不到曾经创立的代理类,所以Fastjson便一直的创立新的代理类,并加载到metaspace中,最终导致metaspace一直扩张,将机器的内存耗尽。
降级JDK1.8才会呈现问题
导致问题产生的起因还是值得器重。为什么在降级之前不会呈现这个问题?这就要剖析jdk1.8和1.7自带的hotspot虚拟机的差别了。
从jdk1.8开始,自带的hostspot虚拟机勾销了过来的永恒区,而新增了metaspace区,从性能上看,metaspace能够认为和永恒区相似,其最次要的功能也是寄存类元数据,但理论的机制则有较大的不同。首先,metaspace默认的最大值是整个机器的物理内存大小,所以metaspace一直扩张会导致java程序强占零碎可用内存,最终零碎没有可用的内存;而永恒区则有固定的默认大小,不会扩张到整个机器的可用内存。当调配的内存耗尽时,两者均会触发full gc,但不同的是永恒区在full gc时,以堆内存回收时相似的机制去回收永恒区中的类元数据(Class对象),只有是根援用无奈达到的对象就能够回收掉,而metaspace判断类元数据是否能够回收,是依据加载这些类元数据的Classloader是否能够回收来判断的,只有Classloader不能回收,通过其加载的类元数据就不会被回收。这也就解释了咱们这两个服务为什么在降级到1.8之后才呈现问题,因为在之前的jdk版本中,尽管每次调用fastjson都创立了很多代理类,在永恒区中加载类很多代理类的Class实例,但这些Class实例都是在办法调用是创立的,调用实现之后就不可达了,因而永恒区内存满了触发full gc时,都会被回收掉。
而应用1.8时,因为这些代理类都是通过主线程的Classloader加载的,这个Classloader在程序运行的过程中永远也不会被回收,因而通过其加载的这些代理类也永远不会被回收,这就导致metaspace一直扩张,最终耗尽机器的内存了。
这个问题并不局限于fastjson,只有是须要通过程序加载创立类的中央,就有可能呈现这种问题。尤其是在框架中,往往大量采纳相似ASM、javassist等工具进行字节码加强,而依据下面的剖析,在jdk1.8之前,因为大多数状况下动静加载的Class都可能在full gc时失去回收,因而不容易呈现问题,也因而很多框架、工具包并没有针对这个问题做一些解决,一旦降级到1.8之后,这些问题就可能会裸露进去。
总结
问题解决了,接下来复盘下整个排查问题的流程,整个流程裸露了我很多问题,最次要的就是对于JVM不同版本的内存调配还不够相熟,导致了对于老生代和元空间判断失误,走了很多弯路,在间接内存中排查了很久,节约了很多工夫。
其次,排查须要的一是认真,二是全面,,最好将所有可能性后行整顿好,不然很容易陷入本人设定好的排查范畴内,走进死胡同不进去。
最初,总结一下这次的问题带来的播种:
- JDK1.8开始,自带的hostspot虚拟机勾销了过来的永恒区,而新增了metaspace区,从性能上看,metaspace能够认为和永恒区相似,其最次要的功能也是寄存类元数据,但理论的机制则有较大的不同。
- 对于JVM外面的内存须要在启动时进行限度,包含咱们相熟的堆内存,也要包含间接内存和元生区,这是保障线上服务失常运行最初的兜底。
- 应用类库,请多留神代码的写法,尽量不要呈现显著的内存透露。
- 对于应用了ASM等字节码加强工具的类库,在应用他们时请多加小心(尤其是JDK1.8当前)。
文章撰写不易,请大家多多反对我的原创技术公众号:后端技术漫谈
参考
察看程序运行时类加载的过程
blog.csdn.net/tenderhearted/article/details/39642275
Metaspace整体介绍(永恒代被替换起因、元空间特点、元空间内存查看分析方法)
https://www.cnblogs.com/duanx...
java内存占用异样问题常见排查流程(含堆外内存异样)
https://my.oschina.net/haitao...
JVM源码剖析之堆外内存齐全解读
http://lovestblog.cn/blog/201...
JVM 类的卸载
https://www.cnblogs.com/caoxb...
fastjson在jdk1.8下面开启asm
https://github.com/alibaba/fa...
fastjson:PropertyNamingStrategy_cn
https://github.com/alibaba/fa...
警觉动静代理导致的Metaspace内存透露问题
https://blog.csdn.net/xyghehe...
关注我
我是一名后端开发工程师。次要关注后端开发,数据安全,爬虫,物联网,边缘计算等方向,欢送交换。
各大平台都能够找到我
- 微信公众号:后端技术漫谈
- Github:@qqxx6661
- CSDN:@蛮三刀把刀
- 知乎:@后端技术漫谈
- 简书:@蛮三刀把刀
- 掘金:@蛮三刀把刀
- 腾讯云+社区:@后端技术漫谈
原创文章次要内容
- 后端开发实战
- Java面试常识
- 设计模式/数据结构/算法题解
- 读书笔记/逸闻趣事/程序人生
集体公众号:后端技术漫谈
如果文章对你有帮忙,无妨点赞,珍藏起来~
本文由博客群发一文多发等经营工具平台 OpenWrite 公布