![書.png](https://ucc.alicdn.com/pic/developer-ecology/128d1d02e6b44381ac561ec28c820d19.png)

****

# 《深入淺出 Kubernetes》開放下載

本書作者**羅建龍**（花名**聲東**），阿里雲技術專家，有著多年作業系統和圖形顯示卡驅動除錯和開發經驗。目前專注雲原生領域，容器叢集和服務網格。本書分為理論篇和實踐篇，共彙集了 12 篇技術文章，深入解析了叢集控制、叢集伸縮原理、映象拉取等理論，帶你實現從基礎概念的準確理解到上手實操的精準熟練，深入淺出使用 Kubernetes！

本書共有以下四大亮點：

- 線上海量真實案例的沉澱
- 理論和實踐的完美契合
- 理論闡述深入淺出
- 技術細節追根究底

幫助你一次搞懂 6 個核心原理，吃透基礎理論，一次學會 6 個典型問題的華麗操作！

![目錄.png](https://ucc.alicdn.com/pic/developer-ecology/41403e275fad401580c505c409803ee6.png)
（本書目錄）

## 如何免費下載？

關注“阿里巴巴雲原生”，回覆 **排查 **，即可免費下載此書。

# 前言

**以下內容節選自《深入淺出 Kubernetes》一書。**

阿里雲有自己的 Kubernetes 容器叢集產品。隨著 Kubernetes 叢集出貨量的劇增，線上使用者零星的發現，叢集會非常低機率地出現節點 NotReady 情況。

據我們觀察，這個問題差不多每個月就會有一到兩個客戶遇到。在節點 NotReady 之後，叢集 Master 沒有辦法對這個節點做任何控制，比如下發新的 Pod，再比如抓取節點上正在執行 Pod 的實時資訊。

在上面的問題中，我們的排查路徑從 K8s 叢集到容器執行時，再到 sdbus 和 systemd，不可謂不復雜。這個問題目前已經在 systemd 中做了修復，所以基本上能看到這個問題的機率是越來越低了。

但是，叢集節點就緒問題還是有的，然而原因卻有所不同。

今天這篇文章，將側重和大家分享另外一例叢集節點 NotReady 的問題。這個問題和上面問題相比，排查路徑完全不同。

# 問題現象

這個問題的現象，也是叢集節點會變成 NotReady 狀態。問題可以透過重啟節點暫時解決，但是在經過大概 20 天左右之後，問題會再次出現。

![1.png](https://ucc.alicdn.com/pic/developer-ecology/9d5e2ccce426454198d97d35db22f275.png)

問題出現之後，如果我們重啟節點上 kubelet，則節點會變成 Ready 狀態，但這種狀態只會持續三分鐘。這是一個特別的情況。

# 大邏輯

在具體分析這個問題之前，我們先來看一下叢集節點就緒狀態背後的大邏輯。K8s 叢集中，與節點就緒狀態有關的元件，主要有四個，分別是：叢集的核心資料庫 etcd、叢集的入口 API Server、節點控制器以及駐守在叢集節點上直接管理節點的 kubelet。

![2.png](https://ucc.alicdn.com/pic/developer-ecology/312407876f7741b6b74e4fe5b3c55533.png)

一方面，kubelet 扮演的是叢集控制器的角色，它定期從 API Server 獲取 Pod 等相關資源的資訊，並依照這些資訊，控制執行在節點上 Pod 的執行；另外一方面，kubelet 作為節點狀況的監視器，它獲取節點資訊，並以叢集客戶端的角色，把這些狀況同步到 API Server。

在這個問題中，kubelet 扮演的是第二種角色。

Kubelet 會使用上圖中的 NodeStatus 機制，定期檢查叢集節點狀況，並把節點狀況同步到 API Server。而 NodeStatus 判斷節點就緒狀況的一個主要依據，就是 PLEG。

PLEG是Pod Lifecycle Events Generator的縮寫，基本上它的執行邏輯，是定期檢查節點上Pod執行情況，如果發現感興趣的變化，PLEG 就會把這種變化包裝成 Event 傳送給 Kubelet 的主同步機制 syncLoop 去處理。但是，在 PLEG 的 Pod 檢查機制不能定期執行的時候，NodeStatus 機制就會認為，這個節點的狀況是不對的，從而把這種狀況同步到 API Server。

而最終把 kubelet 上報的節點狀況，落實到節點狀態的是節點控制這個元件。這裡我故意區分了 kubelet 上報的節點狀況，和節點的最終狀態。因為前者，其實是我們 describe node 時看到的 Condition，而後者是真正節點列表裡的 NotReady 狀態。

![3.png](https://ucc.alicdn.com/pic/developer-ecology/b722a7351c4847cab34d6fb72698caa7.png)

# 就緒三分鐘

在問題發生之後，我們重啟 kubelet，節點三分鐘之後才會變成 NotReady 狀態。這個現象是問題的一個關鍵切入點。

![4.png](https://ucc.alicdn.com/pic/developer-ecology/714416b290cd4ae3aaf3abc1cdc51fac.png)

在解釋它之前，請大家看一下官方這張 PLEG 示意圖。這個圖片主要展示了兩個過程。

- 一方面，kubelet 作為叢集控制器，從 API Server 處獲取 pod spec changes，然後透過建立 worker 執行緒來建立或結束掉 pod；
- 另外一方面，PLEG 定期檢查容器狀態，然後把狀態，以事件的形式反饋給 kubelet。

在這裡，PLEG 有兩個關鍵的時間引數：一個是檢查的執行間隔，另外一個是檢查的超時時間。以預設情況為準，PLEG 檢查會間隔一秒，換句話說，每一次檢查過程執行之後，PLEG 會等待一秒鐘，然後進行下一次檢查；而每一次檢查的超時時間是三分鐘，如果一次 PLEG 檢查操作不能在三分鐘內完成，那麼這個狀況，會被上一節提到的 NodeStatus 機制，當做叢集節點 NotReady 的憑據，同步給 API Server。

而我們之所以觀察到節點會在重啟 kubelet 之後就緒三分鐘，是因為 kubelet 重啟之後，第一次 PLEG 檢查操作就沒有順利結束。節點就緒狀態，直到三分鐘超時之後，才被同步到叢集。

如下圖，上邊一行表示正常情況下 PLEG 的執行流程，下邊一行則表示有問題的情況。relist 是檢查的主函式。

![5.png](https://ucc.alicdn.com/pic/developer-ecology/c567f0ad4074443d819b10c5639ccbe0.png)

# 止步不前的 PLEG

瞭解了原理，我們來看一下 PLEG 的日誌。日誌基本上可以分為兩部分，其中 skipping pod synchronization 這部分是 kubelet 同步函式 syncLoop 輸出的，說明它跳過了一次 pod 同步；而剩餘 PLEG is not healthy: pleg was last seen active ago; threshold is 3m0s，則很清楚的展現了，上一節提到的 relist 超時三分鐘的問題。

```
17:08:22.299597 kubelet skipping pod synchronization - [PLEG is not healthy: pleg was last seen active 3m0.000091019s ago; threshold is 3m0s]
17:08:22.399758 kubelet skipping pod synchronization - [PLEG is not healthy: pleg was last seen active 3m0.100259802s ago; threshold is 3m0s]
17:08:22.599931 kubelet skipping pod synchronization - [PLEG is not healthy: pleg was last seen active 3m0.300436887s ago; threshold is 3m0s]
17:08:23.000087 kubelet skipping pod synchronization - [PLEG is not healthy: pleg was last seen active 3m0.700575691s ago; threshold is 3m0s]
17:08:23.800258 kubelet skipping pod synchronization - [PLEG is not healthy: pleg was last seen active 3m1.500754856s ago; threshold is 3m0s]
17:08:25.400439 kubelet skipping pod synchronization - [PLEG is not healthy: pleg was last seen active 3m3.100936232s ago; threshold is 3m0s]
17:08:28.600599 kubelet skipping pod synchronization - [PLEG is not healthy: pleg was last seen active 3m6.301098811s ago; threshold is 3m0s]
17:08:33.600812 kubelet skipping pod synchronization - [PLEG is not healthy: pleg was last seen active 3m11.30128783s ago; threshold is 3m0s]
17:08:38.600983 kubelet skipping pod synchronization - [PLEG is not healthy: pleg was last seen active 3m16.301473637s ago; threshold is 3m0s]
17:08:43.601157 kubelet skipping pod synchronization - [PLEG is not healthy: pleg was last seen active 3m21.301651575s ago; threshold is 3m0s]
17:08:48.601331 kubelet skipping pod synchronization - [PLEG is not healthy: pleg was last seen active 3m26.301826001s ago; threshold is 3m0s]
```
能直接看到 relist 函式執行情況的，是 kubelet 的呼叫棧。我們只要向 kubelet 程式傳送 SIGABRT 訊號，golang 執行時就會幫我們輸出 kubelet 程式的所有呼叫棧。需要注意的是，這個操作會殺死 kubelet 程式。但是因為這個問題中，重啟 kubelet 並不會破壞重現環境，所以影響不大。

以下呼叫棧是 PLEG relist 函式的呼叫棧。從下往上，我們可以看到，relist 等在透過 grpc 獲取 PodSandboxStatus。

```
kubelet: k8s.io/kubernetes/vendor/google.golang.org/grpc/transport.(*Stream).Header()
kubelet: k8s.io/kubernetes/vendor/google.golang.org/grpc.recvResponse()
kubelet: k8s.io/kubernetes/vendor/google.golang.org/grpc.invoke()
kubelet: k8s.io/kubernetes/vendor/google.golang.org/grpc.Invoke()
kubelet: k8s.io/kubernetes/pkg/kubelet/apis/cri/runtime/v1alpha2.(*runtimeServiceClient).PodSandboxStatus()
kubelet: k8s.io/kubernetes/pkg/kubelet/remote.(*RemoteRuntimeService).PodSandboxStatus()
kubelet: k8s.io/kubernetes/pkg/kubelet/kuberuntime.instrumentedRuntimeService.PodSandboxStatus()
kubelet: k8s.io/kubernetes/pkg/kubelet/kuberuntime.(*kubeGenericRuntimeManager).GetPodStatus()
kubelet: k8s.io/kubernetes/pkg/kubelet/pleg.(*GenericPLEG).updateCache()
kubelet: k8s.io/kubernetes/pkg/kubelet/pleg.(*GenericPLEG).relist()
kubelet: k8s.io/kubernetes/pkg/kubelet/pleg.(*GenericPLEG).(k8s.io/kubernetes/pkg/kubelet/pleg.relist)-fm()
kubelet: k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.JitterUntil.func1(0xc420309260)
kubelet: k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.JitterUntil()
kubelet: k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.Until()
```

使用 PodSandboxStatus 搜尋 kubelet 呼叫棧，很容易找到下邊這個執行緒，此執行緒是真正查詢 Sandbox 狀態的執行緒，從下往上看，我們會發現這個執行緒在 Plugin Manager 裡嘗試去拿一個 Mutex。

```
kubelet: sync.runtime_SemacquireMutex()kubelet: sync.(*Mutex).Lock()
kubelet: k8s.io/kubernetes/pkg/kubelet/dockershim/network.(*PluginManager).GetPodNetworkStatus()
kubelet: k8s.io/kubernetes/pkg/kubelet/dockershim.(*dockerService).getIPFromPlugin()
kubelet: k8s.io/kubernetes/pkg/kubelet/dockershim.(*dockerService).getIP()
kubelet: k8s.io/kubernetes/pkg/kubelet/dockershim.(*dockerService).PodSandboxStatus()
kubelet: k8s.io/kubernetes/pkg/kubelet/apis/cri/runtime/v1alpha2._RuntimeService_PodSandboxStatus_Handler()
kubelet: k8s.io/kubernetes/vendor/google.golang.org/grpc.(*Server).processUnaryRPC()
kubelet: k8s.io/kubernetes/vendor/google.golang.org/grpc.(*Server).handleStream()
kubelet: k8s.io/kubernetes/vendor/google.golang.org/grpc.(*Server).serveStreams.func1.1()
kubelet: created by k8s.io/kubernetes/vendor/google.golang.org/grpc.(*Server).serveStreams.func1
```

而這個 Mutex 只有在 Plugin Manager 裡邊有用到，所以我們檢視所有 Plugin Manager 相關的呼叫棧。執行緒中一部分在等 Mutex，而剩餘的都是在等 Terway cni plugin。

```
kubelet: syscall.Syscall6()kubelet: os.(*Process).blockUntilWaitable()
kubelet: os.(*Process).wait()kubelet: os.(*Process).Wait()
kubelet: os/exec.(*Cmd).Wait()kubelet: os/exec.(*Cmd).Run()
kubelet: k8s.io/kubernetes/vendor/github.com/containernetworking/cni/pkg/invoke.(*RawExec).ExecPlugin()
kubelet: k8s.io/kubernetes/vendor/github.com/containernetworking/cni/pkg/invoke.(*PluginExec).WithResult()
kubelet: k8s.io/kubernetes/vendor/github.com/containernetworking/cni/pkg/invoke.ExecPluginWithResult()
kubelet: k8s.io/kubernetes/vendor/github.com/containernetworking/cni/libcni.(*CNIConfig).AddNetworkList()
kubelet: k8s.io/kubernetes/pkg/kubelet/dockershim/network/cni.(*cniNetworkPlugin).addToNetwork()
kubelet: k8s.io/kubernetes/pkg/kubelet/dockershim/network/cni.(*cniNetworkPlugin).SetUpPod()
kubelet: k8s.io/kubernetes/pkg/kubelet/dockershim/network.(*PluginManager).SetUpPod()
kubelet: k8s.io/kubernetes/pkg/kubelet/dockershim.(*dockerService).RunPodSandbox()
kubelet: k8s.io/kubernetes/pkg/kubelet/apis/cri/runtime/v1alpha2._RuntimeService_RunPodSandbox_Handler()
kubelet: k8s.io/kubernetes/vendor/google.golang.org/grpc.(*Server).processUnaryRPC()
kubelet: k8s.io/kubernetes/vendor/google.golang.org/grpc.(*Server).handleStream()
kubelet: k8s.io/kubernetes/vendor/google.golang.org/grpc.(*Server).serveStreams.func1.1()
```

# 無響應的 Terwayd

在進一步解釋這個問題之前，我們需要區分下 Terway 和 Terwayd。本質上來說，Terway 和 Terwayd 是客戶端伺服器的關係，這跟 flannel 和 flanneld 之間的關係是一樣的。Terway 是按照 kubelet 的定義，實現了 cni 介面的外掛。

![6.png](https://ucc.alicdn.com/pic/developer-ecology/3458a789297e419285c1f1802d6afe9e.png)

而在上一節最後，我們看到的問題，是 kubelet 呼叫 CNI terway 去配置 pod 網路的時候，Terway 長時間無響應。正常情況下這個操作應該是秒級的，非常快速。而出問題的時候，Terway 沒有正常完成任務，因而我們在叢集節點上看到大量 terway 程式堆積。

![7.png](https://ucc.alicdn.com/pic/developer-ecology/615e141069e14f2b9390ce3a01f7b67f.png)

同樣的，我們可以傳送 SIGABRT 給這些 terway 外掛程式，來列印出程式的呼叫棧。下邊是其中一個 terway 的呼叫棧。這個執行緒在執行 cmdDel 函式，其作用是刪除一個 pod 網路相關配置。

```
kubelet: net/rpc.(*Client).Call()
kubelet: main.rpcCall()kubelet: main.cmdDel()
kubelet: github.com/AliyunContainerService/terway/vendor/github.com/containernetworking/cni/pkg/skel.(*dispatcher).checkVersionAndCall()
kubelet: github.com/AliyunContainerService/terway/vendor/github.com/containernetworking/cni/pkg/skel.(*dispatcher).pluginMain()
kubelet: github.com/AliyunContainerService/terway/vendor/github.com/containernetworking/cni/pkg/skel.PluginMainWithError()
kubelet: github.com/AliyunContainerService/terway/vendor/github.com/containernetworking/cni/pkg/skel.PluginMain()
```

以上執行緒透過 rpc 呼叫 terwayd，來真正的移除 pod 網路。所以我們需要進一步排查 terwayd 的呼叫棧來進一步定位此問題。Terwayd 作為 Terway 的伺服器端，其接受 Terway 的遠端呼叫，並替 Terway 完成其 cmdAdd 或者 cmdDel 來建立或者移除 pod 網路配置。

我們在上邊的截圖裡可以看到，叢集節點上有成千 Terway 程式，他們都在等待 Terwayd，所以實際上 Terwayd 裡，也有成千的執行緒在處理 Terway 的請求。

使用下邊的命令，可以在不重啟 Terwayd 的情況下，輸出呼叫棧。

```
curl  --unix-socket /var/run/eni/eni.socket 'http:/debug/pprof/goroutine?debug=2'
```

因為 Terwayd 的呼叫棧非常複雜，而且幾乎所有的執行緒都在等鎖，直接去分析鎖的等待持有關係比較複雜。這個時候我們可以假設最早進入等待狀態的執行緒，大機率是持有鎖的執行緒。

經過呼叫棧和程式碼分析，我們發現下邊這個是等待時間最長（1595 分鐘），且拿了鎖的執行緒。而這個鎖會 block 所有建立或者銷燬 pod 網路的執行緒。

```
goroutine 67570 [syscall, 1595 minutes, locked to thread]:
syscall.Syscall6()
github.com/AliyunContainerService/terway/vendor/golang.org/x/sys/unix.recvfrom()
github.com/AliyunContainerService/terway/vendor/golang.org/x/sys/unix.Recvfrom()
github.com/AliyunContainerService/terway/vendor/github.com/vishvananda/netlink/nl.(*NetlinkSocket).Receive()
github.com/AliyunContainerService/terway/vendor/github.com/vishvananda/netlink/nl.(*NetlinkRequest).Execute()
github.com/AliyunContainerService/terway/vendor/github.com/vishvananda/netlink.(*Handle).LinkSetNsFd()
github.com/AliyunContainerService/terway/vendor/github.com/vishvananda/netlink.LinkSetNsFd()
github.com/AliyunContainerService/terway/daemon.SetupVethPair()github.com/AliyunContainerService/terway/daemon.setupContainerVeth.func1()
github.com/AliyunContainerService/terway/vendor/github.com/containernetworking/plugins/pkg/ns.(*netNS).Do.func1()
github.com/AliyunContainerService/terway/vendor/github.com/containernetworking/plugins/pkg/ns.(*netNS).Do.func2()
```

原因深入分析前一個執行緒的呼叫棧，我們可以確定三件事情。

- 第一，Terwayd 使用了 netlink 這個庫來管理節點上的虛擬網路卡，IP 地址及路由等資源，且 netlink 實現了類似 iproute2 的功能；
- 第二，netlink 使用 socket 直接和核心通訊；
- 第三，以上執行緒等在 recvfrom 系統呼叫上。

這樣的情況下，我們需要去檢視這個執行緒的核心呼叫棧，才能進一步確認這個執行緒等待的原因。因為從 goroutine 執行緒號比較不容易找到這個執行緒的系統執行緒 id，這裡我們透過抓取系統的 core dump 來找出上邊執行緒的核心呼叫棧。

在核心呼叫棧中，搜尋 recvfrom，定位到下邊這個執行緒。基本上從下邊的呼叫棧上，我們只能確定，此執行緒等在 recvfrom 函式上。

```
PID: 19246  TASK: ffff880951f70fd0  CPU: 16  COMMAND: "terwayd" 
#0 [ffff880826267a40] __schedule at ffffffff816a8f65 
#1 [ffff880826267aa8] schedule at ffffffff816a94e9 
#2 [ffff880826267ab8] schedule_timeout at ffffffff816a6ff9 
#3 [ffff880826267b68] __skb_wait_for_more_packets at ffffffff81578f80 
#4 [ffff880826267bd0] __skb_recv_datagram at ffffffff8157935f 
#5 [ffff880826267c38] skb_recv_datagram at ffffffff81579403 
#6 [ffff880826267c58] netlink_recvmsg at ffffffff815bb312 
#7 [ffff880826267ce8] sock_recvmsg at ffffffff8156a88f 
#8 [ffff880826267e58] SYSC_recvfrom at ffffffff8156aa08 
#9 [ffff880826267f70] sys_recvfrom at ffffffff8156b2fe
#10 [ffff880826267f80] tracesys at ffffffff816b5212 
(via system_call)
```

這個問題進一步深入排查，是比較困難的，這顯然是一個核心問題，或者核心相關的問題。我們翻遍了整個核心 core，檢查了所有的執行緒呼叫棧，看不到其它可能與這個問題相關聯的執行緒。

# 修復

這個問題的修復基於一個假設，就是 netlink 並不是 100% 可靠的。netlink 可以響應很慢，甚至完全沒有響應。所以我們可以給 netlink 操作增加超時，從而保證就算某一次 netlink 呼叫不能完成的情況下，terwayd 也不會被阻塞。

# 總結

在節點就緒狀態這種場景下，kubelet 實際上實現了節點的心跳機制。kubelet 會定期把節點相關的各種狀態，包括記憶體、PID、磁碟，當然也包括本文中關注的就緒狀態等，同步到叢集管控。kubelet 在監控或者管理叢集節點的過程中，使用了各種外掛來直接操作節點資源。這包括網路、磁碟，甚至容器執行時等外掛，這些外掛的狀況，會直接應用 kubelet 甚至節點的狀態。

****

> “[阿里巴巴雲原生](https://developer.aliyun.com/group/alisoftwaretech/)關注微服務、Serverless、容器、Service Mesh 等技術領域、聚焦雲原生流行技術趨勢、雲原生大規模的落地實踐，做最懂雲原生開發者的技術圈。”

電子書下載 | 超實用！阿里售後專家的 K8s 問題排查案例合集

相關文章