k8s网络诊断之我的流量去哪了

k8s网络诊断之我的流量去哪了

背景信息:

   某客户反馈,生产业务的应用在做滚动更新时大量502报错,同时生产业务中pod设置了prestop来优雅下线(延迟关闭),但是在滚动更新时依然会有502的问题,由于生产环境流量比较高,决定搭建测试环境模拟复现该问题,实际复现过程中发现,pod切换完成后,客户端访问svc关联的SLB,应用会超时一段时间或者qps下降为0<br />


如图4.0.1所示,qps=0以及timeout都是连接异常
k8s网络诊断之我的流量去哪了
图4.0.1
deplyment里面关于prestop的设置节选(具有 readiness健康检查)

 spec:
      containers:
      - image: nginx:1.18
        imagePullPolicy: IfNotPresent
        lifecycle:
          preStop:
            exec:
              command:
              - /bin/bash
              - -c
              - sleep 20
 readinessProbe:
          failureThreshold: 5
          httpGet:
            path: /
            port: 80
            scheme: HTTP
          initialDelaySeconds: 5
          periodSeconds: 5
          successThreshold: 1
          timeoutSeconds: 1

复现架构(图4.0.2):

k8s网络诊断之我的流量去哪了
图4.0.2
这种问题我们在了解架构之后,看看抓包在哪个环节比较简便,先抓包看下是建联异常,还是返回数据异常呢?
抓eth0的对应svc的nodeport,看起来有重传,但是不知道重传给哪个pod,图4.1.1 图4.1.2

tcpdump -i eth0 port 31199 -s 0 -w nodeport.pcap

k8s网络诊断之我的流量去哪了
图4.1.1
k8s网络诊断之我的流量去哪了
图4.1.2
4.2 抓所有端口接着看,发现有异常的syn重传在包里有端口复用,如图4.2.1所示
k8s网络诊断之我的流量去哪了
图4.2.1
但是将端口过滤出来看,上一次复用该端口已经正常的fin掉了(证明不是长连接的问题),且间隔了一分钟左右才复用如图4.2.2,新pod没有重传报文,为什么还是将报文转发给了老的pod呢?
k8s网络诊断之我的流量去哪了
图4.2.2
4.3 是否会是ipvs规则更新比较慢导致转发给了老的pod?接着收集一下endpoint,pod ,ipvs等组件的变化看看是否存在未更新的情况,收集脚本如下(注意替换ip)

$ cat pod-ep-ipvs.sh 
for i in {1..200}
        do
        echo $(date) >> pod.txt
        kubectl get pods -n ratel -o wide |grep v***s-test >> pod.txt
        kubectl describe ep -n ratel v***s-test-service >>pod.txt
        sudo ipvsadm -Ln |egrep "10.27.255.42:80|10.20.81.251:80" -A 5 >>pod.txt(svc,slb的ip)
        sudo ipvsadm -Ln -c |egrep "10.27.1.245|10.27.1.246"|egrep -vi "close|time_wait" >>pod.txt(pod的ip)
        sudo egrep "10.27.1.245|10.27.1.246" /proc/net/nf_conntrack|egrep -vi "close|time_wait" >>pod.txt(pod的ip)
        sleep 1s
        done

从抓取的记录可以看到相关资源的ipvs规则,pod状态以及endpoint的设置都是新的podip,说明问题可能出在转发层面,而负载转发流量的恰恰就是ipvs本身

2020年 06月 08日 星期一 15:14:28 CST
====pod的采集====
v****s-test-85f56494bd-5swfv       1/1     Running     0    50s     10.27.1.249   cn-beijing.10.20.79.226   <none>
v***s-test-85f56494bd-lx59h        1/1     Running     0    57s     10.27.1.248   cn-beijing.10.20.79.226   <none>
====endpoint的采集====
Name:         v***s-test-service
Namespace:    r***l
Labels:       app=v***s-test
              team=default
Annotations:  <none>
Subsets:
  Addresses:          10.27.1.248,10.27.1.249
  NotReadyAddresses:  <none>
  Ports:
    Name     Port   Protocol
    ----     ----   --------
    crontab  50091  TCP
    main     80     TCP
   
Events:  <none>
====ipvs rule的采集====
TCP  10.20.81.251:80 rr
  -> 10.27.1.248:80               Masq    1      0          0
  -> 10.27.1.249:80               Masq    1      0          0
TCP  10.20.81.252:80 rr
  -> 10.27.1.114:8080             Masq    1      0          0
  -> 10.27.4.110:8080             Masq    1      0          0
--
TCP  10.27.255.42:80 rr
  -> 10.27.1.248:80               Masq    1      0          0
  -> 10.27.1.249:80               Masq    1      0          0
