在 Istio 中除錯 503 錯誤

米開朗基楊發表於2019-03-31
除錯

原文連結：Istio, mTLS, debugging a 503 error
譯者：楊傳勝

大家好，本文我將與你們分享我在 Istio 官方文件中嘗試熔斷教程時遇到的問題。我會記錄下解決此問題的所有步驟，希望對你們有所幫助。至少對我自己來說，在整個排錯過程中學到了很多關於 Istio 的知識。

我的實踐步驟非常簡單，總共分為兩步：

  1. 部署兩個應用（一個 httpbin 示例應用 + 一個帶有命令列工具 curl 的客戶端）
  2. 建立一個 目標規則以限制對 httpbin 服務的呼叫（熔斷）

是不是非常簡單？讓我們開始吧！

首先安裝 httpbin 服務和客戶端：

$ kubectl create ns foo
$ kubectl apply -f <(istioctl kube-inject -f samples/httpbin/httpbin.yaml) -n foo
$ kubectl apply -f <(istioctl kube-inject -f samples/sleep/sleep.yaml) -n foo
 
$ kubectl -n foo get pod,svc

NAME                           READY     STATUS    RESTARTS   AGE
pod/httpbin-6bbb775889-wcp45   2/2       Running   0          35s
pod/sleep-5b597748b4-77kj5     2/2       Running   0          35s
 
NAME              TYPE        CLUSTER-IP     EXTERNAL-IP   PORT(S)    AGE
service/httpbin   ClusterIP   10.105.25.98           8000/TCP   36s
service/sleep     ClusterIP   10.111.0.72            80/TCP     35s
複製程式碼

接下來就登入客戶端 Pod 並使用 curl 來呼叫 httpbin：

$ kubectl -n foo exec -it -c sleep sleep-5b597748b4-77kj5 -- curl http://httpbin:8000/get
複製程式碼
{
  "args": {}, 
  "headers": {
    "Accept": "*/*", 
    "Content-Length": "0", 
    "Host": "httpbin:8000", 
    "User-Agent": "curl/7.35.0", 
    "X-B3-Sampled": "1", 
    "X-B3-Spanid": "b5d006d3d9bf1f4d", 
    "X-B3-Traceid": "b5d006d3d9bf1f4d", 
    "X-Request-Id": "970b84b2-999b-990c-91b4-b6c8d2534e77"
  }, 
  "origin": "127.0.0.1", 
  "url": "http://httpbin:8000/get"
}
複製程式碼

到目前為止一切正常。下面建立一個目標規則針對 httpbin 服務設定斷路器：

$ cat <<EOF | kubectl -n foo apply -f -
apiVersion: networking.istio.io/v1alpha3
kind: DestinationRule
metadata:
  name: httpbin
spec:
  host: httpbin
  trafficPolicy:
    connectionPool:
      tcp:
        maxConnections: 1
      http:
        http1MaxPendingRequests: 1
        maxRequestsPerConnection: 1
    outlierDetection:
      consecutiveErrors: 1
      interval: 1s
      baseEjectionTime: 3m
      maxEjectionPercent: 100
EOF
複製程式碼

現在嘗試再次呼叫 httpbin 服務：

$ kubectl -n foo exec -it -c sleep sleep-5b597748b4-77kj5 -- curl http://httpbin:8000/get

upstream connect error or disconnect/reset before headers
複製程式碼

哎呀出事了！我們可以讓 curl 輸出更加詳細的資訊：

$ kubectl -n foo exec -it -c sleep sleep-5b597748b4-77kj5 -- curl -v http://httpbin:8000/get

