记一次生产环境频繁耗时GC导致的周期性响应缓慢问题

1.问题来源与背景

服务使用K8s集群部署，重要的服务采用多节点负载的形式搭建。出问题的节点持续运行时间将近半年。某一天的早上收到预警信息，说k8s某节点服务不可用，大家立马都紧张起来了。

2.问题查询与定位

2.1 日志中心查询

错误日志：

日志中显示7点多的时候 频繁出现访问超时的现象 。

耗时日志：

耗时日志中也显示7点多的时候出现了大量的响应时间过长的请求。

2.2 容器日志查询

上服务器查看某个节点的日志，发现有很多超时的请求出现。而这些出问题的节点 均为网关api-gateway节点。然后通过请求链路日志进行分析，发现问题大概率就出在网关节点上面。

3.问题排查

3.1 网络排查

step 1
在宿主机使用ping pod ip的方式，发现是正常的。然后执行docker容器中超时的那条curl请求，这里没有使用svc的ip，使用了pod的ip地址。curl 10.233.23.3:4000发现偶尔会出现超时的现象。经过多次尝试，触发其超时后，总结出规律：这个端口超时现象是呈周期性发生的。

step 2
周期性出现超时现象看起来并不像是网络问题，为了进一步排除网络问题，决定在pod中的docker容器内安装另一个web服务，我选择了安装一个nginx。
安装完nginx后，启动，暴露一个端口80。
同样在宿主机使用ping pod ip的方式，发现是正常的。然后开始执行curl命令。使用脚本多次执行curl 10.233.23.3:80命令后发现80端口是正常的，没有出现过一次超时现象。而同时curl 4000端口会发现，超时现象还是会周期性发生。

step 3
通过上述过程可以基本排除是k8s网络引起的超时现象，但是我们运行的这个网关节点已经半年多没有更新过代码了。为什么会突然出现这样的情况呢？

3.2 日志观察

本想观察网关的历史日志，但是网关节点的日志太庞大了，无法快速定位到想要排查的地方，而且在日志系统中也发现不了引发超时现象的原因。
这个时候刚好看到了网关服务节点下有一个gc日志可以查看。于是开始观察gc日志。
由于之前没有这方面的经验，所以只能临阵磨枪，去学习看gc日志。
我们使用的是CMS垃圾回收器，所以参考了CMS垃圾回收器详解这篇文章去学习看gc日志。

看完日志之后，特别欣喜，因为gc日志确实有问题：

从gc日志中，粗略观察出来有耗时特别长的gc，这个时间长达9s，而仔细观察gc的分步日志，会发现这个CMS gc是在执行年轻代gc的时候释放内存失败了，所以才触发了Full gc，而Full gc 是会STW的，刚好耗时又特别长，跟超时现象更加贴切的是，它两次长耗时gc的时间间隔刚好是之前观察出来的 周期性超时的时间间隔。于是问题就基本上可以定位为JVM的问题了。

4.总结

为什么一个java程序会在长时间运行时产生gc失败的问题呢？

#######jvm问题对我来讲可能比较陌生，暂时还没什么时间去研究，后面有时间研究了再进行记录。