标签：Node 问题 node apiserver Kubernetes NotReady kubelet 日志 kube
公众号首发：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 ！匪夷所思：
感觉无法理解，于是又开始瞎想了，难道是 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语言资料的使用方法
标签：Node,问题,node,apiserver,Kubernetes,NotReady,kubelet,日志,kube 来源： https://www.cnblogs.com/lijiaocn/p/11178571.html
本站声明： 1. iCode9 技术分享网（下文简称本站）提供的所有内容，仅供技术学习、探讨和分享； 2. 关于本站的所有留言、评论、转载及引用，纯属内容发起人的个人观点，与本站观点和立场无关； 3. 关于本站的所有言论和文字，纯属内容发起人的个人观点，与本站观点和立场无关； 4. 本站文章均是网友提供，不完全保证技术分享内容的完整性、准确性、时效性、风险性和版权归属；如您发现该文章侵犯了您的权益，可联系我们第一时间进行删除； 5. 本站为非盈利性的个人网站，所有内容不会用来进行牟利，也不会利用任何形式的广告来间接获益，纯粹是为了广大技术爱好者提供技术内容和技术思想的分享性交流网站。