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问题对我来讲可能比较陌生,暂时还没什么时间去研究,后面有时间研究了再进行记录。

Logo

K8S/Kubernetes社区为您提供最前沿的新闻资讯和知识内容

更多推荐