Background
kubernetes 是 master-slave 结构, master node 是集群的大脑, 当 master node 发生故障时整个集群都 "out of controll".master node 中最重要的当属 apiserver 组件, 它负责处理所有请求, 并持久化状态到 etcd. 一般我们会部署多份 apiserver 实现高可用. 官方建议在多个 apiserver 前面部署一个 LB 进行负载均衡, 当其中一台 apiserver 发生故障之后, LB 自动将流量切换到其他实例上面. 这样虽然简单, 但是也引入了额外的依赖, 如果 LB 发生故障将会导致全部 apiserver 不可用. 我们知道在 kubernetes 中 node 节点上 kubelet 与 apiserver 心跳超时后, controller-manager 会将该 node 状态置为 notReady, 随后驱逐其上的 pod, 使这些 pod 在其他地方重建. 所以当 LB 发生故障时, 集群中所有的 node 都会变为 notReady 状态, 进而导致大规模的 pod 驱逐.
故障发生
无独有偶, 这样的事情偏偏被我们碰到了, 接到线上大量 node not ready 的报警后, 立刻上线查看, 发现所有的 node kubelet 都报如下错误:
- E0415 17:03:11.351872 16624 kubelet_node_status.go:374] Error updating node status, will retry: error getting node "k8s-slave88": Get https://10.13.10.12:6443/api/v1/nodes/k8s-slave88?resourceVersion=0&timeout=5s: net/http: request canceled (Client.Timeout exceeded while awaiting headers)
- E0415 17:03:16.352108 16624 kubelet_node_status.go:374] Error updating node status, will retry: error getting node "k8s-slave88": Get https://10.13.10.12:6443/api/v1/nodes/k8s-slave88?timeout=5s: net/http: request canceled (Client.Timeout exceeded while awaiting headers)
- E0415 17:03:21.352335 16624 kubelet_node_status.go:374] Error updating node status, will retry: error getting node "k8s-slave88": Get https://10.13.10.12:6443/api/v1/nodes/k8s-slave88?timeout=5s: net/http: request canceled (Client.Timeout exceeded while awaiting headers)
- E0415 17:03:26.352548 16624 kubelet_node_status.go:374] Error updating node status, will retry: error getting node "k8s-slave88": Get https://10.13.10.12:6443/api/v1/nodes/k8s-slave88?timeout=5s: net/http: request canceled (Client.Timeout exceeded while awaiting headers)
- E0415 17:03:31.352790 16624 kubelet_node_status.go:374] Error updating node status, will retry: error getting node "k8s-slave88": Get https://10.13.10.12:6443/api/v1/nodes/k8s-slave88?timeout=5s: net/http: request canceled (Client.Timeout exceeded while awaiting headers)
- E0415 17:03:31.352810 16624 kubelet_node_status.go:366] Unable to update node status: update node status exceeds retry count
日志中显示的 10.13.10.12 是 LB 的地址. 通过这个日志判断是 kubelet 连接 apiserver 失败, 初步怀疑是网络故障, 手动 telnet 10.13.10.12 6443 后发现一切正常, 这就比较奇怪了, 明明网络通信正常, kubelet 为什么连不上 apiserver? 赶紧用 tcpdump 抓包分析了一下, 发现 kubelet 不断地给 apiservre 发送包却没有收到对端的 ACK, 登录 master 查看 apiserver 服务也一切正常. 后来同事发现重启 kubelet 就好了, 为了尽快解决问题只能把 kubelet 全部重启了, 后面再慢慢定位问题.
定位问题
集群恢复之后, 发现有故障通报 LB 发生了故障, 联系了相关同学发现时间点刚好相符, 怀疑是因为 LB 异常导致 kubelet 无法连接 apiserver. 经过沟通后发现: LB 会为其转发的每一个 connection 维护一些数据结构, 当新的一台 LB server 上线之后会均摊一部分原来的流量, 但是在其维护的数据结构中找不到该 connection 的记录就会认为这个请求非法, 直接 DROP 掉. 类似的事确实还发生不少, 在 kubernetes 的 isuse 里有不少这样的案例, 甚至需要公有云的的 LB 也会有这样的问题, 参见这个 kubernetes#41916, kubernetes#48638, kubernetes-incubator/kube-AWS#598. 大概明白原因之后, push LB 的同学改进的同时, kubelet 也应该做一些改进: 当 kubelet 连接 apiserver 超时之后, 应该 reset 掉连接, 进行重试. 简单做了一个测试, 使用 iptables 规则 drop 掉 kubelet 发出的流量来模拟网络异常:
首先确保 kubelet 与 apiserver 连接正常, 执行 netstat -antpl | grep 6443 可以看到 kubelet 与 apiserver 10.132.106.115:6443 连接正常
- [root@c4-jm-i1-k8stest03 ~]# netstat -antpl |grep kubelet
- tcp 0 0 127.0.0.1:10248 0.0.0.0:* LISTEN 23665/./kubelet
- tcp 0 0 10.162.1.26:63876 10.132.106.115:6443 ESTABLISHED 23665/./kubelet
- tcp6 0 0 :::4194 :::* LISTEN 23665/./kubelet
- tcp6 0 0 :::10250 :::* LISTEN 23665/./kubelet
- tcp6 0 0 :::10255 :::* LISTEN 23665/./kubelet
- tcp6 0 0 10.162.1.26:10250 10.132.1.30:61218 ESTABLISHED 23665/./kubelet
这时候执行 iptables -I OUTPUT -p tcp --sport 63876 -j DROP 将 kubelet 发出的包丢掉, 模拟网络故障, 此时可以看到 netstat 的输出中该连接的 Send-Q 正在逐步增加, 并且 kubelet 也打印出日志显示无法连接,
- [root@c4-jm-i1-k8stest03 ~]# netstat -antpl |grep kubelet
- tcp 0 0 127.0.0.1:10248 0.0.0.0:* LISTEN 23665/./kubelet
- tcp 0 928 10.162.1.26:63876 10.132.106.115:6443 ESTABLISHED 23665/./kubelet
连接被 hang 住了, 重启 kubelet 之后, 一切又恢复了. 这个现象和当时发生故障的情况一模一样: 连接异常导致 kubelet 心跳超时, 重启 kubelet 后会新建连接, 恢复正常心跳. 因为我们当前采用的 kubernetes 版本是 v1.10.2, 下载 master 分支的代码编译试了下, 也是有这个问题的, 感觉这个问题一直存在.
艰难的修复
接下来就是怎么修复这个问题了. 网上找了一下相关的 issue, 首先找到的是 kubernetes/client-go#374 https://github.com/kubernetes/client-go/issues/374 这个 issue, 上面描述的情况和我们碰到的很相似, 有人说是因为使用了 HTTP/2.0 协议 (以下简称 h2), 查找了一下 kubelet 的源码, 发现 kubelet 默认是使用 h2 协议, 具体的代码实现在 SetTransportDefaults 这个函数中 (点击阅读源码). 可以通过设置环境变量 DISABLE_HTTP2 来禁用 h2, 简单验证了一下: 显式设置该环境变量禁用 h2 后, 让连接使用 http1.1 确实没有这个问题了. 查阅文档发现这是 http1.1 与 http2.0 的差异: 在 http1.1 中, 默认采用 keep-alive 复用网络连接, 发起新的请求时, 如果当前有闲置的连接就会复用该连接, 如果没有则新建一个连接. 当 kubelet 连接异常时, 老的连接被占用, 一直 hang 在等待对端响应, kubelet 在下一次心跳周期, 因为没有可用连接就会新建一个, 只要新连接正常通信, 心跳包就可以正常发送. 在 h2 中, 为了提高网络性能, 一个主机只建立一个连接, 所有的请求都通过该连接进行, 默认情况下, 即使网络异常, 他还是重用这个连接, 直到操作系统将连接关闭, 而操作系统关闭僵尸连接的时间默认是十几分钟, 具体的时间可以调整系统参数 net.ipv4.tcp_retries2, net.ipv4.tcp_keepalive_time, net.ipv4.tcp_keepalive_probes, net.ipv4.tcp_keepalive_intvl.(在上面 issue 中的回复中, 确实有人这么做, 通过调整操作系统断开异常连接的时间实现快速恢复).h2 主动探测连接故障是通过发送 Ping frame 来实现, 这是一个优先级比较高并且 payload 很少的包, 网络正常时是可以快速返回, 该 frame 默认不会发送, 需要显式设置才会发送. 在一些 grpc 等要求可靠性比较高的通信框架中都实现了 Ping frame, 在 gRPC On HTTP/2: Engineering A Robust, High Performance Protocol 中谈到
The Less clean version is where the endpoint dies or hangs without informing the client. In this case, TCP might undergo retry for as long as 10 minutes before the connection is considered failed. Of course, failing to recognize that the connection is dead for 10 minutes is unacceptable. gRPC solves this problem using HTTP/2 semantics: when configured using KeepAlive, gRPC will periodically send HTTP/2 PING frames. These frames bypass flow control and are used to establish whether the connection is alive. If a PING response does not return within a timely fashion, gRPC will consider the connection failed, close the connection, and begin reconnecting (as described above).
可以看到 grpc 同样存在这样的问题, 为了快速识别故障连接并恢复采用了 Ping frame. 但是目前 kubernetes 所建立的连接中并没有实现 Ping frame, 导致了无法及时发现连接异常并自愈.
社区那个 issue 已经开了很长时间好像并没有解决的痕迹, 还得自己想办法. 我们知道一个 http.Client 本身其实只做了一些 http 协议的处理, 底层的通信是交给 Transport 来实现, Transport 决定如何根据一个 requst 返回对应的 reponse. 在 kubernetes client-go 中关于 Transporth2 的设置只有这一个函数
- // SetTransportDefaults applies the defaults from http.DefaultTransport
- // for the Proxy, Dial, and TLSHandshakeTimeout fields if unset
- func SetTransportDefaults(t *http.Transport) *http.Transport {
- t = SetOldTransportDefaults(t)
- // Allow clients to disable http2 if needed.
- if s := os.Getenv("DISABLE_HTTP2"); len(s)> 0 {
- klog.Infof("HTTP2 has been explicitly disabled")
- } else {
- if err := http2.ConfigureTransport(t); err != nil {
- klog.Warningf("Transport failed http2 configuration: %v", err)
- }
- }
- return t
- }
只是调用了 http2.ConfigureTransport 来设置 transport 支持 h2. 这一句代码似乎太过简单, 并没有任何 Ping frame 相关的处理逻辑. 查了下 golang 标准库中 Transport 与 Ping frame 相关的方法, 令人失望的是, 当前 golang 对于一个 tcp 连接的抽象 ClientConn 已经支持发送 Ping framle, 但是连接是交由连接池 clientConnPool 管理的, 该结构是个内部的私有结构体, 我们没法直接操作, 封装连接池的 Transport 也没有暴露任何的接口来实现设置连接池中的所有连接定期发送 Ping frame. 如果我们想实现这个功能就必须自定义一个 Transport 并实现一个连接池, 要实现一个稳定可靠的 Transport 似乎并不容易. 只能求助 golang 社区看有没有解决方案, 提交了一个 issue 后: x.NET/http2: make Transport occasionally send PING frames to server #31643 https://github.com/golang/go/issues/31643 , 很快就有人回复并提交了 PR, 查看了一下, 实现还是比较简单的, 于是基于这个 PR 实现了 clinet-go 的 Ping frame 的探测.
峰回路转
开发完毕准备上线的时候, 想趁这次修复升级一下 kubernetes 版本到 v1.10.11, 一般 patch release 是保证兼容的. 在测试 v1.10.11 的时候惊奇的发现, 即使不改任何代码, 这个问题也没办法复现了. 说明在 v1.10.2 中是有问题的, 在 v1.10.11 中恢复了, 接着在 master 中又引入了这个问题, 看来还得需要仔细阅读一下这部分代码了, 到底是发生了什么.
经过阅读代码, 发现这个逻辑曾经在 track/close kubelet->API connections on heartbeat failure #63492 这里修复过, 并且 backport 到 1.10.3 的代码中, 当连接异常时会会调用 closeAllConns 强制关闭掉所有的连接使其重建. 随后在 Restore Bootstrap in the background with fix to preserve kubeadm behavior #71174 这里又引入了 regression: 将 closeAllConns 置为 nil, 导致连接无法正常关闭. 明白了这个逻辑之后修改就简单了, 将 closeAllConns 再置为正确的值即可, 给官方提交了一个 pr: kubelet: fix fail to close kubelet->API connections on heartbeat failure #78016. 官方很乐意就接受了, 并 backport 到了 1.14 版本中. 至此这个就算完全修复了, 当然可以通过上文提到的给 h2 增加 Ping frame 的方式解决该问题, 这是这种方案可能比较复杂, 修复时间比较长.
来源: https://www.cnblogs.com/gaorong/p/10925480.html