在 Istio 中調試 503 錯誤

原文連接：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）。
• 仔細閱讀官方文檔。