JVM 调优案例分析

JVM 调优案例分析

一、脚本引擎导致metaspace fullgc及内存溢出

现象：系统日常运行正常突然发生fullgc甚至内存溢出，重启后恢复正常但是过了几天又会突然发生频繁fullgc触发告警，告警信息如下：

首先发生fullgc，我们需要定位fullgc发生在jvm哪个区域？我们可以通过cat也可以通过gc日志查询发生的区域，目前有两种方式可以快速定位到gc区域：

1、Cat的Problem中可以直接查询error的详细信息（时间比较久了找不到对应的cat截图了）

2、通过gclog查询（大部分系统没有添加gc日志打印），常见配置如下

# 必备
-XX:+PrintGCDetails
-XX:+PrintGCDateStamps
-XX:+PrintTenuringDistribution
-XX:+PrintHeapAtGC
-XX:+PrintReferenceGC
-XX:+PrintGCApplicationStoppedTime
  
# 可选
-XX:+PrintSafepointStatistics
-XX:PrintSafepointStatisticsCount=1
  
# GC日志输出的文件路径
-Xloggc:/path/to/gc-%t.log
# 开启日志文件分割
-XX:+UseGCLogFileRotation
# 最多分割几个文件，超过之后从头文件开始写
-XX:NumberOfGCLogFiles=14
# 每个文件上限大小，超过就触发分割
-XX:GCLogFileSize=100M

通过以上分析可以看出fullgc发生再metaspace区，按照以往的经验，Metaspace在系统稳定运行一段时间后占用空间应该比较稳定才对。我们知道Metaspace主要存储类的元数据，比如我们加载了一个类，出现频繁fullgc的时候说明在不断的加载类，194621k->165280k发现也卸载了不少类，说明在频繁地生成大量”一次性“的类，于是分析dump文件：

具体步骤：
1.申请当前机器堡垒机权限
2.登录堡垒机
3.查看当前Java进程 ​​​ps -ef|grep java​​​ 4.将此机器下线(防止进行dump文件时对其他业务造成影响)
5.进行应用dump操作
sudo -u tuhu jmap -dump:format=b,file=/tmp/heapDump.hprof [pid]
6.修改dump文件权限 ​​sudo chmod 644 /tmp/heapDump.hprof​​ 7.对dump文件进行压缩操作(dump的文件很大 一般不压缩的话 很难下载的)
cd /tmp 进入到 /tmp 目录
​​tar -zcvf dump.tar.gz ./heapDump.hprof​​ 进行压缩，得到压缩文件 dump.tar.gz
8.在文件视图里面 下载dump文件
9.下载到本地解压: ​​tar -xzvf dump.tar.gz​​ //解压tar.gz

通过visualvm分析（mat没有发现问题）发现频繁创建了很多Script类，看reference是Lhs类，于是分析代码Lhs的compile方法：

/**
 * 使用aviator编译原始表达式
 */
public void compile() {
    RuleAssert.requireNotEmptyWhenCompiling(expression,
            RuleErrorEnum.RULE_COMPILE_INVALID_EXPRESSION);
    compiledExpression = AviatorEvaluator.compile(this.expression);
}

经过查询aviator官网文档分析发现确实存在内存溢出的问题，在编译表达式的时候每次都产生新的匿名类，这些类会占用 JVM 方法区(Perm 或者 metaspace）

解决方案：问题修复比较简单编译的时候使用缓存模式，如：AviatorEvaluator.compile(this.expression, true)，重新发布后metaspace稳定

二、kafka消费不均衡导致cpu负载高

现象：广告投放服务突然出现很多cpu负载过高告警，尤其是在发布的时候告警频繁，告警信息如下：

出现负载过高首先我们要明白什么场景下回导致cpu负载过高？才能快速定位到问题原因，个人总结cpu占用高主要有以下几点：

1、存在线程无限循环的占用cpu

2、Young GC频繁导致CPU占用率飙升

3、创建了大量线程的应用程序导致cpu飙升

4、存在密集型计算线程

这里推荐一个比较好用的工具 arthas（阿尔萨斯），提供了很多命令如：thread，jvm，memory等，于是我们通过thread分析线程情况：

通过线程信息可以快速定位到是mkt_ta_track_topic.sub消费线程占用了大量的cpu资源，通过简单的分析定位到问题，主要因为两个问题：

1、ta埋点（消息量很大）测试目前是做了简单的判断打印日志，没有做其他业务逻辑并且使用了多线程消费，消费速度很快相当于空循环

2、mkt_ta_track_topic当时是申请了8个分区，目前只有5台机器意味着有部分机器可能消费多个分区，此时占用cpu更严重；另外服务发布的时候也会导致kafka分区重分配也会出现上面说的负载过高问题

解决方案：

1、调整线程池多线程消费为单线程消费（后面做业务正常处理再做对应的调整）

2、申请扩展机器添加3台服务，为什么添加机器不是调整分区？服务负载本来就很高，借此机会扩容，扩容之后资源利用率依然有75.97%

三：FullGC 停顿时间过长导致上游调用服务超时

背景：新接手了一个服务，上游反馈偶尔调用超时，和上游确认超时发生时间点和具体超时时间，（超时时间为 1000 ms）。

查看当时系统运行情况，发现正在发生 FullGC ，且停顿时间超过 1000 ms。

要对 FullGC 停顿时间太长调优，我们就得先知道影响 FullGc 停顿时间太长的原因有哪些，通常来说，有以下几种：

1. 堆内存过大
2. 使用了非低延迟的垃圾收集器（GC）
3. FGC 期间系统在做其他操作，如 swap 交换空间
4. 堆内存碎片化严重
5. 显示System.gc调用

经排查发现属于第二种情况，JDK 使用为 jdk8 ，默认垃圾收集器为 Parallel Scanenge 收集器，该收集器主打吞吐量，不关心停顿时间。想要低延迟，我们应该使用 CMS 收集器。CMS 是一款以获取最短回收停顿时间为目标的收集器。

解决方案：
使用 CMS：

-XX:+UseConcMarkSweepGC -XX:CMSInitiatingOccupancyFraction=80 -XX:+UseCMSInitiatingOccupancyOnly

---