zoukankan      html  css  js  c++  java
  • Kubernetes集群Node间歇性NotReady,查到最后竟然是这个原因

    公众号首发:https://mp.weixin.qq.com/s/aNt1uI1RWf73Y3Dd6gmnLg

     
    问题截图

    被这个问题困扰一段时间了,先后进行了各种假设,然后又一一推翻,最后找到的原因让人很意外。

    这里简单记录一下问题的排查过程,然后直接抛答案,如果想了解详细的调查过程、调查过程中的所思所想和走过的弯路,点击「阅读原文」。

    出现问题的集群规模不大,总共 200 多个 Node,最早是从 Kubernetes 的事件中发现这个问题的,同事反馈时不时地监听到 NodeNotReady 事件,但是登陆集群查看时 Node 的状态都是 Ready。

    一开始忙其它的事情没太在意,后来这种「幽灵式」的 NodeNotReady 越来越频繁,并且持续的时间越来越长,不但触发了报警系统,而且 Node 上的 Pod 也被漂移了,开始着手调查。

    线索非常少,检查 kube-controller-manager 的日志,只看到一条 NodeNotReady 的事件日志,在 kubelet 的日志里也翻不到有价值的信息。调整日志级别后,只从 kube-controller-manager 的日志里得知一个事实:

    Node 的状态长时间没有得到更新,超过 gracePeriod,被认定为 NotReady。

    关键是为什么会延迟?开始胡思乱想,是不是网络不好,会不会 etcd 状态不对,要么是 docker 又 hang 了,还是 Go 的定时器有问题?乱想一气,乱查一通,没啥结论,还是老老实实地捋代码吧。

    Kubelet 默认上报频率是 10s 一次,kube-controller-manager 的 gracePeriod 默认是 40s,调整这两个参数只能延缓、掩盖问题,不能解决问题,如果你遇到同样的问题,不要在这些参数上耽误功夫了。

    Kubelet 的版本是 1.9.11,这个版本的 kubelet 在向 kbue-apiserver 提交状态信息时,不会打印日志。把添加了几行日志代码的 kubelet 推送到问题集群中,然后把 kube-apiserver 的日志级别调整为 2。这样就有足够的信息来界定问题区间了。

    「幽灵式」的 NodeNotReady 非常频繁,早晚不歇,一天好多次,这对调查过程非常有帮助!让我们有足够的案例用来分析,如果是个把月出现一次,那就抓瞎了。

    很快从新的案例中收集到足够的信息,把几处日志综合起来看,确定 kubelet 到 kube-apiserver 的通信没有问题,更新请求实时送达了 kube-apiserver,kube-apiserver 收到请求的时间与 kube-controller-manager 中记录的时间也完全匹配。

    问题在 kubelet 自身,上一次更新提交完成后,下一次更新很准时地在 10s 后启动(证明 go 的定时器工作正常),但是这次更新却莫名其妙地卡住了!

    Github 上有一个 issue,当 kubelet 的 heartBeatClient 建立的连接被对方中断后,kubelet 会 hang。看到这个 issue 时以为找到了答案,出于谨慎,添加了更多的调试日志,再次推送到问题集群,试图拿到更有力的证据。

    结果很意外,本来满心认为是 kubelet 通过 heartBeatClient 获取信息或者向 kube-apiserver 提交更新的时候发生了延迟。事实却是,一个 if 判断和两行赋值语句,就耗费了足足了 26s !匪夷所思:

     
    在代码中添加日志i

    感觉无法理解,于是又开始瞎想了,难道是 Go 的 gc 有问题?赋值语句耗时如此之长,实在没别的地方可想,翻了翻 Go 的内存模型,内存回收延迟都是毫秒级的,不可能是 gc 的问题。

    突然想到之前遇到一个 kubelet 进程被长时间挂起,最后被 kernel 杀死的场景,会不会是 node 的系统有问题给 kubelet 进程按下了暂停键?

    用 top 观察 kubelet 进程的状态,发现 wa 时间占比有时候会突然升高到 20%,然后用 iostat 发现根分区磁盘和数据盘的 util 都是 100%,处于过饱和状态,await 时间一度升到 20 多秒!

    然后用 pidstat 找到了正在频繁进行 IO 操作的 java 进程,通过向上找父进程的方法找到了它所在的容器。这个容器正在疯狂地吐日志,容器内进程不停地向标准输出写入日志,日志被收集到 container 目录中。

    但没有非常直接地证据证明就是这个原因,把运行有这批容器的 node 找出来与发生过 「幽灵」Not Ready 的 node 对比,发现恰好是对应的,所有发生了「幽灵」Not Ready 的 node 上都运行有正在疯狂吐日志的容器,没有运行该容器的 node 没有发生 Not Ready。

    联系相关方将写入到标准输出的日志停止,node 磁盘设备的 util 从 100% 降低到接近于 0,「幽灵」Not Ready 也不出现了。

    问题的根源其实还没有彻底挖出来,在用 pidstat 查看 io 情况的时候,发现容器狂刷日志时 dockerd 的写操作也很高,是不是两者相互作用才引发的问题?

    最近业务回暖,调用量增加日志随之增多,再联想到 docker ps 无响应的事情已经遇到了不止一次两次了,这里估计有戏,找机会再挖一挖。

    另外联系业务方调整日志输出也不治本,只不过都是内部系统,规模也不大,比较好协调罢了,需要找一个业务无感知的限制方法。

    调查这些问题真是耗时间,其它工作的进度又又又延后了......

    这里只是大概叙述一下,完整调查过程见「阅读原文」。

    上一篇:以Go的map是否并发安全为例,介绍最权威的Go语言资料的使用方法

    阅读原文

  • 相关阅读:
    MiniUi绑定mini-combobox下拉框
    ORA-01658:无法为表空间XXX中的段创建initial区
    ora-01033:oracle initialization or shutdown in progress 解决方法
    MVC示例
    NHibernate概念
    流程的python PDF高清版
    正则指引 pdf 高清版
    第三方库:logger,自定义日志封装模块
    python2.* 版本 与 3.* 版本中的区别
    Selenium2+python自动化-文件上传
  • 原文地址:https://www.cnblogs.com/lijiaocn/p/11178571.html
Copyright © 2011-2022 走看看