kubernetes升级后出现很多pod probe失败
背景
kubernetes集群版本从1.18升级到1.23后出现许多运行正常的pod,由于liveness probe失败导致重启,还有一些是readiness probe失败。
起初怀疑pod重启,不应该是kubernetes升级导致的,由于1.18和1.23版本的container hash算法没有修改,所以升级kubelet不会导致已经运行的container重新生成。后面排查到pod重启时间在kubernetes升级之后,不是升级那个时间。所以可以排除升级kubelet导致的重启。
通过对比新老版本的kubelet日志,发现1.23版本的kubelet的日志中有许多类似这样报错,基本每隔几分钟就有一条
|
|
排查过程
1 分析kubernetes源码
从日志报错的文件位置,排查到context deadline exceeded (Client.Timeout exceeded while awaiting headers)
是net/http
库里client报错。
搜索出现这种报错的原因:
连接已经建立,但是服务端响应慢
连接建立超时
golang net/http超时引发大量fin-wait2
同时大概看了net/http库中client和transport部分代码,于是怀疑是不是连接建立超时导致。
2 抓包进行重现
部署配置了readiness probe的nginx deployment。为什么要部署nginx?由于nginx有访问日志,同时有错误日志。这样就能看出来kubelet是否进行了probe。
|
|
同时在pod网络命名空间里进行抓包,等待probe失败出现
|
|
功夫不负有心人,终于抓到了probe失败的包
|
|
nginx访问日志
|
|
kubelet日志
|
|
2.1 现象分析
probe是每隔10秒执行一次,本来在15/Sep/2022:11:09:02
应该有访问日志,但是nginx中没有访问日志。同时kubelet日志说明15/Sep/2022:11:09:02
执行的probe失败。
第一个包kubelet发出syn
到nginx,第二个包nginx响应syn,ack
,然后第三个包直接进行rst
。经过1s后kubelet进行syn
重试,nginx再次响应syn,ack
,最后一个包还是响应rst
。
于是问题的突破关键点在于为什么kubelet对nginx响应syn,ack
包进行rst。怀疑是kubernetes版本差异导致的,或golang版本差异导致的(1.18的golang版本为1.13(我们使用1.16.5重新编译了解决goaway出现的5xx),1.23版本的golang版本为1.17)。
3 对比kubernetes源码和golang源码
对kubernetes 1.18.20和1.23.10进行版本比较,分析有关probe的修改,发现核心probe逻辑没有变化,排除了kubernetes版本导致的问题。
对golang 1.16.5和1.17.13版本进行比较,分析net库是否有修改,发现net库基本没有任何变化。
这时候我再去读了下golang的net库,思考是否是建立连接失败,代码里主动取消连接而发送rst连接呢?
由于代码太复杂没有看下去,去搜索一下golang rst连接
,发现使用net.TCPConn.SetLinger()
是能够发rst。
Forcefully Close TCP Connections in Golang
这时候已经排查了3天了,凭借直觉,隐隐感觉是方向错误。
如果kubernetes的bug,那么社区里应该有大量反馈,但是搜了一圈只有一些不知原因的issue,而且很久没有修复
如果是golang bug那么这么久了应该有issue,然而并没有相关issue,而且net库代码没有什么变化。
4 排查系统内核
排查conntrack表,是否因为端口重用且4元组一样,新的请求跟老的记录重合导致rst(这里是猜测内核机制是这样),且内核参数net.netfilter.nf_conntrack_tcp_timeout_time_wait = 120 net.ipv4.tcp_tw_reuse = 1
。即两分钟内端口重用导致新的连接跟timewait记录一样,查了发送probe失败前10分钟内数据包,没有重复的端口。
排查ipvs表,是否因为端口被ipvs监听了,rst包是ipvs发出的。
ipvs表中有大一些本地随机端口监听,而且抓包中probe失败的源端口36704
也在这里面。
|
|
4.1 现象分析
这些端口service的NodePort端口
|
|
查看apiserver配置的NodePort端口范围
|
|
查看本地local port range
|
|
5 原因分析
由于本地local port range的端口和NodePort端口范围重叠,导致kubelet作为客户端进行probe会使用已分配的NodePort端口。导致nginx响应syn、ack包
被ipvs rst掉(ipvs是这么想,我没有syn包,就有sync、ack
包,这个响应包不合法直接rst)。
5.1 为什么升级之后这个问题凸显?
kubelet作为客户端进行probe会使用已分配的NodePort端口概率大大上升?
排查TIMEWAIT连接,10.10.85.105
和10.23.77.129
是kubernetes升级之前一直存在, 发现169.254.20.10
是新增的连接
|
|
|
|
对lo进行抓包,发现有进程使用短链接一直请求169.254.20.10:8080
|
|
169.254.20.10:8080是node-local-dns监听的(使用daemonset部署且网络模式为host),但是客户端通过ss、lsof命令,一直抓不到。最后通过遍历所有本地进程进行strace,发现是node-local-dns自己访问自己
|
|
所以根因是因为node-local-dns持续不断的自己访问自己,导致本地端口快速被使用(滚动),最终导致更快的滚动到已经分配的Nodeport端口
5.2 为什么node-local-dns持续不断的自己访问自己?
在node-local-dns里有health配置,它会一直访问定义的169.254.20.10:8080
获得health响应时间,用于metric。node-local-dns的health与coredns的health不一样,coredns会访问/health
,node-local-dns访问是/
(直接返回404,这个health没有意义,由于node-local-dns 1.21.1使用的1.7版本的coredns代码,这个问题在1.8.1修复了)。
|
|
6 解决方案
修改系统的local port范围与NodePort范围不重叠,我这里是设置net.ipv4.ip_local_reserved_ports
为NodePort的端口范围。当然也可以直接修改net.ipv4.ip_local_port_range
与NodePort范围不重叠
7 总结
产生这个问题的直接原因:node-local-dns启用health且网络模式是host,持续不断的使用短连接自己访问自己的8080端口,导致本地端口滚动加快。增加kubelet使用已经分配的NodePort端口进行probe探测概率。
根本原因: 系统的local port范围与NodePort范围重叠,导致kubelet使用已分配的NodePort进行probe探测时候,连接建立不成功(建立连接时,pod响应任何包都会被rst)。
存在问题
- 系统的local port范围与NodePort范围重叠
- kubernetes升级变更与增加node-local-dns同一时刻操作
经验教训
- 最小化变更(类型最小化代码 commit),减少排查变更后产生的问题的复杂度,加快解决问题速度。
- 在搜不到issue时候,先排查环境问题,再排查软件bug。