前言

收到生产某服务多台机器报警，cpu飙到100%，系统无法正常提供服务。故开始排查问题。

分析

一、分析cpu过高的原因

tomcat进出把cpu占满了cpu。使用命令top top -H -p pid查到tomcat进程中相应的线程。将查到的线程号转成十六进制printf "%x\n" tid。然后使用命令jstack pid | tid -A 50查看线程快照。判断是因为频繁full gc引起的cpu飙高。

二、分析频繁full gc的原因

首先先查看了jvm的堆内存配置。整个堆内存约为5.5个G，其中青年代分了3个G，老年代分了2.5个G。

再使用命令jstat -gcutil pid 1000查看每秒钟内存各区域占比和gc情况。发现S0、Eden和老年代已经被占满，导致一直full gc，并且每次full gc之后内存都没有被释放掉。内存释放不掉，服务很容易就OOM了。

为了方便分析排查，立刻保存了线程快照和堆dump。命令：jstack -l pid > jstack.log、jmap -dump:format=b,file=temp.dump pid。保留完现场之后，先将几台问题机器重启，防止起OOM，保障服务的暂时可用。将dump下载到本地进行分析。

三、离线dump分析

使用jdk自带的VisualVM分析dump。但是由于dump文件有7G多，因此使用命令jvisualvm -J-Xms1024m -J-Xmx2048m打开。

发现OrderAndPrice对象有11万多个实例，感觉非常的可疑。OrderAndPrice是个聚合对象，OrderDetail、OrderPreprice等都是其的属性。OrderAndPrice保存了订单的详细信息，查库获得。查看OrderAndPrice的实例，发现它被一个HashMap引用，而这个Map中竟然有一百万多个项，占用了1G多的内存。

原来这个Map是Mybatis的一级缓存。当我们使用Mybatis进行数据库的操作时候，会创建一个SqlSession来进行一次数据库的会话，会话结束则关闭SqlSession对象。MyBatis一级缓存的生命周期和SqlSession一致。MyBatis一级缓存内部设计简单，只是一个没有容量限定的HashMap，在缓存的功能性上有所欠缺。所以才会出现有100多万个项的巨大Map。

查看线程快照，定位到了相关的代码。在代码中发现对于String的非空判断使用的是jdk中的Strings.isNullOrEmpty()方法。该方法不能判断空格这样的空字符串，导致全表扫描。修改代码，替换成common3中的StringUtils.isNotBlank()方法。修复代码之后，发布上线解决问题。

1
2
3

public static boolean isNullOrEmpty(@Nullable String string) {
    return string == null || string.length() == 0; // string.isEmpty() in Java 6
}

解决

1、配置Mybatis一级缓存范围。因为Mybatis一级缓存无法关闭，但是可以配置其缓存范围。减少缓存对象的数量和缓存时间。

1
2
3

<!-- SESSION，缓存会话内的所有sql语句结果 -->
<!-- STATEMENT，每次查询结束都会清掉一级缓存 -->
<setting name="localCacheScope" value="STATEMENT"/>

2、不要使用Strings.isNullOrEmpty()判断非空字符串。

3、加上慢查询的监控。

引用

https://tech.meituan.com/2018/01/19/mybatis-cache.html