TCP  10.27.255.42:50091 rr
  -> 10.27.1.248:50091            Masq    1      0          0
  -> 10.27.1.249:50091            Masq    1      0          0

前面脚本抓取的日志中是有提取ipvs 的session以及nf_conn表的记录的,从日志里面可以看到表项里面都有syn建联的报文了,

====ipvs的session采集====
IPVS connection entries
pro expire state       source             virtual            destination
TCP 00:09  SYN_RECV    100.97.130.6:27307 10.20.79.226:31199 10.27.1.245:80
TCP 00:59  SYN_RECV    10.23.31.87:59462  10.20.79.226:31199 10.27.1.246:80
TCP 00:09  SYN_RECV    100.97.130.130:26633 10.20.79.226:31199 10.27.1.245:80
====nf_conntrack表内session的采集====
ipv4     2 tcp      6 107 SYN_SENT src=10.27.2.92 dst=10.27.1.245 sport=37912 dport=18080 [UNREPLIED] src=10.27.1.245 dst=10.27.2.92 sport=18080 dport=37912 mark=0 zone=0 use=2
ipv4     2 tcp      6 119 SYN_SENT src=10.23.31.87 dst=10.20.79.226 sport=59462 dport=31199 [UNREPLIED] src=10.27.1.246 dst=10.23.31.87 sport=80 dport=59462 mark=0 zone=0 use=2
ipv4     2 tcp      6 103 SYN_SENT src=10.27.1.241 dst=10.27.1.246 sport=38702 dport=80 [UNREPLIED] src=10.27.1.246 dst=10.27.1.241 sport=80 dport=38702 mark=0 zone=0 use=2
ipv4     2 tcp      6 104 SYN_SENT src=10.27.4.30 dst=10.27.1.245 sport=36178 dport=18080 [UNREPLIED] src=10.27.1.245 dst=10.27.4.30 sport=18080 dport=36178 mark=0 zone=0 use=2


如下图所示图4.3.1,客户端的syn重传无法建联,我们知道tcp按次握手要 syn--synack--ack才能完成建联,为什么server端不返回synack呢?
k8s网络诊断之我的流量去哪了
图4.3.1
而在server端的抓包如图4.3.2,虽然有端口复用,但是上一次复用这个端口的时候,对应的连接已经被fin掉了,四次挥手fin已经完成的状态下,对应的连接进入time_Wait状态
k8s网络诊断之我的流量去哪了
图4.3.2
4.4 在k8s 集群里选择ipvs组件,那么负责转发流量给对应的endpoint就是ipvs,这种情况就要抓全量的session去看session状态变化,怀疑跟五元组相同复用有关系,通过抓ipvs以及/proc/net/nf_conntrack全量session对比发现上一秒time_Wait还在过期倒计时,下一秒复用端口变成了syn_recv,并转发给了老的ip

2020年 06月 08日 星期一 17:58:22 CST
TCP 01:00  TIME_WAIT   10.23.31.87:58578  10.20.79.226:31199 10.27.1.249:80
ipv4     2 tcp      6 60 TIME_WAIT src=10.23.31.87 dst=10.20.79.226 sport=58578 dport=31199 src=10.27.1.249 dst=10.23.31.87 sport=80 dport=58578 [ASSURED] mark=0 zone=0 use=2
2020年 06月 08日 星期一 17:58:24 CST
TCP 00:58  TIME_WAIT   10.23.31.87:58578  10.20.79.226:31199 10.27.1.249:80
ipv4     2 tcp      6 58 TIME_WAIT src=10.23.31.87 dst=10.20.79.226 sport=58578 dport=31199 src=10.27.1.249 dst=10.23.31.87 sport=80 dport=58578 [ASSURED] mark=0 zone=0 use=2
2020年 06月 08日 星期一 17:58:26 CST
TCP 00:59  SYN_RECV    10.23.31.87:58578  10.20.79.226:31199 10.27.1.249:80
ipv4     2 tcp      6 119 SYN_SENT src=10.23.31.87 dst=10.20.79.226 sport=58578 dport=31199 [UNREPLIED] src=10.27.1.249 dst=10.23.31.87 sport=80 dport=58578 mark=0 zone=0 use=2
2020年 06月 08日 星期一 17:58:27 CST
TCP 00:58  SYN_RECV    10.23.31.87:58578  10.20.79.226:31199 10.27.1.249:80
ipv4     2 tcp      6 117 SYN_SENT src=10.23.31.87 dst=10.20.79.226 sport=58578 dport=31199 [UNREPLIED] src=10.27.1.249 dst=10.23.31.87 sport=80 dport=58578 mark=0 zone=0 use=2


