本系列文章將介紹使用者從 Spring Cloud,Dubbo 等傳統微服務框架遷移到 Istio 服務網格時的一些經驗,以及在使用 Istio 過程中可能遇到的一些常見問題的解決方法。
失敗的 Eureka 心跳通知
在上一篇文章中,我們介紹了 Headless Service 和普通 Service 的區別。由於 Headless Service 的特殊性,在 Istio 下發給 Envoy Sidecar 的配置中,此類服務的配置引數和其他服務的引數有所不同。除了我們上次遇到的 mTLS 故障之外,這些差異可能還會導致應用出現一些其他意想不到的情況。
這次遇到的問題現象是:在 Spring Cloud 應用遷移到 Istio 中後,服務提供者向 Eureka Server 傳送心跳失敗。
備註:Eureka Server 採用心跳機制來判定服務的健康狀態。服務提供者在啟動後,週期性(預設30秒)向Eureka Server傳送心跳,以證明當前服務是可用狀態。Eureka Server在一定的時間(預設90秒)未收到客戶端的心跳,則認為服務當機,登出該例項。
檢視應用程式日誌,可以看到 Eureka 客戶端傳送心跳失敗的相關日誌資訊。
2020-09-24 13:32:46.533 ERROR 1 --- [tbeatExecutor-0] com.netflix.discovery.DiscoveryClient : DiscoveryClient_EUREKA-TEST-CLIENT/eureka-client-544b94f967-gcx2f:eureka-test-client - was unable to send heartbeat!
com.netflix.discovery.shared.transport.TransportException: Cannot execute request on any known server
at com.netflix.discovery.shared.transport.decorator.RetryableEurekaHttpClient.execute(RetryableEurekaHttpClient.java:112) ~[eureka-client-1.9.13.jar!/:1.9.13]
at com.netflix.discovery.shared.transport.decorator.EurekaHttpClientDecorator.sendHeartBeat(EurekaHttpClientDecorator.java:89) ~[eureka-client-1.9.13.jar!/:1.9.13]
at com.netflix.discovery.shared.transport.decorator.EurekaHttpClientDecorator$3.execute(EurekaHttpClientDecorator.java:92) ~[eureka-client-1.9.13.jar!/:1.9.13]
at com.netflix.discovery.shared.transport.decorator.SessionedEurekaHttpClient.execute(SessionedEurekaHttpClient.java:77) ~[eureka-client-1.9.13.jar!/:1.9.13]
at com.netflix.discovery.shared.transport.decorator.EurekaHttpClientDecorator.sendHeartBeat(EurekaHttpClientDecorator.java:89) ~[eureka-client-1.9.13.jar!/:1.9.13]
at com.netflix.discovery.DiscoveryClient.renew(DiscoveryClient.java:864) ~[eureka-client-1.9.13.jar!/:1.9.13]
at com.netflix.discovery.DiscoveryClient$HeartbeatThread.run(DiscoveryClient.java:1423) ~[eureka-client-1.9.13.jar!/:1.9.13]
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) ~[na:na]
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[na:na]
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) ~[na:na]
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630) ~[na:na]
at java.base/java.lang.Thread.run(Thread.java:832) ~[na:na]
過期的 IP 地址
對於請求失敗類的故障,我們首先可以通過 Envoy 的訪問日誌檢視失敗原因。通過下面的命令檢視客戶端 Envoy Sidecar 的日誌:
k logs -f eureka-client-66f748f84f-vvvmz -c eureka-client -n eureka
從 Envoy 日誌中可以檢視到客戶端通過 HTTP PUT 向伺服器發出的心跳請求。該請求的 Response 狀態碼為 "UF,URX",表示其 Upstream Failure,即連線上游服務失敗。在日誌中還可以看到,在連線失敗後,Envoy 向客戶端應用返回了一個 "503" HTTP 錯誤碼。
[2020-09-24T13:31:37.980Z] "PUT /eureka/apps/EUREKA-TEST-CLIENT/eureka-client-544b94f967-gcx2f:eureka-test-client?status=UP&lastDirtyTimestamp=1600954114925 HTTP/1.1" 503 UF,URX "-" "-" 0 91 3037 - "-" "Java-EurekaClient/v1.9.13" "1cd54507-3f93-4ff3-a93e-35ead11da70f" "eureka-server:8761" "172.16.0.198:8761" outbound|8761||eureka-server.eureka.svc.cluster.local - 172.16.0.198:8761 172.16.0.169:53890 - default
從日誌中可以看到訪問的 Upstream Cluster 是 outbound|8761||eureka-server.eureka.svc.cluster.local ,Envoy 將該請求轉發到了 IP地址 為 172.16.0.198 的 Upstream Host。
檢視叢集中部署的服務,可以看到 eureka-server 是一個 Headless Service。
HUABINGZHAO-MB0:eureka-istio-test huabingzhao$ k get svc -n eureka -o wide
NAME TYPE CLUSTER-IP EXTERNAL-IP PORT(S) AGE SELECTOR
eureka-server ClusterIP None <none> 8761/TCP 17m app=eureka-server
在本系列的上一篇文章『Istio 運維實戰系列(2):讓人頭大的『無頭服務』-上』中,我們瞭解到 Headless Service 並沒有 Cluster IP,DNS 會直接將 Service 名稱解析到 Service 後端的多個 Pod IP 上。Envoy 日誌中顯示連線 Eureka Server地址 172.16.0.198 失敗,我們來看看這個 IP 來自哪一個 Eureka Server 的 Pod 。
HUABINGZHAO-MB0:eureka-istio-test huabingzhao$ k get pod -n eureka -o wide | grep eureka-server
NAME READY STATUS RESTARTS AGE IP NODE NOMINATED NODE READINESS GATES
eureka-server-0 1/1 Running 0 6h55m 172.16.0.59 10.0.0.15 <none> <none>
eureka-server-1 1/1 Running 0 6m1s 172.16.0.200 10.0.0.7 <none> <none>
eureka-server-2 1/1 Running 0 6h56m 172.16.1.3 10.0.0.14 <none> <none>
從上面的命令輸出中可以看到 Eureka 叢集中有三個伺服器,但沒有哪一個伺服器的 Pod IP 是 Envoy 日誌中顯示的 172.16.0.198。進一步分析發現 eureka-server-1 Pod 的啟動時間比客戶端的啟動時間晚很多,初步懷疑 Envoy 採用了一個已經被銷燬的 Eureka Server 的 IP 進行訪問,導致訪問失敗。
通過檢視 Envoy dump 檔案中 outbound|8761||eureka-server.eureka.svc.cluster.local 的相關配置,進一步加深了我對此的懷疑。從下面的 yaml 片段中可以看到該 Cluster 的型別為 “ORIGINAL_DST”。
{
"version_info": "2020-09-23T03:57:03Z/27",
"cluster": {
"@type": "type.googleapis.com/envoy.api.v2.Cluster",
"name": "outbound|8761||eureka-server.eureka.svc.cluster.local",
"type": "ORIGINAL_DST", # 該選項表明 Enovy 在轉發請求時會直接採用 downstream 原始請求中的地址。
"connect_timeout": "1s",
"lb_policy": "CLUSTER_PROVIDED",
...
}
根據 Envoy 的文件說明,“ORIGINAL_DST” 的解釋為:
In these cases requests routed to an original destination cluster are forwarded to upstream hosts as addressed by the redirection metadata, without any explicit host configuration or upstream host discovery.
即對於“ORIGINAL_DST” 型別的 Cluster,Envoy 在轉發請求時會直接採用 downstream 請求中的原始目的地 IP 地址,而不會採用服務發現機制。Istio 中 Envoy Sidecar 的該處理方式和 K8s 對 Headless Service 的處理是類似的,即由客戶端根據 DNS 直接選擇一個後端的 Pod IP,不會採用負載均衡演算法對客戶端的請求進行重定向分發。但讓人疑惑的是:為什麼客戶端通過 DNS 查詢得到的 Pod 地址 172.16.0.198 訪問失敗了呢?這是由於客戶端查詢 DNS 時得到的地址在訪問期間已經不存在了。下圖解釋了導致該問題的原因:
- Client 查詢 DNS 得到 eureka-server 的三個IP地址。
- Client 選擇 Server-1 的 IP 172.16.0.198 發起連線請求,請求被 iptables rules 攔截並重定向到了客戶端 Pod 中 Envoy 的 VirtualInbound 埠 15001。
- 在收到 Client 的連線請求後,根據 Cluster 的配置,Envoy 採用請求中的原始目的地址 172.16.0.198 連線 Server-1,此時該 IP 對應的 Pod 是存在的,因此 Envoy 到 Server-1 的連結建立成功,Client 和 Envoy 之間的連結也會建立成功。Client 在建立連結時採用了 HTTP Keep Alive 選項,因此 Client 會一直保持該連結,並通過該連結以 30 秒間隔持續傳送 HTTP PUT 服務心跳通知。
- 由於某些原因,該 Server-1 Pod 被 K8s 重建為 Server-1ꞌ,IP 發生了變化。
- 當 Server-1 的 IP 變化後,Envoy 並不會立即主動斷開和 Client 端的連結。此時從 Client 的角度來看,到 172.16.0.198 的 TCP 連結依然是正常的,因此 Client 會繼續使用該連結傳送 HTTP 請求。同時由於 Cluster 型別為 “ORIGINAL_DST” ,Envoy 會繼續嘗試連線 Client 請求中的原始目的地址 172.16.0.198,如圖中藍色箭頭所示。但是由於該 IP 上的 Pod 已經被銷燬,Envoy 會連線失敗,並在失敗後向 Client 端返回一個這樣的錯誤資訊:“upstream connect error or disconnect/reset before headers. reset reason: connection failure HTTP/1.1 503” 。如果 Client 在收到該錯誤後不立即斷開並重建連結,那麼直到該連結超時之前,Client 都不會重新查詢 DNS 獲取到 Pod 重建後的正確地址。
為 Headless Service 啟用 EDS
從前面的分析中我們已經知道出錯的原因是由於客戶端 HTTP 長連結中的 IP 地址過期導致的。那麼一個最直接的想法就是讓 Envoy 採用正確的 IP 地址去連線 Upstream Host。在不修改客戶端程式碼,不重建客戶端連結的情況下,如何才能實現呢?
如果對比一個其他服務的 Cluster 配置,可以看到正常情況下,Istio 下發的配置中,Cluster 型別為 EDS (Endopoint Discovery Service),如下面的 yaml 片段所示:
{
"version_info": "2020-09-23T03:02:01Z/2",
"cluster": {
"@type": "type.googleapis.com/envoy.config.cluster.v3.Cluster",
"name": "outbound|8080||http-server.default.svc.cluster.local",
"type": "EDS", # 普通服務採用 EDS 服務發現,根據 LB 演算法從 EDS 下發的 endpoint 中選擇一個進行連線
"eds_cluster_config": {
"eds_config": {
"ads": {},
"resource_api_version": "V3"
},
"service_name": "outbound|8080||http-server.default.svc.cluster.local"
},
...
}
在採用 EDS 的情況下,Envoy 會通過 EDS 獲取到該 Cluster 中所有可用的 Endpoint,並根據負載均衡演算法(預設為 Round Robin)將 Downstream 發來的請求傳送到不同的 Endpoint。因此只要把 Cluster 型別改為 EDS,Envoy 在轉發請求時就不會再採用請求中錯誤的原始 IP 地址,而會採用 EDS 自動發現到的 Endpoint 地址。採用 EDS 的情況下,本例的中的訪問流程如下圖所示:
通過查閱 Istio 原始碼,可以發現 Istio 對於 Headless Service 預設採用了 "ORIGINAL_DST" 型別的 Cluster,但我們也可以通過設定一個 Istiod 的環境變數 PILOT_ENABLE_EDS_FOR_HEADLESS_SERVICES 為 Headless Service 強制啟用 EDS 。
func convertResolution(proxy *model.Proxy, service *model.Service) cluster.Cluster_DiscoveryType {
switch service.Resolution {
case model.ClientSideLB:
return cluster.Cluster_EDS
case model.DNSLB:
return cluster.Cluster_STRICT_DNS
case model.Passthrough: // Headless Service 的取值為 model.Passthrough
if proxy.Type == model.SidecarProxy {
// 對於 Sidecar Proxy,如果 PILOT_ENABLE_EDS_FOR_HEADLESS_SERVICES 的值設為 True,則啟用 EDS,否則採用 ORIGINAL_DST
if service.Attributes.ServiceRegistry == string(serviceregistry.Kubernetes) && features.EnableEDSForHeadless {
return cluster.Cluster_EDS
}
return cluster.Cluster_ORIGINAL_DST
}
return cluster.Cluster_EDS
default:
return cluster.Cluster_EDS
}
}
在將 Istiod 環境變數 PILOT_ENABLE_EDS_FOR_HEADLESS_SERVICES 設定為 true 後,再檢視 Envoy 的日誌,可以看到雖然請求原始 IP 地址還是 172.16.0.198,但 Envoy 已經把請求分發到了實際可用的三個 Server 的 IP 上。
[2020-09-24T13:35:28.790Z] "PUT /eureka/apps/EUREKA-TEST-CLIENT/eureka-client-544b94f967-gcx2f:eureka-test-client?status=UP&lastDirtyTimestamp=1600954114925 HTTP/1.1" 200 - "-" "-" 0 0 4 4 "-" "Java-EurekaClient/v1.9.13" "d98fd3ab-778d-42d4-a361-d27c2491eff0" "eureka-server:8761" "172.16.1.3:8761" outbound|8761||eureka-server.eureka.svc.cluster.local 172.16.0.169:39934 172.16.0.198:8761 172.16.0.169:53890 - default
[2020-09-24T13:35:58.797Z] "PUT /eureka/apps/EUREKA-TEST-CLIENT/eureka-client-544b94f967-gcx2f:eureka-test-client?status=UP&lastDirtyTimestamp=1600954114925 HTTP/1.1" 200 - "-" "-" 0 0 1 1 "-" "Java-EurekaClient/v1.9.13" "7799a9a0-06a6-44bc-99f1-a928d8576b7c" "eureka-server:8761" "172.16.0.59:8761" outbound|8761||eureka-server.eureka.svc.cluster.local 172.16.0.169:45582 172.16.0.198:8761 172.16.0.169:53890 - default
[2020-09-24T13:36:28.801Z] "PUT /eureka/apps/EUREKA-TEST-CLIENT/eureka-client-544b94f967-gcx2f:eureka-test-client?status=UP&lastDirtyTimestamp=1600954114925 HTTP/1.1" 200 - "-" "-" 0 0 2 1 "-" "Java-EurekaClient/v1.9.13" "aefb383f-a86d-4c96-845c-99d6927c722e" "eureka-server:8761" "172.16.0.200:8761" outbound|8761||eureka-server.eureka.svc.cluster.local 172.16.0.169:60794 172.16.0.198:8761 172.16.0.169:53890 - default
神祕消失的服務
在將 Eureka Server Cluster 的型別從 ORIGINAL_DST 改為 EDS 之後,之前心跳失敗的服務正常了。但過了一段時間後,發現原來 Eureka 中註冊的部分服務下線,導致服務之間無法正常訪問。查詢 Eureka Server 的日誌,發現日誌中有如下的錯誤:
2020-09-24 14:07:35.511 WARN 6 --- [eureka-server-3] c.netflix.eureka.cluster.PeerEurekaNode : EUREKA-SERVER-2/eureka-server-2.eureka-server.eureka.svc.cluster.local:eureka-server-2:8761:Heartbeat@eureka-server-0.eureka-server: missing entry.
2020-09-24 14:07:35.511 WARN 6 --- [eureka-server-3] c.netflix.eureka.cluster.PeerEurekaNode : EUREKA-SERVER-2/eureka-server-2.eureka-server.eureka.svc.cluster.local:eureka-server-2:8761:Heartbeat@eureka-server-0.eureka-server: cannot find instance
從日誌中我們可以看到多個 Eureka Server 之間的資料同步發生了錯誤。當部署為叢集模式時,Eureka 叢集中的多個例項之間會進行資料同步,本例中的 Eureka 叢集中有三個例項,這些例項之間的資料同步如下圖所示:
當改用 EDS 之後,當叢集中的每一個 Eureka Server 向叢集中的其他 Eureka Server 發起資料同步時,這些請求被請求方 Pod 中的 Envoy Sidecar 採用 Round Robin 進行了隨機分發,導致同步訊息發生了紊亂,叢集中每個伺服器中的服務註冊訊息不一致,導致某些服務被誤判下線。該故障現象比較隨機,經過多次測試,我們發現在 Eureka 中註冊的服務較多時更容易出現改故障,當只有少量服務時不容易復現。
找到原因後,要解決該問題就很簡單了,我們可以通過將 Eureka Server 的 Sidecar Injection 設定為 false 來規避該問題,如下面的 yaml 片段所示:
apiVersion: apps/v1
kind: StatefulSet
metadata:
name: eureka-server
spec:
selector:
matchLabels:
app: eureka-server
serviceName: "eureka-server"
replicas: 3
template:
metadata:
labels:
app: eureka-server
annotations:
sidecar.istio.io/inject: "false" # 不為 eureka-server pod 注入 Envoy Siedecar
spec:
containers:
- name: eureka-server
image: zhaohuabing/eureka-test-service:latest
ports:
- containerPort: 8761
name: http
反思
對於 Headless Service,Istio 預設採用 “ORIGINAL_DST” 型別的 Cluster,要求 Envoy Sidecar 在轉發時採用請求原始目的 IP 地址的行為其實是合理的。如同我們在本系列的上一篇文章『Istio 運維實戰系列(2):讓人頭大的『無頭服務』-上』所介紹的,Headless Service 一般用於定義有狀態的服務。對於有狀態的服務,需要由客戶端根據應用特定的演算法來自行決定訪問哪一個後端 Pod,因此不應該在這些 Pod 前加一個負載均衡器。
在本例中,由於 Eureka 叢集中各個節點之間會對收到的客戶端服務心跳通知進行同步,因此對於客戶端來說,將心跳通知傳送到哪一個 Eureka 節點並不重要,我們可以認為 Eureka 叢集對於外部客戶端而言是無狀態的。因此設定 PILOT_ENABLE_EDS_FOR_HEADLESS_SERVICES 環境變數,在客戶端的 Envoy Sidecar 中對客戶端發往 Eureka Server 的請求進行負載均衡是沒有問題的。但是由於 Eureka 叢集內部的各個節點之間的是有狀態的,修改後影響了叢集中各個 Eureka 節點之間的資料同步,導致了後面部分服務錯誤下線的問題。對於引發的該問題,我們通過去掉 Eureka Server 的 Sidecar 注入來進行了規避。
對於該問題,更合理的處理方法是 Envoy Sidecar 在嘗試連線 Upstream Host 失敗一定次數後主動斷開和客戶端側的連結,由客戶端重新查詢 DNS,獲取正確的 Pod IP 來建立新的連結。經過測試驗證,Istio 1.6 及之後的版本中,Envoy 在 Upstream 連結斷開後會主動斷開和 Downstream 的長連結,建議儘快升級到 1.6 版本,以徹底解決本問題。也可以直接採用騰訊雲上的雲原生 Service Mesh 服務 TCM(Tencent Cloud Mesh),為微服務應用快速引入 Service Mesh 的流量管理和服務治理能力,而無需再關注 Service Mesh 基礎設施自身的安裝、維護、升級等事項。
參考文件
- All about ISTIO-PROXY 5xx Issues
- Service Discovery: Eureka Server
- Istio 運維實戰系列(2):讓人頭大的『無頭服務』-上
- Eureka 心跳通知問題測試原始碼
【騰訊雲原生】雲說新品、雲研新術、雲遊新活、雲賞資訊,掃碼關注同名公眾號,及時獲取更多幹貨!!