kubernetes – 滚动发布引发调用方超时的新问题与定位

kubernetes集群的网络问题已经解决的差不多了,业务方也稳定的使用了一阵子了。

可惜最近两天,滚动发布又开始引发调用方超时了,这又是什么问题呢?

实际上,我们已经完美的实现了健康检查、优雅退出这些基本事项,也已经在线上平稳运行了好一阵子。

缩小范围

根据之前分析超时问题的经验,我首先通过单纯的扩容 or 单纯的缩容,明确是POD上线导致还是POD下线导致。

结果发现是POD下线导致的报错,也就是说流量可能被转给了下线中的POD。

然而这个问题我曾经已经解决过2次了,那2次的原因分别是:

  • kube-proxy ipvs模式的坑:ipvs本身有bug,转发规则在POD彻底删除前会令weight=0,此时会因为客户端源地址相同导致复用conntrack缓存关系,进而把流量再次送入到下线中的POD。(后来我们换了iptables就解决了)
  • kube-proxy规则同步慢:因K8S架构决定,当POD被标记terminating后,kubelet开始杀死POD和kube-proxy开始下线转发规则是同时进行的,因此如果kubelet先杀POD而Kube-proxy后下转发规则,则会导致流量被送入正在被杀死的POD。(后来我们在prestop中sleep 2秒来等待kube-proxy先下掉规则,问题得到解决)

如果上面2件事情你都做过了,还是报错,那么就是我这次遇到的第3个原因了。

初步怀疑

最近集群规模是变大了很多,100+node,2000+POD,因此iptables转发规则变多,导致了哪方面变慢了。

那么,此时有2个怀疑方向:

  • 因为规则多了,所以iptables-restore执行的时间太长了,之前给的sleep 2秒不够用了。
  • 因为集群node多了,所以etcd压力大了,同步到kube-proxy的延迟变高了。

为了观察这2个点,必须从k8s代码入手,看一下它们是否打印相关的时间点日志,以便来定位问题。

从K8S代码入手

具体看代码的过程我就不展开了,我分析了从deployment提交缩容变更之后的完整代码路径,得到如下的执行流程分析:

  1. 向apiserver提交deployment yaml进行缩容1次。
  2. deployment controller收到1次deployment变化event,向apiserver更新1次replicaset yaml。
  3. replicaset controller收到1次relicaset变化event,启动多个协程并发的向apiserver更新N个pod的status为terminating。
  4. endpoints controller收到N个pod变化event,对于每个pod event会根据内存反向索引反查pod属于哪个service,根据service label selector向apiserver筛选出pod list,同时再根据调用apiserver获取service name同名的endpoints对象,对比endpoints对象中现有pod ip list和本次筛选出的pod list是否有差异,没有则不会更新endpoints对象, 否则将最新pod ip list更新到endpoints对象的subsets字段,然后向apiserver提交endpoints对象。
  5. kube-proxy监听到endpoints对象变化,根据endpoints对象中记录的service name->pod ip list关系更新内存记录,并全量刷新iptables规则。
  6. kubelet监听到3)触发的pod更新event,则已经开始对变化POD进行退 出流程了,也就是先prestop hook,然后等待graceful terminating秒,之后强杀kill SIGKILL信号。

其实这里面的参与组件(进程)很多,包括:

  • apiserver:它封装了etcd的各类操作。
  • controller-manager:它实现了各种资源controller,比如replicaset、deployment、endpoints、service等等。
  • kube-proxy:它负责根据endpoints资源的变化,更新node上的iptables rules。
  • kubelet:它负责根据pod资源的变化,更新node上的docker container。

分析方法

通过代码,我找到了几个相关的日志,可以帮助我分析我的怀疑。

我能看到的几个重要信息是:

  • replicaset controller向apiserver并发更新N个POD的状态为terminating,一共花费了多久?
  • endpoints controller监听到上述POD的状态变化并更新endpoints,一共花费了多久?
  • endpoints更新事件,kube-proxy从apiserver同步到这个变化,一共花费了多久?
  • kube-proxy收到endpoints变化后,多久能完成iptables rules的刷新?

因此,我给kube-proxy、kubelet、controller-manager的启动参数分别配置了-v日志级别并重启,以便可以看到相关的日志。

在我打开日志的node上,实际观察了这些完整的路径:

replicaset几点删除了pod?