而后确认为bug
https://github.com/kubernetes/kubernetes/issues/81775

======start 这一段引用自网络资料========

原因
K8S 实现了 pod graceful termination,也就是在显式缩容或者部署新服务从而旧的 replica set 隐式缩容时,请求这个 pod 对应 cluster IP 的客户端无感。 其实现机制是这样的:


首先, kube-proxy 把 LVS 里某个 cluster IP 要删除的 pod IP 的 weight 设置成 0,但并不删除这个 pod IP,目的是让新的连接走剩下的活着的 pod IP,而老的没断开的连接继续传输数据;
然后, kube-proxy 不断检查 LVS 那个要删除的 pod IP 上的活跃连接和非活跃连接数,只有当两者都为零时,才会真的从 LVS 里删除这个 pod IP。
一般来说,K8S 里服务之间往往请求很短,会使用短连接或者 keepalive time 比较短的长连接,而 pod graceful termination 默认期限 30s,也就是 30s 内 pod 还没退出就会强行杀掉,所以「已有连接」有30s 的时间自然断开,不影响服务,而「新连接」有 weight 设置的缘故,不会走到这个要被删除的 pod IP,所以新连接畅通无阻, 总结来说,非常完美的 graceful termination。


然而细节是魔鬼,K8S 1.13 里为了提升性能,把 /proc/sys/net/ipv4/vs/conn_reuse_mode 从默认值1 改成 0 了, 这个值为 1 时,会导致某种情况下新建连接有 1s 的额外延迟,而改成 0 的效果是, 如果请求 cluster IP 的源端口被重用了,也就是在 conntrack table 里已经有了 条目了,那么 IPVS 会直接选择之前服务这个 的 pod,并不会真的按权重走负载均衡逻辑,导致新的连接去了那个要被删除的 pod,当那个 pod 30s 后被删除后,这些重用了源端口的流量就会连接失败了。在这个四元组里 src_ip 是请求服务的客户端 pod ip,对于这一个客户端 pod 来说是固定的,cluster 的 ip 和 port 也都是固定的,只有 src_port 可以在 net.ipv4.ip_local_port_range 规定的不到三万个端口里变化,在高并发短链接情况下非常容易发生源端口复用的情况。

======end 这一段引用自网络资料========


优化方案:
1,扩大客户端local_portrange
2,关闭ipvs所在的实例的net.ipv4.vs.conn_reuse_mode 设置为1,会导致性能下降,偶发1s的延迟(0复用会导致五元组相同转发给老的pod)
3,使用iptables的模式


总结:
在IPVS网络代理模式下的kubernetes集群中进行滚动更新,期间如果客户端在短时间(两分钟)内发送大量请求(短链接,需建联),且客户端端口触发复用(端口随机分配不是一直递增,但是本地端口依然是用的越少越不容易复现),这个时候由于客户端的请求报文网络五元组相同,且ipvs的复用连接参数net.ipv4.vs.conn_reuse_mode为0时,就会触发IPVS复用Connection(time_wait变SYN_RECV/syn_sent),会导致报文被转发到了一个已经“销毁”的Pod上,从而导致建联失败,引发业务异常


扩展:
为何ipvs是syn_recv,而nf_conntrack表是syn_sent?
我们依据tcp三次握手的状态变化来推断,client跟ipvs建连因此ipvs记录的是syn_recv,而ipvs实际将流量导向真实pod的时候,ipvs作为一个“中间商”,它发送syn给pod,因此nf_conntrack里面填充的是syn_sent
k8s网络诊断之我的流量去哪了 k8s网络诊断之我的流量去哪了


-------------------------专家服务 值得信赖------------------------------
-------------------------专家服务 不负所托------------------------------


======再扩展======
案例更新2:
后来遇到一个类似的case,如下这个截图,为什么tcp三次握手建联不成功呢?(端口复用,synack缘何没有,ack里面的seq是否正确?对端tcp连接的状态?)
k8s网络诊断之我的流量去哪了
案例更新3:
源pod访问目标地址为nodeip+nodeport,nodeip是terway-eniip的模式,eni网卡直通,但是会时通时不通
client重传报文如下:
k8s网络诊断之我的流量去哪了
server端接收报文如下:
k8s网络诊断之我的流量去哪了
server端的报文没有收到一开始的syn?那么可能在哪个环节被拒绝了呢?


conntrack表的采集日志如下:
k8s网络诊断之我的流量去哪了

上一篇:关于Linux cpu中断问题及案例


下一篇:如何使用curl访问k8s的apiserver