* Hostname was NOT found in DNS cache
*   Trying 10.105.235.142...
* Connected to httpbin (10.105.235.142) port 8000 (#0)
> GET /get HTTP/1.1
> User-Agent: curl/7.35.0
> Host: httpbin:8000
> Accept: */*
> 
< HTTP/1.1 503 Service Unavailable
< content-length: 57
< content-type: text/plain
< date: Tue, 28 Aug 2018 12:26:54 GMT
* Server envoy is not blacklisted
< server: envoy
< 
* Connection #0 to host httpbin left intact
upstream connect error or disconnect/reset before headers
複製程式碼

發現了 503 錯誤。。。為什麼呢？根據剛剛建立的 DestinationRule，應該可以成功呼叫 httpbin 服務的。因為我們將 TCP 連線的最大數量設定為 1，而 curl 命令只生成了一個連線。那麼到底哪裡出問題了呢？

我能想到的第一件事就是通過查詢 istio-proxy 的狀態來驗證熔斷策略是否生效：

$ kubectl -n foo exec -it -c istio-proxy sleep-5b597748b4-77kj5 -- curl localhost:15000/stats | grep httpbin | grep pending

cluster.outbound|8000||httpbin.foo.svc.cluster.local.upstream_rq_pending_active: 0
cluster.outbound|8000||httpbin.foo.svc.cluster.local.upstream_rq_pending_failure_eject: 0
cluster.outbound|8000||httpbin.foo.svc.cluster.local.upstream_rq_pending_overflow: 0
cluster.outbound|8000||httpbin.foo.svc.cluster.local.upstream_rq_pending_total: 5
複製程式碼

upstream_rq_pending_overflow 的值是 0，說明沒有任何呼叫被標記為熔斷。

Istio sidecar（名為 istio-proxy 的 Envoy 容器）暴露出 15000 埠以提供一些實用的功能，可以通過 HTTP 訪問這個埠，例如列印相關服務的一些統計資訊。

因此，在上面的的命令中，我們在客戶端 Pod（sleep-5b597748b4-77kj5）的 sidecar 容器（-c istio-proxy）中執行 curl（curl localhost:15000/stats），過濾出我們要檢查的服務的統計資訊（| grep httpbin），然後過濾出熔斷器掛起狀態（| grep pending）。

為了確認 DestinationRule 才是罪魁禍首，我決定將它刪除然後再嘗試呼叫：

$ kubectl -n foo delete DestinationRule httpbin

destinationrule.networking.istio.io "httpbin" deleted


$ kubectl -n foo exec -it -c sleep sleep-5b597748b4-77kj5 -- curl -v http://httpbin:8000/get

...
< HTTP/1.1 200 OK
...
複製程式碼

再將該 DestinationRule 加回來，然後再次嘗試呼叫：

...
< HTTP/1.1 503 Service Unavailable
...
複製程式碼

看來問題確實出在 DestinationRule 這裡，但是還是不知道為什麼，我們需要進一步研究。我靈機一動，要不先來看看 Envoy（istio-proxy sidecar）的日誌吧：

$ kubectl -n foo logs -f sleep-5b597748b4-77kj5 -c istio-proxy

# 在另一個終端執行以下命令 (kubectl -n foo exec -it -c sleep sleep-5b597748b4-77kj5 -- curl -v http://httpbin:8000/get)
# 然後會輸出下面的日誌：

[2018-08-28T13:06:56.454Z] "GET /get HTTP/1.1" 503 UC 0 57 0 - "-" "curl/7.35.0" "19095d07-320a-9be0-8ba5-e0d08cf58f52" "httpbin:8000" "172.17.0.14:8000"
複製程式碼

並沒有看到什麼有用的資訊。日誌告訴我們 Envoy 從伺服器收到了 503 錯誤，OK，那我們就來檢查一下伺服器端（httpbin）的日誌：

$ kubectl -n foo logs -f httpbin-94fdb8c79-h9zrq -c istio-proxy
# 在另一個終端執行以下命令 (kubectl -n foo exec -it -c sleep sleep-5b597748b4-77kj5 -- curl -v http://httpbin:8000/get)
# 日誌輸出為空
複製程式碼

什麼？日誌輸出中竟然沒有任何內容，就好像請求根本沒有到達伺服器一樣。那麼現在該怎麼辦呢，可不可以增加日誌輸出等級？也許請求已經收到了，只是沒有被輸出而已。

還記得我上面講過的 Envoy 暴露了 15000 埠作為管理介面嗎？我們可以用它來獲取統計資料。看看它都提供了哪些功能：

$ kubectl -n foo exec -it -c istio-proxy httpbin-94fdb8c79-h9zrq -- curl http://localhost:15000/help

admin commands are:
  /: Admin home page
  /certs: print certs on machine
...
  /logging: query/change logging levels
...
複製程式碼

嘿嘿，似乎找到了我們需要的東西：/logging，試試吧：

$ kubectl -n foo exec -it -c istio-proxy httpbin-94fdb8c79-h9zrq -- curl http://localhost:15000/logging?level=trace

active loggers:
  admin: trace
...
複製程式碼

上面的命令將伺服器 Envoy 的日誌等級設為 trace，該日誌等級輸出的日誌資訊最詳細。關於管理介面的更多資訊，請檢視 Envoy 官方文件。現在我們再來重新檢視伺服器 Envoy 的日誌，希望能夠得到一些有用的資訊：

$ kubectl -n foo logs -f httpbin-94fdb8c79-h9zrq -c istio-proxy

# 在另一個終端執行以下命令 (kubectl -n foo exec -it -c sleep sleep-5b597748b4-77kj5 -- curl -v http://httpbin:8000/get)
# 然後會輸出下面的日誌：（我過濾了一些不相關的內容）

[debug][filter] external/envoy/source/extensions/filters/listener/original_dst/original_dst.cc:18] original_dst: New connection accepted
[debug][main] external/envoy/source/server/connection_handler_impl.cc:217] [C31] new connection
[trace][connection] external/envoy/source/common/network/connection_impl.cc:389] [C31] socket event: 2
[trace][connection] external/envoy/source/common/network/connection_impl.cc:457] [C31] write ready
[debug][connection] external/envoy/source/common/ssl/ssl_socket.cc:111] [C31] handshake error: 2
[trace][connection] external/envoy/source/common/network/connection_impl.cc:389] [C31] socket event: 3
[trace][connection] external/envoy/source/common/network/connection_impl.cc:457] [C31] write ready
[debug][connection] external/envoy/source/common/ssl/ssl_socket.cc:111] [C31] handshake error: 1
[debug][connection] external/envoy/source/common/ssl/ssl_socket.cc:139] [C31] SSL error: 268435612:SSL routines:OPENSSL_internal:HTTP_REQUEST
[debug][connection] external/envoy/source/common/network/connection_impl.cc:133] [C31] closing socket: 0
複製程式碼

現在我們可以看到請求確實已經到達伺服器了，但由於握手錯誤導致了請求失敗，並且 Envoy 正在關閉連線。現在的問題是：為什麼會發生握手錯誤？為什麼會涉及到 SSL？

當在 Istio 中談到 SSL 時，一般指的是雙向 TLS。然後我就去檢視 Istio 官方文件，檢視找到與我的問題相關的內容，最後終於在 基礎認證策略 這篇文件中找到了我想要的東西。

我發現我在部署 Istio 時啟用了 Sidecar 之間的雙向 TLS 認證！

檢查一下：

$ kubectl get MeshPolicy default -o yaml

apiVersion: authentication.istio.io/v1alpha1
kind: MeshPolicy
metadata: ...
spec:
  peers:
  - mtls: {}

 
$ kubectl -n istio-system get DestinationRule default -o yaml

apiVersion: networking.istio.io/v1alpha3
kind: DestinationRule
metadata: ...
spec:
  host: '*.local'
  trafficPolicy:
    tls:
      mode: ISTIO_MUTUAL
複製程式碼

上面這些輸出表明叢集中開啟了雙向 TLS 認證，因為這些全域性身份驗證策略和目標規則只有在開啟雙向 TLS 認證時才會存在。

再回到最初的問題：為什麼呼叫 httpbin 服務會失敗？現在我們已經知道了網格中開啟了雙向 TLS 認證，通過閱讀文件可以推斷出伺服器端僅接受使用 TLS 的加密請求，而客戶端仍在使用明文請求。現在來重新修改一個問題：為什麼客戶端（sleep pod）會使用明文來請求伺服器端（httpbin pod）？

再次仔細閱讀官方文件可以找到答案。雙向 TLS 認證（mTLS）在 Istio 中的工作方式很簡單：它會建立一個預設的 DestinationRule 物件（名稱為 default），它表示網格中的所有客戶端都使用雙向 TLS。但是當我們為了實現熔斷策略建立自己的 DestinationRule 時，用自己的配置（根本就沒有設定 TLS！）覆蓋了預設配置。

這是 基礎認證策略 文件中的原文：

除了認證場合之外，目標規則還有其它方面的應用，例如金絲雀部署。但是所有的目標規則都適用相同的優先順序。因此，如果一個服務需要配置其它目標規則（例如配置負載均衡），那麼新規則定義中必須包含類似的 TLS 塊來定義 ISTIO_MUTUAL 模式，否則它將覆蓋網格或名稱空間範圍的 TLS 設定並禁用 TLS。

現在知道問題出在哪了，解決辦法就是：修改 DestinationRule 以包含 TLS 配置項：

cat <<EOF | kubectl -n foo apply -f -
apiVersion: networking.istio.io/v1alpha3
kind: DestinationRule
metadata:
  name: httpbin
spec:
  host: httpbin
  trafficPolicy:
    connectionPool:
      tcp:
        maxConnections: 1
      http:
        http1MaxPendingRequests: 1
        maxRequestsPerConnection: 1
    outlierDetection:
      consecutiveErrors: 1
      interval: 1s
      baseEjectionTime: 3m
      maxEjectionPercent: 100
    tls:
      mode: ISTIO_MUTUAL
EOF
複製程式碼

再次嘗試呼叫 httpbin 服務：

kubectl -n foo exec -it -c sleep sleep-5b597748b4-77kj5 -- curl -v http://httpbin:8000/get

...
< HTTP/1.1 200 OK
...
複製程式碼

現在我可以繼續實驗熔斷教程了！

總結：

  • 確認是否啟用了 mTLS，如果啟用了可能會遇到很多錯誤。
  • 所有的目標規則都適用相同的優先順序，具體的規則會覆蓋全域性的規則。
  • 有時候可以充分利用 Sidecar 的管理介面（本地埠 15000）。
  • 仔細閱讀官方文件。

相關文章