Kubernetes從懵圈到熟練:讀懂這一篇,集羣節點不下線

排查徹底陌生的問題,徹底不熟悉的系統組件,是售後工程師的一大工做樂趣,固然也是挑戰。今天借這篇文章,跟你們分析一例這樣的問題。排查過程當中,須要理解一些本身徹底陌生的組件,好比systemd和dbus。可是排查問題的思路和方法基本上仍是能夠複用了,但願對你們有所幫助。docker

問題一直在發生

I'm NotReady

阿里雲有本身的Kubernetes容器集羣產品。隨着Kubernetes集羣出貨量的劇增,線上用戶零星的發現,集羣會很是低機率地出現節點NotReady狀況。據咱們觀察,這個問題差很少每月,就會有一兩個客戶遇到。在節點NotReady以後,集羣Master沒有辦法對這個節點作任何控制,好比下發新的Pod,再好比抓取節點上正在運行Pod的實時信息。服務器

須要知道的Kubernetes知識

這裏我稍微補充一點Kubernetes集羣的基本知識。Kubernetes集羣的「硬件基礎」,是以單機形態存在的集羣節點。這些節點能夠是物理機,也能夠是虛擬機。集羣節點分爲Master和Worker節點。Master節點主要用來負載集羣管控組件,好比調度器和控制器。而Worker節點主要用來跑業務。Kubelet是跑在各個節點上的代理,它負責與管控組件溝通,並按照管控組件的指示,直接管理Worker節點。cookie

當集羣節點進入NotReady狀態的時候,咱們須要作的第一件事情,確定是檢查運行在節點上的kubelet是否正常。在這個問題出現的時候,使用systemctl命令查看kubelet狀態,發現它做爲systemd管理的一個daemon,是運行正常的。當咱們用journalctl查看kubelet日誌的時候,發現下邊的錯誤。數據結構

什麼是PLEG

這個報錯很清楚的告訴咱們,容器runtime是不工做的,且PLEG是不健康的。這裏容器runtime指的就是docker daemon。Kubelet經過直接操做docker daemon來控制容器的生命週期。而這裏的PLEG,指的是pod lifecycle event generator。PLEG是kubelet用來檢查容器runtime的健康檢查機制。這件事情原本能夠由kubelet使用polling的方式來作。可是polling有其成本上的缺陷,因此PLEG應用而生。PLEG嘗試以一種「中斷」的形式,來實現對容器runtime的健康檢查,雖然實際上,它同時用了polling和」中斷」兩種機制。函數

基本上看到上邊的報錯,咱們能夠確認,容器runtime出了問題。在有問題的節點上,經過docker命令嘗試運行新的容器,命令會沒有響應。這說明上邊的報錯是準確的.工具

容器runtime

Docker Daemon調用棧分析

Docker做爲阿里雲Kubernetes集羣使用的容器runtime,在1.11以後,被拆分紅了多個組件以適應OCI標準。拆分以後,其包括docker daemon,containerd,containerd-shim以及runC。組件containerd負責集羣節點上容器的生命週期管理,並向上爲docker daemon提供gRPC接口。性能

在這個問題中,既然PLEG認爲容器運行是出了問題,咱們須要先從docker daemon進程看起。咱們可使用kill -USR1 <pid>命令發送USR1信號給docker daemon,而docker daemon收到信號以後,會把其全部線程調用棧輸出到文件/var/run/docker文件夾裏。測試

Docker daemon進程的調用棧相對是比較容易分析的。稍微留意,咱們會發現大多數的調用棧都相似下圖中的樣子。經過觀察棧上每一個函數的名字,以及函數所在的文件(模塊)名稱,咱們能夠看到,這個調用棧下半部分,是進程接到http請求,作請求路由的過程;而上半部分則進入實際的處理函數。最終處理函數進入等待狀態,等待的是一個mutex實例。ui

到這裏,咱們須要稍微看一下ContainerInspectCurrent這個函數的實現,而最重要的是,咱們能搞明白,這個函數的第一個參數,就是mutex的指針。使用這個指針搜索整個調用棧文件,咱們會找出,全部等在這個mutex上邊的線程。同時,咱們能夠看到下邊這個線程。阿里雲

這個線程上,函數ContainerExecStart也是在處理具體請求的時候,收到了這個mutex這個參數。但不一樣的是,ContainerExecStart並無在等待mutex,而是已經拿到了mutex的全部權,並把執行邏輯轉向了containerd調用。關於這一點,咱們可使用代碼來驗證。前邊咱們提到過,containerd向上經過gRPC對docker daemon提供接口。此調用棧上半部份內容,正是docker daemon在經過gRPC請求來呼叫containerd。