endpoints controller几点更新了endpoints?

kubelet几点开始POD退出流程?

kube-proxy几点同步到endpoints?

kube-proxy几点刷新完iptables规则?

然而发现好像也没有慢过2秒的。

iptables刷新规则虽然慢,但每次endpoints变化它会执行2次iptables-save和1次iptables-restore,也就200ms左右吧。

因为pod是并发更新的,因此endpoints controller虽然多次收到pod event,但是后面几次pod event其实去label selector筛选pod list已经没有diff了,因此也不会多次重复更新endpoints对象。

在实际日志中,我每次缩容时kube-proxy最差也就是收到2次endpoints更新事件,导致连续2次刷新iptables规则,也就花掉400ms,距离2秒还是很遥远的。

虽然做了很多分析,但是此时还是没有直观的证据来证明我的猜测。

再怀疑?

只能开始怀疑是不是自己运气不好,所在node同步是及时的,可能有其他node同步规则慢了?

实际上etcd压力并不大,很难怀疑etcd。

可是所有机器都开日志代价太高了,毕竟100+node,但是其他Node的嫌疑实在是无法忽略。

偷懒的我呢,就在网上搜索了一下关键字:kube-proxy endpoints latency

结果呢,有一个这样的博客让我觉得特别像是我的问题。

作者说它也把优雅退出做的很完美,不应该是低级错误。

因此,他在controller-manager的日志里看到这样一个东东:

I0412 22:59:59.914517 1 request.go:638] Throttling request took 2.489742918s, request: GET:https://10.3.0.1:443/api/v1/namespaces/[some namespace]/endpoints/[some endpoints]”

也就是说controller-manager调用apiserver是有整体限流的,目的是保护apiserver。

看了一下集群的controller-manager日志,的确存在这样的告警,而且等待时长非常严重:

Apr 20 19:10:15 10-19-143-152 hyperkube[223564]: I0420 19:10:15.752636 223564 request.go:530] Throttling request took 97.966322ms, request: GET:https://10.19.105.10:6443/apis/networking.k8s.io/v1?timeout=32s
Apr 20 19:10:15 10-19-143-152 hyperkube[223564]: I0420 19:10:15.802714 223564 request.go:530] Throttling request took 148.0144ms, request: GET:https://10.19.105.10:6443/apis/coordination.k8s.io/v1beta1?timeout=32s

抱着无脑试试的态度,调大了下面2个限流参数:

  • –kube-api-qps
  • –kube-api-burst

反复验证,问题得到解决。

当集群规模大了之后,controller-manager和apiserver之间的交互变得更加频繁了,因此默认值20已经早就不够用了。

至于为什么我所在的node的日志没有抓到endpoints同步慢的问题日志呢?难道其他node被哪方面限速了?

我理解apiserver向kube-proxy同步endpoints这个不应该受限qps吧?

总之这个我还没时间回头去详细看。

后续

因为是买的云上托管的K8S,对云厂商过度信任,也导致k8s基础组件的优化参数成为了盲区。

因此,我们需要关注一下K8S规模变大后的一些关键参数优化,腾讯的文章描述了一些关键参数:

梳理给大家做调整。

apiserver

  • --max-mutating-requests-inflight :在给定时间内的最大 mutating 请求数,调整 apiserver 的流控 qos,可以调整至 3000,默认为 200
  • --max-requests-inflight:在给定时间内的最大 non-mutating 请求数,默认 400,可以调整至 1000
  • --watch-cache-sizes:调大 resources 的 watch size,默认为 100,当集群中 node 以及 pod 数量非常多时可以稍微调大,比如:--watch-cache-sizes=node#1000,pod#5000

controller-manager

  • 调大 –kube-api-qps 值:可以调整至 100,默认值为 20
  • 调大 –kube-api-burst 值:可以调整至 100,默认值为 30
  • 禁用不需要的 controller:kubernetes v1.14 中已有 35 个 controller,默认启动为--controllers,即启动所有 controller,可以禁用不需要的 controller
  • 调整 controller 同步资源的周期:避免过多的资源同步导致集群资源的消耗,所有带有 --concurrent 前缀的参数

scheduler

调大--kube-api-qps 值:可以调整至 100,默认值为 50

如果文章帮助您解决了工作难题,您可以帮我点击屏幕上的任意广告,或者赞助少量费用来支持我的持续创作,谢谢~