关注上方 云原生CTO 更多云原生干货等你来探索
专注于 云原生技术分享 提供优质 云原生开发 视频技术培训 面试技巧，及技术疑难问题 解答
云原生技术分享不仅仅局限于containerd
、CoreDNS
、Envoy
、etcd
、Fluentd
、Harbor
、Helm
、Jaeger
、Kubernetes
、Open Policy Agent
、Prometheus
、Rook
、TiKV
、TUF
、Vitess
、Argo
、Buildpacks
、CloudEvents
、CNI
、Contour
、Cortex
、CRI-O
、Falco
、Flux
、gRPC
、KubeEdge
、Linkerd
、NATS
、Notary
、OpenTracing
、Operator Framework
、SPIFFE
、SPIRE
和 Thanos
等
令人困惑的 503s 和 Istio到底是哪里引起的？
Istio
是一个众所周知的开源服务网格。我们，在DKube
，已经使用它一段时间了。最近，我们的用户报告说在 Istio
周围看到上游连接错误和 503。我会带你解决这个有趣的问题。
1. 问题
一段时间以来，我们的用户报告说在我们的 UI 中偶尔会看到如下错误。
上游连接错误或在Header之前断开/重置。重置原因：连接终止
如果我们刷新浏览器页面，这个问题就会消失。但是，要重现此错误非常困难。
我们知道这是 来自 Istio
，因为我们的 UI
不处理这样的页面。有趣的是，我们主要在从我们的 Open ID Connect (OIDC)
提供程序回调到运行 Nodejs
服务器的 UI
服务器期间会看到这一点。
1.2 Istio Mixer
我开始筛选 Istio
日志。有一个包含 2 个容器的 Istio
策略pod—proxy
和Istio Mixer
。proxy
容器定期抛出日志，如
2020–09–04 14:36:59.085][29][warning][filter] [src/istio/mixerclient/report_batch.cc:106] Mixer Report failed with: UNAVAILABLE:upstream connect error or disconnect/reset before headers. reset reason: connection failure
此日志表明Mixer
无法正确处理请求。但是，Mixer
的日志另有建议。Istio 有一个名为 policyCheckFailOpen 的配置参数，这意味着
在无法到达Mixer策略服务的情况下允许所有流量。默认值为false，这意味着当客户端无法连接到Mixer时，流量被拒绝。
由于proxy容器抛出了与我追逐的相同的错误，我认为将此参数设置为 true 可能会解决此问题，但我错了！
1.3 Istio ingress控制器
我再次开始追捕罪魁祸首。我为 Istio
启用了详细日志记录。这将输出一连串的日志，所以要预先警告。
您可以按如下方式启用详细日志记录。
kubectl port-forward -n<namespace> <istio proxy pod> 15000 &
curl -X POST localhost:15000/logging?level=debug
我开始在使用 docker.io/istio/proxyv2:1.1.6
容器镜像的ingress gateway pod
中看到以下调试日志。
[2020–09–04 14:25:43.870][42][debug][pool] [external/envoy/source/common/http/conn_pool_base.cc:20] queueing request due to no available connections
[2020–09–04 14:25:43.966][42][debug][pool] [external/envoy/source/common/http/http1/conn_pool.cc:332] [C27322] connect timeout
[2020–09–04 14:25:43.966][42][debug][connection] [external/envoy/source/common/network/connection_impl.cc:101] [C27322] closing data_to_write=0 type=1
[2020–09–04 14:25:43.966][42][debug][connection] [external/envoy/source/common/network/connection_impl.cc:183] [C27322] closing socket: 1
[2020–09–04 14:25:43.966][42][debug][client] [external/envoy/source/common/http/codec_client.cc:82] [C27322] disconnect. resetting 0 pending requests
[2020–09–04 14:25:43.966][42][debug][pool] [external/envoy/source/common/http/http1/conn_pool.cc:129] [C27322] client disconnected, failure reason:
[2020–09–04 14:25:43.966][42][debug][pool] [external/envoy/source/common/http/http1/conn_pool.cc:164] [C27322] purge pending, failure reason:
[2020–09–04 14:25:43.966][42][debug][router] [external/envoy/source/common/router/router.cc:644] [C0][S16904449693883860917] upstream reset: reset reason connection failure
[2020–09–04 14:25:43.966][42][debug][http] [external/envoy/source/common/http/async_client_impl.cc:94] async http request response headers (end_stream=false): ‘:status’, ‘503’ ‘content-length’, ‘91’ ‘content-type’, ‘text/plain’
还有另一个日志。
[2020–09–14T07:00:25.505Z] “GET /callback?code=xxx&state=xxx HTTP/2” **503 UC** “-” 0 95 1 — “10.233.64.1” “Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.83 Safari/537.36” “2926fb89–58d9–99ef-a5f6–65cd348d3c53” “192.168.200.23:32222” “10.233.64.210:3000” outbound|3000||dkube-ui.dkube.svc.cluster.local — 10.233.64.200:443 10.233.64.1:39082 -
UC 代表上游连接。这是否暗示与 UI
服务器的某种连接超时？服务，UI
服务器，看起来不错。那为什么是503s
呢？我错过了什么？
1.4. 数据传输协议
我决定对 UI
服务器的容器接口进行 tcpdump
。为了进行 tcpdump
，您需要知道容器的接口名称。在此之前，您需要知道接口的链接 ID
。为此，请执行到容器并输入以下内容
kubectl exec -it <pod name> -n<namespace> — cat /sys/class/net/eth0/iflink
通常，eth0
是事实上的容器接口名称。相应地更改它。无论如何，上面的命令将输出类似 70 的内容。要获取 veth
接口名称，请运行以下命令
ip a | grep ^70
或
ip link | grep ^70
这会给你，
70: **veth930b1c36**@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1410 qdisc noqueue master cni0 state UP mode DEFAULT group default
突出显示的部分是您的界面。现在开始使用 tcpdump
：
sudo tcpdump -eni veth930b1c36 -w dump.pcap
1.5 Ksniff (K8s tcpdump)
如果您不想经历上述麻烦，可以使用ksniff
。它是一个 kubectl
插件，它利用 tcpdump
在 Kubernetes
集群中的任何 pod
上启动远程捕获。我通过Krew安装了这个。现在开始使用 tcpdump
：
kubectl sniff <pod name> -p -n<namespace> -f 'tcp[tcpflags] & (tcp-syn|tcp-fin|tcp-rst|tcp-push) != 0' -o dump.pcap
https://github.com/eldadru/ksniff, '-f' 是可选的，使用它是因为我只对
TCP
数据包的一个子集感兴趣。检查捕获的数据包
dump.pcap
将包含您捕获的数据包，可以将其导入 Wireshark
以获得更好的可读性和理解性。现在是有趣的部分。
07:00:25.507495 ethertype IPv4 (0x0800), length 1477: 10.233.64.200.55116 > 10.233.64.210.3000: Flags [P.], seq 1118:2529, ack 2921202, win 6771, options [nop,nop,TS val 2437011412 ecr 1473459814], length 1411
07:00:25.507530 ethertype IPv4 (0x0800), length 54: 10.233.64.210.3000 > 10.233.64.200.55116: Flags [R], seq 1780822149, win 0, length 0
10.233.64.200
属于 Istio ingress
，10.233.64.210
属于 UI 服务器。从转储中可以看出，入口正在通过已建立的 TCP
连接推送数据。但是，UI
服务器以重置标志进行响应。重置可能是由 UI
服务器发送的，因为数据包到达之前建立的 TCP
连接，但本地服务器已经关闭了它的套接字。
正是因为这个重置标志，Istio
正确地说，“上游重置：重置原因连接终止”。
1.6 UI服务器为什么要发送RESET包？
Ingress
控制器在 T 秒向 UI 服务器发送第一个SYN
数据包。UI 服务器在
T+5
发送FIN
数据包，因为过去 5 秒内没有人使用它。这是套接字被破坏的时间，可以通过 此处指定的 5 秒保持连接超时来解释。一段时间后，
OIDC
提供商在T+19.8
发出回调。此请求到达istio
代理，然后被发送到UI
服务器。由于套接字已经关闭，因此
UI
服务器在T+19.8
发送了一个重置数据包。
因此，一旦套接字被破坏，就必须建立新的连接。这就是为什么浏览器页面刷新使我们能够通过。
本质上，UI 服务器因为 http keepalive
超时而关闭了套接字。对于 Nodejs
服务器，http keepalive
超时是指服务器在完成写入最后一个响应后，在套接字将被销毁之前等待额外传入数据所需的非活动毫秒数。如果服务器在保持活动超时触发之前收到新数据，它将重置此不活动超时。
2 解决方案
理想情况下，Istio
不应写入已关闭的套接字。这可能是 Istio
内部竞争条件的结果。我们或许也应该转向更高版本的 Istio
。
2.1 解决方案1
一种解决方案可能是增加 UI
服务器的 HTTP keepalive
超时，以便它不会很快发送 RESET
数据包。例如：1 分钟
2.2 解决方案2
另一种解决方案是在 503
状态代码上启用 HTTP
重试。请注意，您无法根据 Istio
的 HTTP
请求类型（POST、GET、PUT
等）进行配置。这可能对非幂等请求处理程序不利。
这两种解决方案可以结合使用，以提供更强大的 503
防护。
由于各种原因，我们继续采用第二种解决方案。这是通过在虚拟服务上设置重试来完成的，这是 Istio
的流量路由策略。
retries:
attempts: 3
perTryTimeout: 5s
retryOn: gateway-error,connect-failure,refused-stream
Istio proxy
缓存每个请求。在下图中，我们可以看到 HTTP
重试（第 4 行）正在运行。获得 TCP
重置（第三行）后，初始 GET
调用（第二行）失败。Istio gateway
重试失败的请求（参见第二个 GET
调用，第 6 行）并成功。
我看到许多报告的问题与 Istio
的上游连接错误和 503 相关。因此，我希望有人会发现这有帮助。
5.3 文档
参考资料 [1]
参考资料
https://medium.com/@in.live.in/puzzling-503s-and-istio-1bf504b9aae6: https://github.com/prometheus/blackbox_exporter
