记一次令人窒息的线上fullgc调优

今天第二篇采坑了… …
现场因为处理太急促没有保留,而且是一旁协助,没有收集到所有信息实在是有些遗憾…只能靠记忆回想一些细节


情况是一台服务器一启动就开始full gc,短短1分钟可以有几十次的full gc.
主要几个配置参数为-Xmx2g -XX:NewRatio=3(CMS相关和其他的和这次无关不列了) 很简单的参数.
下意识dump了heap,结果并没什么特别明显的问题.
在想是不是内存不够,加到3g还是一样的问题.

那似乎只能看是不是业务代码有内存泄漏了.
jmap -histo:live看了下也是很常见的一些类(而且上面还做过heap分析).

开始陷入沉思,突然发现了一个诡异的点…jmap -heap old区很小… …多试了几次依旧是很小…
这不科学

jstat -gcoldjstat -gcnew一看….old的容量只有400M 而young的只有100多M 差不多是设置的newRatio的值
使用jcmd pid VM.flags一看,发现-XX:MaxNewSize被设置成了100多M… …就算是Xmx2g,实际使用才400多M,这点内存完全不能满足应用的正常使用.

之后添加了-Xms解决.(这点存疑 估计还修改了其他配置 见下面分析)

但其实还是有些问题遗留,默认的MaxNewSize为什么只有100多M…
简单的分析,MaxNewSize没有默认设置,那他的值来源于Xmx和NewRatio(Xmx / (newRatio + 1)),验证如下:
java -XX:NewRatio=3 -XX:+PrintFlagsFinal -version | grep New(不去连线上了..本地操作 windows下用findstr)

的确如此.

线上出问题的只有100多M,也就是Xmx参数可能被错误配置或者被覆盖了(模拟后面的Xmx覆盖了前面的)

最后的配置修改不是亲手做的一些项也无法确定了…


不过这次发现的问题也很明显
首先是监控,这台服务的gc日志没有被收集导致一开始没有历史记录(图1),有的话一眼就看出heap过小.
其次是思维定势了,遇到fgc想当然先去分析dump,浪费了时间.


总结一下这次使用的命令:
寻找java进程:
jps

查看gc情况(最后两个数字是间隔ms和打印次数):
jstat -gcutil|gcold|gcnew pid 1000 10

查看系统属性:
jcmd process_id VM.system_properties

JVM启动用的命令行:
jcmd process_id VM.command_line

显示调优标志:
jcmd process_id VM.flags [-all]

heap dump:
jmap -dump:format=b,file=test.bin pid

查看堆使用情况:
jmap -heap pid

查看存活对象:
jmap -histo:live pid

查看默认配置:
java -XX:+PrintFlagsFinal -version | grep HeapSize


参考资料:
https://docs.oracle.com/cd/E19900-01/819-4742/abeik/index.html
https://stackoverflow.com/questions/4667483/how-is-the-default-java-heap-size-determined
https://docs.oracle.com/javase/8/docs/technotes/guides/troubleshoot/tooldescr007.html