Containerd調用棧分析

與輸出docker daemon的調用棧相似,咱們能夠經過kill -SIGUSR1 <pid>命令來輸出containerd的調用棧。不一樣的是,此次調用棧會直接輸出到messages日誌。

Containerd做爲一個gRPC的服務器,它會在接到docker daemon的遠程請求以後,新建一個線程去處理此次請求。關於gRPC的細節,咱們這裏其實不用關注太多。在此次請求的客戶端調用棧上,能夠看到此次調用的核心函數是Start一個進程。咱們在containerd的調用棧裏搜索Start,Process以及process.go等字段,很容易發現下邊這個線程。

這個線程的核心任務,就是依靠runC去建立容器進程。而在容器啓動以後,runC進程會退出。因此下一步,咱們天然而然會想到,runC是否是有順利完成本身的任務。查看進程列表,咱們會發現,系統中有個別runC進程,還在執行,這不是預期內的行爲。容器的啓動,跟進程的啓動,耗時應該是差不對的,系統裏有正在運行的runC進程,則說明runC不能正常啓動容器。

什麼是Dbus

RunC請求Dbus

容器runtime的runC命令,是libcontainer的一個簡單的封裝。這個工具能夠用來管理單個容器,好比容器建立,或者容器刪除。在上節的最後,咱們發現runC不能完成建立容器的任務。咱們能夠把對應的進程殺掉,而後在命令行用一樣的命令嘗試啓動容器,同時用strace追蹤整個過程。

分析發現,runC停在了向帶有org.free字段的dbus寫數據的地方。那什麼是dbus呢?在Linux上,dbus是一種進程間進行消息通訊的機制。

緣由並不在Dbus

咱們可使用busctl命令列出系統現有的全部bus。以下圖,在問題發生的時候,我看到客戶集羣節點Name的編號很是大。因此我傾向於認爲,dbus某些相關的數據結構,好比Name,耗盡了引發了這個問題。

Dbus機制的實現,依賴於一個組件叫作dbus-daemon。若是真的是dbus相關數據結構耗盡,那麼重啓這個daemon,應該是能夠解決這個問題。但不幸的是,問題並無這麼直接。重啓dbus-daemon以後,問題依然存在。

在上邊用strace追蹤runC的截圖中,我提到了,runC卡在向帶有org.free字段的bus寫數據的地方。在busctl輸出的bus列表裏,顯然帶有這個字段的bus,都在被systemd使用。這時,咱們用systemctl daemon-reexec來重啓systemd,問題消失了。因此基本上咱們能夠判斷一個方向:問題可能跟systemd有關係。

Systemd是硬骨頭

Systemd是至關複雜的一個組件,尤爲對沒有作過相關開發工做的同窗來講,好比我本身。基本上,排查systemd的問題,我用到了四個方法,(調試級別)日誌,core dump,代碼分析,以及live debugging。其中第一個,第三個和第四個結合起來使用,讓我在通過幾天的鏖戰以後,找到了問題的緣由。可是這裏咱們先從「沒用」的core dump提及。

沒用的Core Dump

由於重啓systemd解決了問題,而這個問題自己,是runC在使用dbus和systemd通訊的時候沒有了響應,因此咱們須要驗證的第一件事情,就是systemd不是有關鍵線程被鎖住了。查看core dump裏全部線程,只有如下一個線程,此線程並無被鎖住,它在等待dbus事件,以便作出響應。

零散的信息

由於機關用盡,因此只能作各類測試、嘗試。使用busctl tree命令,能夠輸出全部bus上對外暴露的接口。從輸出結果看來,org.freedesktop.systemd1這個bus是不能響應接口查詢請求的。

使用下邊的命令,觀察org.freedesktop.systemd1上接受到的因此請求,能夠看到,在正常系統裏,有大量Unit建立刪除的消息,可是有問題的系統裏,這個bus上徹底沒有任何消息。

gdbus monitor --system --dest org.freedesktop.systemd1 --object-path /org/freedesktop/systemd1

分析問題發生先後的系統日誌,runC在重複的跑一個libcontainer_%d_systemd_test_default.slice測試,這個測試很是頻繁,可是當問題發生的時候,這個測試就中止了。因此直覺告訴我,這個問題,可能和這個測試,有很大的關係。

