某天突然收到线上应用的gc时间过长的告警,刚开始只有一台机器偶尔报一下,后续其他机器也纷纷告警,具体告警的阈值是应用10分钟内ygc的总时长达到了6.6s。
-XX:+PrintReferenceGC
参数,经过一段时间观察,应用重启后,观察了一段时间,发现gc日志中JNI Weak Reference处理时长变得越来越长。而且占用整个ygc时长的大部分。jdk.nashorn.internal.ir.IdenNode
通过引用链找到可疑的js脚本对应的String
,尝试了很多次发现都失败了。主要本身对jdk.nashorn
包下类不是很熟悉,再加上引用链都比较长,所以找了很久都没有找到这个类和脚本的应用关系。String
对象存在,String
底层采用char[]
来存储字符。所以直接找char[]
实例中内容为js脚本的,但是这里又遇到一个问题,看上面的dump文件图,会发现char[]
实例数当前内存有100w+,这里就抓住了部分js脚本长度比较长的一个特点。直接根据size正序排列,长度前10的字符串,就直接就找到了一个脚本,顺着引用链会轻易发现,js脚本的内容都是保存在Source$RawData
对象中的,如下图Classes
栏目,直接搜索Source$RawData
,可以看到有241个实例,如下图,这241个,然后找了出现频率比较高的几个js脚本,然后看了对应脚本的调用方式,发现其中一个脚本每次执行都是通过ScriptEngine.eval
这种方式来执行,就造成了``JNIHandleBlock```,不断增长的问题,最终导致ygc时,处理JNI Weak Reference的时间越来越长。eval
方法,换成Bindings的方式调用。-Xms4000m -Xmx4000m -XX:+UseConcMarkSweepGC -XX:CMSInitiatingOccupancyFraction=70 -XX:MaxDirectMemorySize=512m -XX:+UseCMSInitiatingOccupancyOnly -XX:SurvivorRatio=8 -XX:+ExplicitGCInvokesConcurrent -XX:MetaspaceSize=512m -XX:MaxMetaspaceSize=512m -XX:-OmitStackTraceInFastThrow -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:/var/www/logs/gc-%t.log -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=10m -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/var/www/logs -Djava.io.tmpdir=/var/www/tmp -Dio.netty.availableProcessors=4 -XX:ParallelGCThreads=4 -Dpinpoint.applicationName=crawler-worker.product-bank
这样,其中-Xms4000m
是初始化堆大小,-Xmx4000m
是最大堆大小,然后重启应用,重启后,就收到ygc频繁的告警,然后用jstat -gc pid 3000
看了下,发现了奇怪的地方(如下图)年轻代总容量才300多m(S0C+S1C+EC),而年老大总容量(OC)有3700多m,这种情况就直接导致了,直接分配对象空间的eden区域很容易就占满了,而直接触发ygc,而导致这个问题的原因呢,是忘记配置-Xmn1024m
参数导致,这个参数就是制定年轻代的大小,这里的大小配置成整个堆的1/4至1/2都是合理的,加上这个参数后,刚启动应用就ygc时间过长的问题就得到了解决。版权声明
作者:wycm
出处:https://blog.csdn.net/vwycm/article/details/88639105
您的支持是对博主最大的鼓励,感谢您的认真阅读。
本文版权归作者所有,欢迎转载,但未经作者同意必须保留此段声明,且在文章页面明显位置给出原文连接,否则保留追究法律责任的权利。