GC耗时高，原因竟是服务流量小？

简介

最近，我们系统配置了GC耗时的监控，但配置上之后，系统会偶尔出现GC耗时大于1s的报警，排查花了一些力气，故在这里分享下。

发现问题

我们系统分多个环境部署，出现GC长耗时的是俄罗斯环境，其它环境没有这个问题，这里比较奇怪的是，俄罗斯环境是流量最低的一个环境，而且大多数GC长耗时发生在深夜。

发现报警后，我立马查看了GC日志，如下： 

日志中出现了to-space exhausted，经过一番了解，出现这个是由于g1在做gc时，都是先复制存活对象，再回收原region，当没有空闲空间复制存活对象时，就会出现to-space exhausted，而这种GC场景代价是非常大的。

同时，在这个gc发生之前，还发现了一些如下的日志。

这里可以看到，系统在分配约30M+的大对象，难道是有代码频繁分配大对象导致的gc问题。

定位大对象产生位置

jdk在分配大对象时，会调用G1CollectedHeap::humongous_obj_allocate方法，而使用async-profiler可以很容易知道哪里调用了这个方法，如下：

# 开启收集
./profiler.sh start --all-user -e G1CollectedHeap::humongous_obj_allocate -f ./humongous.jfr jps

# 停止收集
./profiler.sh stop -f ./humongous.jfr jps
复制代码

将humongous.jfr文件用jmc打开，如下：

根据调用栈我发现，这是我们的一个定时任务，它会定时调用一个接口获取配置信息并缓存它，而这个接口返回的数据量达14M之多。

难道是这个接口导致的gc问题？但这个定时任务调用也不频繁呀，5分钟才调用一次，不至于让gc忙不过来吧！
另一个疑问是，这个定时任务在其它环境也会运行，而且其它环境的业务流量大得多，为什么其它环境没有问题？

至此，我也不确定是这个定时任务导致的问题，还是系统自身特点导致偶尔的高gc耗时。

由于我们有固定的上线日，于是我打算先优化产生大对象的代码，然后在上线前的期间试着优化一下jvm gc参数。

优化产生大对象的代码

我们使用的是httpclient调用接口，调用接口时，代码会先将接口返回数据读取成String，然后再使用jackson把String转成map对象，简化如下：

rsp = httpClient.execute(request);
String result = IOUtils.toString(rsp.getEntity().getContent());
Map resultMap = JSONUtil.getMapper().readValue(result, Map.class);
复制代码

要优化它也很简单，使用jackson的readValue有一个传入InputStream的重载方法，用它来读取json数据，而不是将其加载成一个大的String对象再读，如下&