另外,我使用systemd-analyze命令,打開了systemd的調試日誌,發現systemd有Operation not supported的報錯。

根據以上零散的知識,只能作出一個大概的結論:org.freedesktop.systemd1這個bus在通過大量Unit建立刪除以後,沒有了響應。而這些頻繁的Unit建立刪除測試,是runC某一個checkin改寫了UseSystemd這個函數,而這個函數被用來測試,systemd的某些功能是否可用。UseSystemd這個函數在不少地方被調用,好比建立容器,或者查看容器性能等操做。

代碼分析

這個問題在線上全部Kubernetes集羣中,發生的頻率大概是一個月兩例。問題一直在發生,且只能在問題發生以後,經過重啓systemd來處理,這風險極大。

咱們分別給systemd和runC社區提交了bug,可是一個很現實的問題是,他們並無像阿里雲這樣的線上環境,他們重現這個問題的機率幾乎是零,因此這個問題沒有辦法期望社區來解決。硬骨頭還得咱們本身啃。

在上一節最後,咱們看到了,問題出現的時候,systemd會輸出一些Operation not supported報錯。這個報錯看起來和問題自己風馬牛不相及,可是直覺告訴我,這,或許是離問題最近的一個地方,因此我決定,先搞清楚這個報錯因何而來。

Systemd代碼量比較大,而報這個錯誤的地方也比較多。經過大量的代碼分析(這裏略去一千字),我發現有幾處比較可疑地方,有了這些可疑的地方,接下來須要作的事情,就是等待。在等待了三週之後,終於有線上集羣,再次重現了這個問題。

Live Debugging

在徵求客戶贊成以後,下載systemd調試符號,掛載gdb到systemd上,在可疑的函數下斷點,continue繼續執行。通過屢次驗證,發現systemd最終踩到了sd_bus_message_seal這個函數裏的EOPNOTSUPP報錯。

這個報錯背後的道理是,systemd使用了一個變量cookie,來追蹤本身處理的全部dbus message。每次在在加封一個新的消息的時候,systemd都會先把cookie這個值加一,而後再把這個cookie值複製給這個新的message。

咱們使用gdb打印出dbus->cookie這個值,能夠很清楚看到,這個值超過了0xffffffff。因此看起來,這個問題是systemd在加封過大量message以後,cookie這個值32位溢出,新的消息不能被加封致使的。

另外,在一個正常的系統上,使用gdb把bus->cookie這個值改到接近0xffffffff,而後觀察到,問題在cookie溢出的時候馬上出現,則證實了咱們的結論。

怎麼判斷集羣節點NotReady是這個問題致使的

首先咱們須要在有問題的節點上安裝gdb和systemd debuginfo,而後用命令gdb /usr/lib/systemd/systemd 1把gdb attach到systemd,在函數sd_bus_send設置斷點,而後繼續執行。等systemd踩到斷點以後,用p /x bus->cookie查看對應的cookie值,若是此值超過了0xffffffff,那麼cookie就溢出了,則必然致使節點NotReady的問題。確認完以後,可使用quit來detach調試器。

問題修復

這個問題的修復,並無那麼直截了當。緣由之一,是systemd使用了同一個cookie變量,來兼容dbus1和dbus2。對於dbus1來講,cookie是32位的,這個值在通過systemd三五個月頻繁建立刪除Unit以後,是確定會溢出的;而dbus2的cookie是64位的,可能到了時間的盡頭,它也不會溢出。

另一個緣由是,咱們並不能簡單的讓cookie折返,來解決溢出問題。由於這有可能致使systemd使用同一個cookie來加封不一樣的消息,這樣的結果將是災難性的。

最終的修復方法是,使用32位cookie來一樣處理dbus1和dbus2兩種情形。同時在cookie達到0xfffffff的以後下一個cookie返回0x80000000,用最高位來標記cookie已經處於溢出狀態。檢查到cookie處於這種狀態時,咱們須要檢查是否下一個cookie正在被其餘message使用,來避免cookie衝突。

後記

這個問題根本緣由確定在systemd,可是runC的函數UseSystemd使用不那麼美麗的方法,去測試systemd的功能,而這個函數在整個容器生命週期管理過程當中,被頻繁的觸發,讓這個低機率問題的發生成爲了可能。systemd的修復已經被紅帽接受,預期不久的未來,咱們能夠經過升級systemd,從根本上解決這個問題。


原文連接 本文爲雲棲社區原創內容,未經容許不得轉載。

相關文章
相關標籤/搜索