<關注公眾號，回復“排查”獲取下載鏈接>

《深入淺出 Kubernetes》開放下載

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

本書共有以下四大亮點：

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

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

（本書目錄）

如何免費下載？

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

前言

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

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

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

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

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

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

問題現象

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

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

大邏輯

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

一方面，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 狀態。

就緒三分鐘

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

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

• 一方面，kubelet 作為集群控制器，從 API Server 處獲取 pod spec changes，然后通過創建 worker 線程來創建或結束掉 pod；
• 另外一方面，PLEG 定期檢查容器狀態，然后把狀態，以事件的形式反饋給 kubelet。

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

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

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

止步不前的 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 接口的插件。

而在上一節最后，我們看到的問題，是 kubelet 調用 CNI terway 去配置 pod 網絡的時候，Terway 長時間無響應。正常情況下這個操作應該是秒級的，非?？焖?。而出問題的時候，Terway 沒有正常完成任務，因而我們在集群節點上看到大量 terway 進程堆積。

同樣的，我們可以發送 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 甚至節點的狀態。

<關注公眾號，回復?排查?即可下載本書>

“阿里巴巴云原生關注微服務、Serverless、容器、Service Mesh 等技術領域、聚焦云原生流行技術趨勢、云原生大規模的落地實踐，做最懂云原生開發者的技術圈。”

總結

以上是生活随笔為你收集整理的电子书下载 | 超实用！阿里售后专家的 K8s 问题排查案例合集的全部內容，希望文章能夠幫你解決所遇到的問題。

如果覺得生活随笔網站內容還不錯，歡迎將生活随笔推薦給好友。