在Kubernetes环境里的容器中curl另一个服务时会出现断断续续的超时, 问题现象很简单, 但问题根源很复杂
问题现象
root@nginx-test:/# time curl -I nginx-ingress.default.svc.cluster.local
HTTP/1.1 200 OK
Server: nginx/1.14.2
Date: Fri, 23 Dec 2022 02:45:08 GMT
Content-Type: text/html
Content-Length: 612
Last-Modified: Tue, 04 Dec 2018 14:44:49 GMT
Connection: keep-alive
ETag: "5c0692e1-264"
Accept-Ranges: bytes
real 0m0.008s
user 0m0.003s
sys 0m0.004s
root@nginx-test:/# time curl -I nginx-ingress.default.svc.cluster.local
HTTP/1.1 200 OK
Server: nginx/1.14.2
Date: Fri, 23 Dec 2022 02:45:15 GMT
Content-Type: text/html
Content-Length: 612
Last-Modified: Tue, 04 Dec 2018 14:44:49 GMT
Connection: keep-alive
ETag: "5c0692e1-264"
Accept-Ranges: bytes
real 0m5.512s
user 0m0.008s
sys 0m0.014s
排查过程
Kubernetes中通过ServiceName 请求到具体实例过程：
原Pod A -> 调用 ServiceName -> CoreDNS ClusterIP -> CoreDNS Instance -> 目的Pod Cluster IP -> 目的Pod
内部排除
-
CoreDNS ClusterIP->CoreDNS Instance和目的Pod Cluster IP->目的Pod验证测试，通过ClusterIP选择Endpoint, 全部解析正常, 无错误日志和无出现超时问题 -
怀疑发起端Conntrack问题: https://opengers.github.io/openstack/openstack-base-netfilter-framework-overview/
关于conntrack, 涉及到内核的一些知识，没办法搞的太深，太深了也看不太懂, 大家可自行了解:
当加载内核模块nf_conntrack后，conntrack机制就开始工作，如上图，椭圆形方框conntrack在内核中有两处位置(PREROUTING和OUTPUT之前)能够跟踪数据包。对于每个通过conntrack的数据包，内核都为其生成一个conntrack条目用以跟踪此连接，对于后续通过的数据包，内核会判断若此数据包属于一个已有的连接，则更新所对应的conntrack条目的状态(比如更新为ESTABLISHED状态)，否则内核会为它新建一个conntrack条目。所有的conntrack条目都存放在一张表里，称为连接跟踪表
连接跟踪表存放于系统内存中，可以用cat /proc/net/nf_conntrack, conntrack命令查看当前跟踪的所有conntrack条目
[root@kcs-cpu-test-s-nbkzp /]# cat /proc/net/nf_conntrack | grep "172.19.14.79"
ipv4 2 tcp 6 4 CLOSE src=172.16.0.98 dst=172.19.14.79 sport=18322 dport=9115 src=172.19.14.79 dst=172.16.0.98 sport=9115 dport=18322 [ASSURED] mark=0 zone=0 use=2
ipv4 2 udp 17 8 src=172.19.14.79 dst=192.168.3.10 sport=35338 dport=53 src=172.19.255.190 dst=172.19.14.65 sport=53 dport=16815 mark=0 zone=0 use=2
ipv4 2 udp 17 27 src=172.19.14.79 dst=192.168.3.10 sport=51211 dport=53 src=172.19.255.190 dst=172.19.14.65 sport=53 dport=36029 mark=0 zone=0 use=2
ipv4 2 udp 17 27 src=172.19.14.79 dst=192.168.3.10 sport=44824 dport=53 src=172.19.255.166 dst=172.19.14.65 sport=53 dport=24944 mark=0 zone=0 use=2
ipv4 2 tcp 6 86399 ESTABLISHED src=172.19.255.188 dst=172.19.14.79 sport=59524 dport=9115 src=172.19.14.79 dst=172.19.255.188 sport=9115 dport=59524 [ASSURED] mark=0 zone=0 use=2
ipv4 2 udp 17 27 src=172.19.14.79 dst=192.168.3.10 sport=37464 dport=53 src=172.19.255.166 dst=172.19.14.65 sport=53 dport=57672 mark=0 zone=0 use=2
ipv4 2 udp 17 27 src=172.19.14.79 dst=192.168.3.10 sport=49602 dport=53 src=172.19.255.166 dst=172.19.14.65 sport=53 dport=61155 mark=0 zone=0 use=2
ipv4 2 udp 17 8 src=172.19.14.79 dst=192.168.3.10 sport=45178 dport=53 src=172.19.255.190 dst=172.19.14.65 sport=53 dport=8361 mark=0 zone=0 use=2
ipv4 2 tcp 6 86 SYN_SENT src=172.19.14.79 dst=141.193.213.21 sport=58428 dport=443 [UNREPLIED] src=141.193.213.21 dst=172.16.0.98 sport=443 dport=31561 mark=0 zone=0 use=2
ipv4 2 tcp 6 83 TIME_WAIT src=172.19.14.79 dst=18.206.20.10 sport=59756 dport=443 src=18.206.20.10 dst=172.16.0.98 sport=443 dport=40968 [ASSURED] mark=0 zone=0 use=2
ipv4 2 udp 17 8 src=172.19.14.79 dst=192.168.3.10 sport=42468 dport=53 src=172.19.255.166 dst=172.19.14.65 sport=53 dport=29517 mark=0 zone=0 use=2
ipv4 2 udp 17 27 src=172.19.14.79 dst=192.168.3.10 sport=55563 dport=53 src=172.19.255.166 dst=172.19.14.65 sport=53 dport=62899 mark=0 zone=0 use=2
ipv4 2 icmp 1 27 src=172.19.14.79 dst=114.114.114.114 type=8 code=0 id=11301 [UNREPLIED] src=114.114.114.114 dst=172.16.0.98 type=0 code=0 id=0 mark=0 zone=0 use=2
ipv4 2 udp 17 27 src=172.19.14.79 dst=192.168.3.10 sport=33698 dport=53 src=172.19.255.190 dst=172.19.14.65 sport=53 dport=41024 mark=0 zone=0 use=2
ipv4 2 udp 17 27 src=172.19.14.79 dst=192.168.3.10 sport=43051 dport=53 src=172.19.255.190 dst=172.19.14.65 sport=53 dport=53071 mark=0 zone=0 use=2
ipv4 2 tcp 6 26 SYN_SENT src=172.19.14.79 dst=141.193.213.21 sport=58180 dport=443 [UNREPLIED] src=141.193.213.21 dst=172.16.0.98 sport=443 dport=45470 mark=0 zone=0 use=2
ipv4 2 udp 17 8 src=172.19.14.79 dst=192.168.3.10 sport=39660 dport=53 src=172.19.255.190 dst=172.19.14.65 sport=53 dport=2030 mark=0 zone=0 use=2
ipv4 2 udp 17 8 src=172.19.14.79 dst=192.168.3.10 sport=56476 dport=53 src=172.19.255.190 dst=172.19.14.65 sport=53 dport=42210 mark=0 zone=0 use=2
ipv4 2 udp 17 27 src=172.19.14.79 dst=192.168.3.10 sport=52771 dport=53 src=172.19.255.190 dst=172.19.14.65 sport=53 dport=13105 mark=0 zone=0 use=2
ipv4 2 icmp 1 27 src=172.19.14.79 dst=192.168.3.1 type=8 code=0 id=11301 src=192.168.3.1 dst=172.19.14.79 type=0 code=0 id=11301 mark=0 zone=0 use=2
ipv4 2 tcp 6 23 TIME_WAIT src=172.19.14.79 dst=3.228.146.75 sport=36186 dport=443 src=3.228.146.75 dst=172.16.0.98 sport=443 dport=47344 [ASSURED] mark=0 zone=0 use=2
ipv4 2 tcp 6 86392 ESTABLISHED src=172.19.255.188 dst=172.19.14.79 sport=59778 dport=9115 src=172.19.14.79 dst=172.19.255.188 sport=9115 dport=59778 [ASSURED] mark=0 zone=0 use=2
ipv4 2 tcp 6 89 TIME_WAIT src=172.19.14.79 dst=141.193.213.20 sport=41388 dport=443 src=141.193.213.20 dst=172.16.0.98 sport=443 dport=61174 [ASSURED] mark=0 zone=0 use=2
ipv4 2 udp 17 27 src=172.19.14.79 dst=192.168.3.10 sport=35822 dport=53 src=172.19.255.166 dst=172.19.14.65 sport=53 dport=5434 mark=0 zone=0 use=2
ipv4 2 udp 17 8 src=172.19.14.79 dst=192.168.3.10 sport=56052 dport=53 src=172.19.255.166 dst=172.19.14.65 sport=53 dport=46407 mark=0 zone=0 use=2
ipv4 2 udp 17 8 src=172.19.14.79 dst=192.168.3.10 sport=46306 dport=53 src=172.19.255.166 dst=172.19.14.65 sport=53 dport=50289 mark=0 zone=0 use=2
ipv4 2 icmp 1 27 src=172.19.14.79 dst=8.8.8.8 type=8 code=0 id=11301 src=8.8.8.8 dst=172.16.0.98 type=0 code=0 id=0 mark=0 zone=0 use=2
ipv4 2 icmp 1 27 src=172.19.14.79 dst=39.156.66.18 type=8 code=0 id=11301 src=39.156.66.18 dst=172.16.0.98 type=0 code=0 id=0 mark=0 zone=0 use=2
ipv4 2 udp 17 27 src=172.19.14.79 dst=192.168.3.10 sport=53680 dport=53 src=172.19.255.190 dst=172.19.14.65 sport=53 dport=37363 mark=0 zone=0 use=2
ipv4 2 udp 17 8 src=172.19.14.79 dst=192.168.3.10 sport=40797 dport=53 src=172.19.255.166 dst=172.19.14.65 sport=53 dport=57158 mark=0 zone=0 use=2
ipv4 2 tcp 6 4 CLOSE src=172.16.0.98 dst=172.19.14.79 sport=18320 dport=9115 src=172.19.14.79 dst=172.16.0.98 sport=9115 dport=18320 [ASSURED] mark=0 zone=0 use=2
ipv4 2 tcp 6 86393 ESTABLISHED src=172.19.255.188 dst=172.19.14.79 sport=59804 dport=9115 src=172.19.14.79 dst=172.19.255.188 sport=9115 dport=59804 [ASSURED] mark=0 zone=0 use=2
问题梳理
DNS client (glibc 或 musl libc) 会并发请求 A (ipv4地址) 和 AAAA (ipv6地址)记录，跟 DNS Server 通信自然会先 connect (建立fd)，后面请求报文使用这个 fd 来发送，由于 UDP 是无状态协议， connect 时并不会创建 conntrack 表项, 而并发请求的 A 和 AAAA 记录默认使用同一个 fd 发包，这时它们源 Port 相同，当并发发包时，两个包都还没有被插入 conntrack 表项，所以 netfilter 会为它们分别创建 conntrack 表项，而集群内请求 kube-dns 或 coredns 都是访问的CLUSTER-IP，报文最终会被 DNAT 成一个 endpoint 的 POD IP，当两个包被 DNAT 成同一个 IP，最终它们的五元组就相同了，在最终插入的时候后面那个包就会被丢掉，如果 dns 的 pod 副本只有一个实例的情况就很容易发生，现象就是 dns 请求超时，client 默认策略是等待 5s 自动重试，如果重试成功，我们看到的现象就是 dns 请求有 5s 的延时
netfilter conntrack 模块为每个连接创建 conntrack 表项时，表项的创建和最终插入之间还有一段逻辑，没有加锁，是一种乐观锁的过程。conntrack 表项并发刚创建时五元组不冲突的话可以创建成功，但中间经过 NAT 转换之后五元组就可能变成相同，第一个可以插入成功，后面的就会插入失败，因为已经有相同的表项存在。比如一个 SYN 已经做了 NAT 但是还没到最终插入的时候，另一个 SYN 也在做 NAT，因为之前那个 SYN 还没插入，这个 SYN 做 NAT 的时候就认为这个五元组没有被占用，那么它 NAT 之后的五元组就可能跟那个还没插入的包相同
所以总结来说，根本原因是内核 conntrack 模块的 bug，DNS client(在linux上一般就是resolver)会并发地请求A 和 AAAA 记录netfilter 做 NAT 时可能发生资源竞争导致部分报文丢弃
这篇post有非常详细的解释，建议大家都好好地读一读racy conntrack and dns lookup timeouts
post的相关结论：
* 只有多个线程或进程，并发从同一个 socket 发送相同五元组的 UDP 报文时，才有一定概率会发生
* glibc, musl(alpine linux的libc库)都使用 “parallel query”, 就是并发发出多个查询请求，因此很容易碰到这样的冲突，造成查询请求被丢弃
* 由于 ipvs 也使用了 conntrack, 使用 kube-proxy 的 ipvs 模式，并不能避免这个问题
解决方案
彻底方法一：内核解决
Martynas向内核提交了两个patch来fix这个问题，不过他说如果集群中有多个DNS server的情况下，问题并没有完全解决。
其中一个patch已经在2018-7-18被合并到linux内核主线中: netfilter: nf_conntrack: resolve clash for matching conntracks
目前只有4.19.rc 版本包含这个patch。
规避方法二： 使用TCP替换UDP, 可以彻底饶过内核解决（每次都三握四挥, 平均响应时间下降明显）
对于已经上线运行的容器可以直接修改yaml定义
template:
spec:
dnsConfig:
options:
- name: use-vc
dnsPolicy: ClusterFirst
缺点： DNS解析会从之前的1ms变成10ms左右
规避方法三：打开single-request-reopen（使用不同端口）/sing-request（串行）,避免并发; 绝大概率缓解
如果出现网络慢响应，DNS client也会在timeout 1s后关闭，attempts 再重试；
template:
spec:
dnsConfig:
options:
- name: single-request-reopen
- name: timeout
value: '1'
- name: attempts
value: '3'
- name: ndots
value: '2'
dnsPolicy: ClusterFirst
缺点： 绝大概率缓解, 并非根治； 概率：之前 百分之2 降低到 万分之5
规避其他样式配置：
- pod的postStart hook中
lifecycle:
postStart:
exec:
command:
- /bin/sh
- -c
- "/bin/echo 'options single-request-reopen' >> /etc/resolv.conf"
- ConfigMap覆盖POD里面的/etc/resolv.conf
apiVersion: v1
data:
resolv.conf: |
nameserver xx.xx.xx.xx
search default.svc.cluster.local svc.cluster.local cluster.local
options ndots:2 single-request-reopen timeout:1 attempts:3
kind: ConfigMap
metadata:
name: resolvconf
-----
## Pod中添加
volumeMounts:
- name: resolv-conf
mountPath: /etc/resolv.conf
subPath: resolv.conf
...
volumes:
- name: resolv-conf
configMap:
name: resolvconf
items:
- key: resolv.conf
path: resolv.conf
总结：
无论通过那种方式，只能重启Pod才可以生效
出发本质
从用户视角:
http.Get("http://nginx-ingress.default.svc.cluster.local")
#或者
curl_easy_setopt(curl, CURLOPT_URL, "http://nginx-ingress.default.svc.cluster.local");
#或者
listener, err := net.Listen("tcp", "nginx-ingress.default.svc.cluster.local:80")
系统库底层，都会请求getaddrinfo()或者gethostbyname()方法实现DNS查询
getaddrinfo( 会返回A与AAAA的记录, 如果其中任一个没有返回，都将超时重试
而gethostbyname()只会返回A记录
这个取决于网络基础库实现
参考文章
- https://dzone.com/articles/racy-conntrack-and-dns-lookup-timeouts
- https://www.bookstack.cn/read/kubernetes-practice-guide/troubleshooting-cases-dns-lookup-5s-delay.md
- https://unix.stackexchange.com/questions/141163/dns-lookups-sometimes-take-5-seconds
- https://blog.codacy.com/dns-hell-in-kubernetes/
- https://opengers.github.io/openstack/openstack-base-netfilter-framework-overview/
- https://support.huaweicloud.com/cce_faq/cce_faq_00195.html
「如果这篇文章对你有用,请随意打赏」
如果这篇文章对你有用,请随意打赏
使用微信扫描二维码完成支付
