问题背景
K8S集群环境中，有个业务在做大量配置的下发（持续几小时甚至更长时间），期间发现calico的Pod反复重启。
[root@node02 ~]# kubectl get pod -n kube-system -owide|grep node01
calico-kube-controllers-6f59b8cdd8-8v2qw 1/1 Running 0 4h45m 10.10.119.238 node01 <none> <none>
calico-node-b8w2b 1/1 CrashLoopBackOff 43 3d19h 10.10.119.238 node01 <none> <none>
coredns-795cc9c45c-k7qpb 1/1 Running 0 4h45m 177.177.237.42 node01 <none> <none>
...分析过程
看到Pod出现CrashLoopBackOff状态，就想到大概率是Pod内服务自身的原因，先使用kubectl describe命令查看一下：
[root@node02 ~]# kubectl descroiebe pod -n kube-system calico-node-b8w2b
...
Events:
Type Reason Age From Message
---- ------ ---- ---- -------
Warning Unhealthy 58m (x111 over 3h12m) kubelet, node01 (combined from similar events): Liveness probe failed: Get http://localhost:9099/liveness: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)
Normal Pulled 43m (x36 over 3d19h) kubelet, node01 Container image "calico/node:v3.15.1" already present on machine
Warning Unhealthy 8m16s (x499 over 3h43m) kubelet, node01 Liveness probe failed: Get http://localhost:9099/liveness: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)
Warning BackOff 3m31s (x437 over 3h3m) kubelet, node01 Back-off restarting failed container从Event日志可以看出，是calico的健康检查没通过导致的重启，出错原因也比较明显：net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)，这个错误的含义是建立连接超时[1]，并且手动在控制台执行健康检查命令，发现确实响应慢（正常环境是毫秒级别）：
[root@node01 ~]# time curl -i http://localhost:9099/liveness
HTTP/1.1 204 No Content
Date: Tue, 15 Jun 2021 06:24:35 GMT
real0m1.012s
user0m0.003s
sys0m0.005s
[root@node01 ~]# time curl -i http://localhost:9099/liveness
HTTP/1.1 204 No Content
Date: Tue, 15 Jun 2021 06:24:39 GMT
real0m3.014s
user0m0.002s
sys0m0.005s
[root@node01 ~]# time curl -i http://localhost:9099/liveness
real1m52.510s
user0m0.002s
sys0m0.013s
[root@node01 ~]# time curl -i http://localhost:9099/liveness
^C先从calico相关日志查起，依次查看了calico的bird、confd和felix日志，没有发现明显错误，再看端口是否处于正常监听状态：
[root@node02 ~]# netstat -anp|grep 9099
tcp 0 0 127.0.0.1:9099 0.0.0.0:* LISTEN 1202/calico-node
tcp 0 0 127.0.0.1:9099 127.0.0.1:56728 TIME_WAIT -
tcp 0 0 127.0.0.1:56546 127.0.0.1:9099 TIME_WAIT -考虑到错误原因是建立连接超时，并且业务量比较大，先观察一下TCP连接的状态情况：
[root@node01 ~]# netstat -na | awk '/^tcp/{s[$6]++}END{for(key in s) print key,s[key]}'
LISTEN 49
ESTABLISHED 284
SYN_SENT 4
TIME_WAIT 176
连接状态没有什么大的异常，再使用top命令看看CPU负载，好家伙，业务的java进程的CPU跑到了700%，持续观察一段时间发现最高飙到了2000%+，跟业务开发人员沟通，说是在做压力测试，并且线上有可能也存在这么大的并发量。好吧，那就继续看看这个状态下，CPU是不是出于高负载；
[root@node01 ~]# top
top - 14:28:57 up 13 days, 27 min, 2 users, load average: 9.55, 9.93, 9.91
Tasks: 1149 total, 1 running, 1146 sleeping, 0 stopped, 2 zombie
%Cpu(s): 16.0 us, 2.9 sy, 0.0 ni, 80.9 id, 0.0 wa, 0.0 hi, 0.1 si, 0.0 st
KiB Mem : 15249982+total, 21419184 free, 55542588 used, 75538048 buff/cache
KiB Swap: 0 total, 0 free, 0 used. 94226176 avail Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
6754 root 20 0 66.8g 25.1g 290100 S 700.0 17.3 2971:49 java
25214 root 20 0 6309076 179992 37016 S 36.8 0.1 439:06.29 kubelet
20331 root 20 0 3196660 172364 24908 S 21.1 0.1 349:56.64 dockerd查看CPU总核数，再结合上面统计出的load average和cpu的使用率，貌似负载也没有高到离谱；
[root@node01 ~]# cat /proc/cpuinfo| grep "physical id"| sort| uniq| wc -l
48
[root@node01 ~]# cat /proc/cpuinfo| grep "cpu cores"| uniq
cpu cores: 1这就奇怪了，凭感觉，问题大概率是高并发导致的，既然这里看不出什么，那就再回到建立连接超时这个现象上面来。说到连接超时，就会想到TCP建立连接的几个阶段（参考下图），那超时发生在哪个阶段呢？
tcp-state-transmission
Google相关资料[2]，引用一下：
在TCP三次握手创建一个连接时，以下两种情况会发生超时：
client发送SYN后，进入SYN_SENT状态，等待server的SYN+ACK。
server收到连接创建的SYN，回应SYN+ACK后，进入SYN_RECD状态，等待client的ACK。
那么，我们的问题发生在哪个阶段？从下面的验证可以看出，问题卡在了SYN_SENT阶段，并且不止calico的健康检查会卡住，其他如kubelet、kube-controller等组件也会卡住：
[root@node01 ~]# curl http://localhost:9099/liveness
^C
[root@node01 ~]# netstat -anp|grep 9099
tcp 0 0 127.0.0.1:44360 127.0.0.1:9099 TIME_WAIT -
tcp 0 1 127.0.0.1:47496 127.0.0.1:9099 SYN_SENT 16242/curl
[root@node01 ~]# netstat -anp|grep SYN_SENT
tcp 0 1 127.0.0.1:47496 127.0.0.1:9099 SYN_SENT 16242/curl
tcp 0 1 127.0.0.1:39142 127.0.0.1:37807 SYN_SENT 25214/kubelet
tcp 0 1 127.0.0.1:38808 127.0.0.1:10251 SYN_SENT 25214/kubelet
tcp 0 1 127.0.0.1:53726 127.0.0.1:10252 SYN_SENT 25214/kubelet
...到目前为止，我们可以得出2个结论：
- calico健康检查不通过的原因是TCP请求在SYN_SENT阶段卡住了；
- 该问题不是特定Pod的问题，应该是系统层面导致的通用问题；
综合上面2个结论，那就怀疑TCP相关内核参数是不是合适呢？特别是与SYN_SENT状态有关的参数[3]；
net.ipv4.tcp_max_syn_backlog 默认为1024，表示SYN队列的长度
net.core.somaxconn 默认值是128，用于调节系统同时发起的tcp连接数，在高并发的请求中，默认值可能会导致链接超时或者重传，因此需要结合并发请求数来调节此值查看系统上的配置，基本都是默认值，那就调整一下上面两个参数的值并设置生效：
[root@node01 ~]# cat /etc/sysctl.conf
...
net.ipv4.tcp_max_syn_backlog = 32768
net.core.somaxconn = 32768
[root@node01 ~]# sysctl -p
...
net.ipv4.tcp_max_syn_backlog = 32768
net.core.somaxconn = 32768再次执行calico的健康检查命令，请求已经不再卡住了，问题消失，查看异常的Pod也恢复正常：
[root@node01 ~]# time curl -i http://localhost:9099/liveness
HTTP/1.1 204 No Content
Date: Tue, 15 Jun 2021 14:48:38 GMT
real 0m0.011s
user 0m0.004s
sys 0m0.004s
[root@node01 ~]# time curl -i http://localhost:9099/liveness
HTTP/1.1 204 No Content
Date: Tue, 15 Jun 2021 14:48:39 GMT
real 0m0.010s
user 0m0.001s
sys 0m0.005s
[root@node01 ~]# time curl -i http://localhost:9099/liveness
HTTP/1.1 204 No Content
Date: Tue, 15 Jun 2021 14:48:40 GMT
real 0m0.011s
user 0m0.002s其实，最终这个问题的解决也是半猜半验证得到的，如果是正向推演，发现TCP请求在SYN_SENT阶段卡住之后，其实应该要确认相关内核参数是不是确实太小。
解决方案
在高并发场景下，做服务器内核参数的调优。
参考资料
- https://romatic.net/post/go_net_errors/
- http://blog.qiusuo.im/blog/2014/03/19/tcp-timeout/
- http://www.51testing.com/html/13/235813-3710663.html