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

2021-12-20 03:49:00

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

背景信息：

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

如图4.0.1所示，qps=0以及timeout都是连接异常

图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）：

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

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

图4.1.1

图4.1.2
4.2 抓所有端口接着看，发现有异常的syn重传在包里有端口复用，如图4.2.1所示

图4.2.1
但是将端口过滤出来看，上一次复用该端口已经正常的fin掉了（证明不是长连接的问题），且间隔了一分钟左右才复用如图4.2.2，新pod没有重传报文，为什么还是将报文转发给了老的pod呢？

图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呢？

图4.3.1
而在server端的抓包如图4.3.2，虽然有端口复用，但是上一次复用这个端口的时候，对应的连接已经被fin掉了，四次挥手fin已经完成的状态下，对应的连接进入time_Wait状态

图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

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

======再扩展======
案例更新2：
后来遇到一个类似的case，如下这个截图，为什么tcp三次握手建联不成功呢？（端口复用，synack缘何没有，ack里面的seq是否正确？对端tcp连接的状态？）

案例更新3：
源pod访问目标地址为nodeip+nodeport，nodeip是terway-eniip的模式，eni网卡直通，但是会时通时不通
client重传报文如下：

server端接收报文如下：

server端的报文没有收到一开始的syn？那么可能在哪个环节被拒绝了呢？

conntrack表的采集日志如下：

码农公寓

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

背景信息：

复现架构（图4.0.2）：

相关文章