kubernetesgraceperiod失效問題排查

冬島發表於2018-07-10

我們在使用 Kubernetes 時遇到了設定 –grace-period 引數不生效的問題,從 kubelet 日誌看是 kubelet 接受到 Pod DELETE 事件後在同一秒內又接受到了 REMOVE 事件,所以 Pod 立刻就會刪掉了。經過比較曲折的排查最後終於解決了這個問題,下面分享一下 kubernetes grace period 相關的一些概念和理論然後再介紹一下我們踩到的坑。

根據 kubernetes 官方文件《Termination of Pods》這一節的介紹可知 Kubernetes 刪除 Pod 時是可以配置 –grace-period 引數的,而且即使沒設定這個引數它也有 30 秒的預設值。那麼:

  • 這個寬限期到底有什麼作用是怎麼生效的呢?
  • grace-period 和 docker stop -t 引數有關係嗎?
  • 在 Kubernetes 中使用 grace-period 的最佳實踐應該怎樣的?

在解答這些問題前我們從優雅下線的作用、 Pod 中容器的生命週期 和 Pod 刪除的流程說起。

優雅下線有什麼用?

我們知道集團的應用都有 online 和 offline 的操作。online 是在應用啟動後可能會做一些註冊服務或者開啟告警之類的操作,offline 是在了停容器前會做關閉告警或者登出服務的操作。所以 online 和 offline 對於一個複雜的分散式叢集來說是必不可少的操作。

Container Lifecycle Hooks

Kubernetes 給 Pod 中的 container 新增了兩個 hook 點(官方文件看這裡):容器啟動後和容器停止前。容器啟動後正是做 online 的好時機,容器停止前正是做 offline 的好時機。

  • PostStart hook

PostStart 執行的時機是在容器啟動以後,但是並不是等容器啟動完成再執行。容器啟動以後和容器啟動完成的區別是什麼呢?我們先看一下 Docker 官網的 Entrypoint 和 CMD 的配置可知容器有可以通過 Entrypoint 和 CMD 配置啟動指令,如果 Entrypoint 和 CMD 都做了配置那麼 CMD 會作為 Entrypoint 的引數由 Entrypoint 來決定如何使用 CMD。但是 Entrypoint 執行之後是不會結束的,如果容器的一號程式結束容器也就退出了。所以在標準的容器玩法中是不知道容器什麼時候啟動成功的,只知道容器已經啟動了。所以 kubelet 是在執行 Entrypoint 之後就會立即執行 PostStart hook,而不是等 Entrypoint 執行完再去執行的。所以理論上來說 PostStart 和 Entrypoint 是並行執行的。

這個 hook 點是執行應用 online 好時機,PostStart 可以探測應用是否啟動成功,如果應用啟動成功就執行 online 的動作

  • PreStop hook

PreStop 是在 Pod 銷燬前 kubelet 對容器執行的指令,可以是到容器中執行一個命令也可以是向容器的某個埠發起一個 HTTP 請求。PreStop 的作用是做一些下線前的準備工作,比如集團的精衛應用再下線前需要從 zk 中登出當前的服務例項。

這個 hook 是執行 offline 的好時機,可以在下線前做一些清理動作。

Termination of Pods

當發起一個刪除 Pod 的指令時 Pod 的刪除邏輯是這樣的:

  1. 呼叫 kube-apiserver 發起刪除 Pod 請求,如果刪除 Pod 時沒有設定 grace period 引數那麼就會使用 30 秒的預設值,否則就會使用使用者指定的 grace period 進行優雅下線
  2. kube-apiserver 接受到這個請求以後給相應的 Pod 標記為“刪除狀態”。其實 Pod 沒有“刪除狀態”,此時 Pod 的 status 還是 Running 狀態,所謂的“刪除狀態”只是 deletionTimestamp 和 deletionGracePeriodSeconds 欄位會被設定,這時候 kubelet 或者 kube-proxy 監聽到這樣的 Pod 就會認為此 Pod 已經不能提供服務了,然後開始做相應的清理操作。
  3. 此時如果通過 Dashbord 檢視 Pod 的狀態是 Terminating ,其實 Terminating 也不是 Pod status 的欄位的值。只是因為設定了 deletionTimestamp 和 deletionGracePeriodSeconds 欄位所以 Dashbord 就會把 Pod 標記為 Terminating 狀態。這也是 Kubernetes 官方文件中提到的狀態
  4. (和第三條同時發生)當 kube-proxy 監聽到 Pod 處於 Terminatiing 狀態時就把 Pod 從 Service 的 EndPoint 中摘掉,這樣對外暴露的服務就摘掉了這個 Pod,防止新的請求傳送到這個 Pod 上來
  5. kubelet 監測到 Pod 處於 Terminating 狀態的話會下線 Pod,下線的過程分成兩個步驟。1. 執行 PreStop 2. 殺死容器。第一步:如果 Pod 設定了 PreStop hook 的話 kubelet 監測到 Pod 處於 Terminating 狀態後就會執行 PreStop 操作,執行 PreStop 設定的超時時間和刪除 Pod 時指定的 grace period 一致(如果沒設定預設是 30 秒)
  6. PreStop 執行完以後還有第二步殺死容器,第二部也有超時時間,這個超時時間是 grace period 減去 PreStop 耗時。如果執行 PreStop 超時或者 grace period 減去 PreStop 耗時剩餘的時間不夠兩秒(甚至可能是負數) kubelet 會強制設定成兩秒。第二部的超時時間暫且稱之為 tm2, kubelet 停止容器時執行的是 docker stop -t tm2 命令。所以 tm2 的邏輯是:首先傳送 term 訊號到容器的一號程式,如果容器在 tm2 時間內沒有停止就強制傳送 kill 訊號殺死容器
  7. kubelet 執行完 PreStop 和殺死容器兩步以後會回撥 kube-apiserver,把 Pod 從 kube-apiserver 中刪除,這次的刪除是真的刪除,這時候通過 API 就再也看不到這個 Pod 的資訊了

上面這些過程也可以檢視Kubernetes 官方文件,官方文件也有詳細的說明。從這裡可以判斷出來 Pod 下線現在 kube-apiserver 中標記為刪除狀態,然後 kubelet 執行完正真的刪除動作才會真的刪除 Pod。

優雅下線時間也可以設定成零,零的意思是立即從 Kubernetes 中刪除此 Pod。引數設定方法是:--forc --grace-period=0 這兩個引數同時被設定

回答上面的問題

  • 這個寬限期到底有什麼作用是怎麼生效的呢?

grace-period 的作用是讓 kubelet 可以在刪掉 Pod 前優雅的下線掉 Pod 中的服務,儘量做到服務無損的摘掉 Pod。通過前面的介紹可知 kubelet 在停止 Pod 前會嘗試執行 PreStop 操作。而 PreStop 就是為了應用優雅下線而設計的 hook。

注意:即使 PreStop 執行失敗 kubelet 還是會繼續執行 docker stop 的,kubelet 並不會因為 PreStop 執行失敗就停止 Pod 的清理,所以在集團內部使用對 PreStop 非常敏感的話就需要修改這部分邏輯

  • grace-period 和 docker stop -t 引數有關係嗎?

如果執行 PreStop 之後 grace-period 還有剩餘的時間那麼剩餘的時間就是 docker stop -t 的超時時間否則 docker stop -t 的超時時間就是預設的 2 秒,所以 grace-period 的長短可以影響到 docker stop -t 引數的超時時間,從而影響到容器程式對 term 訊號的處理

  • 在 Kubernetes 中使用 grace-period 的最佳實踐應該怎樣的?

Kubernetes 中 Pod 如果對狀態敏感就應該設定合理的 PreStop 操作和 grace-period 超時時間。保證 PreStop 可以在 grace-period 時間內完成,這樣 docker stop -t 2 也沒有問題

kubernetes grace period 失效

我們使用的版本是 1.7 版本,當時發現設定 –grace-period 引數指定的時間不生效,而且預設的 30 秒也沒有生效。 現象是隻要執行 kubectl delete pod 命令 Pod 就會立刻被刪除掉,並不會執行優雅下線的操作。

測試方法

為了測試程式響應 term 訊號後是否等待 30 秒再響應 kill 資訊,專門寫了一個 Go 的小程式:

package main

import (
    "fmt"
    "time"
    "os"
    "os/signal"
    "syscall"
)

var isTerm = false

func main()  {
    go signalFunc()
    for {
        if isTerm {
            fmt.Println("term is received")
        } else {
            fmt.Println("not have term ")
        }
        time.Sleep(time.Second * 1)
    }
}

func signalFunc()  {
    sigs := make(chan os.Signal, 1)
    done := make(chan bool, 1)
    signal.Notify(sigs, syscall.SIGINT, syscall.SIGTERM)
    go func() {
        sig := <-sigs
        fmt.Println()
        fmt.Println(sig)
        isTerm = true
        done <- true
    }()
    fmt.Println("awaiting signal")
    <-done
    fmt.Println("exiting")
}

上面這段程式碼每秒列印一條 not have term 這樣的日誌。當接受到 term 訊號以後每秒列印一條 term is received 這樣的日誌。那麼如果刪除 Pod 時 pod 的容器有 30 條 term is received 日誌就說明優雅下線成功了。

理想情況應該是列印向下面這樣的日誌,接收到 term 訊號後還會列印 30 條日誌

image-20180427113645806.png

實際情況是在刪除 Pod 時幾乎是立即就把容器殺死的,我看到的日誌是這樣的:

image-20180427113626573.png

我把這段程式碼編譯成二進位制再做成映象部署成 Pod 進行測試發現優雅下線並沒有生效。term is received 這條日誌大多數列印一次容器就掛掉了。最多的時間列印 2 次,有的時候一次都沒列印容器就掛掉了。

確定 BUG 的範圍

發現實際情況和文件介紹的不一樣就開始排查這個問題。因為線上的 kubelet 是我們自己編譯的,第一個想到的可能性就是我們的編譯環境有問題導致 kubelet 異常,所以我首先在我的 Mac 上面編譯了一下 kubelet 然後傳到 ECS 裡面做測試發現是正常的 –grace-period 可以正常生效 。

至此基本確定了是編譯環境有問題導致 kubelet 異常,編譯環境到底哪裡有問題毫無頭緒。編譯過 Kubernetes 二進位制的都知道官方提供了一個編譯映象,我們的二進位制就是通過官方提供的 gcr.io/google_containers/kube-cross:v1.8.3-1 這個映象編譯的。而且我們的編譯環境環境和我的 Mac 都是通過這個映象編譯的,Golang 語言本身也是所有依賴都編譯到二進位制裡面的,所以理論上不會有差別的。大家知道 Mac 下的 Docker 是在虛擬機器裡面執行的,我不確定是不是這個虛擬機器的環境也有問題。所以我又啟動了我本地的 VirtualBox 虛擬機器,在 CentOS 7 裡面又編譯了一次,發現我在 VirtualBox 裡面編譯出來的 kubelet 也是有問題的。接著我找到江博同學在他的 Mac 編譯一次還是有問題的。少數服從多數此時我已經不關心為什麼我的 Mac 上編譯是正常的了,我覺得我的 Mac 可能什麼地方有問題了。因為我在自己的 Mac 上面編譯過 1.10 的 kubelet,也許是我的電腦上快取了什麼資訊導致編譯出來的 kubelet 可能是新版本的,所以就不再考慮了。

緊接著我又做測試了一下最新兩個版本的 kubelet。當時猜想可能是 1.7 版本比較老有 BUG,所以我就立即從社群的 release 頁面直接下載了 1.10 版本的 kubelet 和 1.9.4 版本的 kubelet 進行測試測試。測試結果是這兩個高版本的 kubelet 都可以執行優雅下線動作,所以當時斷定是 1.7 版本的 Bug。然後開始排查這個 Bug。

DELETE 和 REMOVE 操作

最初猜測可能是 kubelet 垃圾回收機制非同步執行的邏輯有問題導致的 BUG,所以第一個排查的就是垃圾回收機制。最後排查問題並不是垃圾回收的問題,因為垃圾回收只清理死掉的 Pod 的資訊,而不會主動殺死 Pod。

接著就從 kubelet 的日誌開始找線索,從日誌中發現 kubelet 收到 Pod DELETE 操作以後又立刻收到了 Pod REMOVE 操作。程式碼檔案路徑是 pkg/kubelet/kubelet.go 程式碼片段如下:

image-20180430214503943.png

那麼問題來了:DELETE 和 REMOVE 的區別是什麼?為什麼有了 DELETE 還需要 REMOVE 呢?

DELETE 和 REMOVE 動作進一步分析

這裡簡要說明一下,DELETE 和 RMEOVE 這兩個“動作”不是 kube-apiserver 直接下發的,kube-apiserver 下發的是 Pod 狀態的變遷,這兩個動作是 Kubelet 根據自己快取的 Pod 資訊和從 kube-apiserver 監聽到的最新的資訊 Merge 出來的(具體程式碼參見 pkg/kubelet/config/config.go merge 函式)。

先分析 DELETE 邏輯的程式碼。kubelet 接受到 DELETE 動作以後執行 HandlePodUpdates 操作。這個操作的邏輯很簡單,先在 podManager 中更新 Pod 的狀態然後通過 dispatchWork 把當前 Pod 狀態變遷的動作傳遞下去。

// HandlePodUpdates is the callback in the SyncHandler interface for pods
// being updated from a config source.
func (kl *Kubelet) HandlePodUpdates(pods []*v1.Pod) {
   start := kl.clock.Now()
   for _, pod := range pods {
      kl.podManager.UpdatePod(pod)
      if kubepod.IsMirrorPod(pod) {
         kl.handleMirrorPod(pod, start)
         continue
      }
      // TODO: Evaluate if we need to validate and reject updates.

      mirrorPod, _ := kl.podManager.GetMirrorPodByPod(pod)
      kl.dispatchWork(pod, kubetypes.SyncPodUpdate, mirrorPod, start)
   }
}

podManager 是 kubelet 在本地快取 Pod 資訊的資料結構,podManager 是 kubelet 比較核心的元件,kubelet 很多操作都會用到。

kubelet 獲取 Pod 的資訊有幾個途徑:

  1. 通過 podManager 獲取本地實時的 Pod 資訊
  2. 通過 kube-apiserver 獲取 Pod 資訊
  3. 靜態 Pod 通過配置檔案或者 url 獲取
  4. 通過本地 Container 列表反向演算 Pod 資訊(kubelet 重啟的時候就是通過這種方式判斷本機上有哪些 Pod 的)
  5. 通過 cgroup 演算 Pod 資訊(kubelet 就是通過對比 cgroup 設定的資訊和 podManager 的資訊判斷哪些 Pod 是孤兒 Pod 的,孤兒 Pod 的程式會被 kubelet 立即通過 kill 訊號殺程式,非常強暴)

繼續分析 dispatchWork 會發現最後會呼叫到 func (kl *Kubelet) syncPod(o syncPodOptions) error { 這個函式。syncPod 這個函式是 kubelet 核心處理函式,大多數 Pod 狀態的變化都會經過此函式處理一次。

看一下 syncPod 的程式碼如下圖程式碼片段所示:

image-20180430223245963.png
可見當 Pod 的 DeletionTimestamp 欄位設定時 syncPod 就會執行 killPod 進行清理。

繼續跟進 killPod 最後定位到 pkg/kubelet/kuberuntime/kuberuntime_container.go 的 killContainer 函式。killContainer 的程式碼片段如下:

image-20180430223855788.png
通過這段程式碼可以看出這就是官方文件中描述的 kubelet 終止 Pod 的兩個步驟 1. 執行 PreStop 2. 停止容器。至此我們大概清楚了 kubelet DELETE Pod 的大概流程:

  1. kubelet 從接受到 Pod 狀態的變遷然後 Merge 成 DELETE 動作
  2. DELETE 操作是先在 podManager 中更新 Pod 的最新狀態然後再 syncPod 中執行 killPod 函式
  3. killPod 執行 killContainer 最後停掉 Pod 的所有程式
  4. kubelet 垃圾回收 goroutine 每秒執行一次發現死的 Pod 並且是已經刪除的狀態就執行垃圾回收,然後此 Pod 的資訊就徹底從當前 Node 中刪除了

好的程式碼總是能給人有用的指引,通過上面 killContainer 這個程式碼片段可知只要這個函式執行就會列印箭頭指向的那樣一行日誌。不妨先分析一下 kubelet 的日誌看看情況。我在 kubelet 日誌中搜尋 cat kubelet.log |grep “Killing container|grep “second grace period” 這樣的關鍵字發現 killContainer 執行了兩次,並且第一次執行時優雅下線時間是 30 秒,第二次卻是零秒。至此看起來問題比較明朗了,是因為第二次的超時時間是零秒,所以執行了 docker stop -t 2 命令立即向 container 傳送了 kill 訊號,所以優雅下線就沒有生效。

現在 DELETE 的邏輯清楚了,那麼 REMOVE 的邏輯是怎樣的呢?會不會第二次 killContainer 的呼叫是 REMOVE 動作發起的呢?接下來我又分析了一下 REMOVE 的邏輯,程式碼片段如下所示:

image-20180430225348243.png
REMOVE 首先從 podManager 中刪除掉當前 Pod 的資訊,然後執行 deletePod 函式,程式碼片段如下:

image-20180430230036033.png
這個函式最後把 Pod 的資訊傳送到了 podKillingCh 這個 channel。kubelet 啟動的時候會啟動一個 goroutine 監聽這個 channel。當發現 channel 中有資訊是就取出 Pod 然後執行 killPod 操作。所以最後會走到 killContainer 的邏輯。那麼上面的猜測是成立的,第二次的 killContainer 呼叫是 Remove 發起的。

在這個函式排查的時候發現 REMOVE 預設傳進來的 gracePeriod 引數是零秒。結合上面介紹的 Pod 強制刪除的引數可知 REMOVE 操作中的零秒超時時間其實就是 –force 和 –grace-period=0 引數同時設定的結果,也就是說這是一個強制刪除操作。下面總結一下 DELETE 和 REMOVE 這兩個動作的區別:

  • DELETE 意思是 kube-apiserver 已經把當前 Pod 標記為 Terminating 狀態(也就是deletionTimestamp 和 deletionGracePeriodSeconds 欄位被設定了)。kubelet 接收到這個動作時會執行優雅下線 Pod
  • REMOVE 的意思是當前這個 Pod 已經從 kube-apiserver 中徹底刪除了。kubelet 接收到這個引數是會強制殺死 Pod

好,既然這樣的話是不是強制在 killContainer 這個函式中把超時時間改成 30 秒就一定會生效呢?如下圖所示,於是我就強制把 gracePeriod 設定成 30 進行測試。讓人失望的是雖然已經設定成 30 但是還是沒有生效。

image-20180430225136813.png
雖然強制設定成 30 秒沒有生效。也就是說 REMOVE 動作的強制刪除並不是通過 killContainer 設定零秒超時時間生效的,那麼到底是怎麼生效的呢?

為此我對 REMOVE 邏輯的各個環節進行了大量的除錯,最終發現一個現象:只要不從 podManager 中刪除當前 Pod 優雅下線就會生效,一旦從 podManager 中刪除 Pod 那麼及時不執行 killContainer Pod 也會被強制殺死。當時通過分析 kubelet 程式碼認為 kubelet 只要停止容器就會呼叫 killContainer 函式, killContainer 會呼叫 runtime 的 stopContainer 函式。如下所示:

image-20180430232805599.png
containerManager 的介面可知 kubelet 殺死一個容器只有 StopContainer 和 RemoveContainer 兩個途徑。於是我就在這兩個函式裡面守株待兔新增各種除錯資訊,最終還是沒有逮到兔子。難道 kubelet 管理 container 還有其他途徑?

孤兒 Pod 的清理

貌似很清晰的線索現在又沒有頭緒了。接下來又回到了 kubelet 日誌,看看日誌中是否還有什麼線索。
回到 kubelet 的日誌仔細分析日誌,因為現在對 kubelet DELETE 和 REMOVE 已經比較瞭解了,所以把上面程式碼排查確定的一些過程的日誌排除掉之後發現了下面這樣奇怪的日誌:

image-20180430233522375.png
果然上面守株待兔沒有逮到是因為 kubelet 管理 Pod 真的還有其他的途徑,而且看起來貌似是非常強暴的方式,直接 kill 程式。通過 ”Attempt to kill process with pid“ 這個關鍵字找到程式碼的位置然後反向推演呼叫過程最後發現是 kubelet 刪除孤兒 Pod 時進行的操作。上面提到了 REMOVE 操作的時候如果註釋掉從 podManager 中刪除 Pod 的程式碼優雅下線就會生效,否則就不會生效。通過分析 kubelet 刪除孤兒 Pod 的邏輯證實了這個現象。

如下所示孤兒 Pod 的清理是這個分支。這個清理動作每 2 秒就會執行一次。

image-20180430233844069.png
清理的邏輯是遍歷系統的 cgroup 資訊資訊,然後根據 cgroup 資訊計算當前系統中實際執行的 pod 的數量和 pod 名稱、ID 等基本資訊。然後再和 podManager 中快取的資訊進行對比。如果發現哪個 cgroup 中的 Pod 在 podManager 中沒有就認為這是一個孤兒 pod,然後直接通過非常強暴的 kill 訊號強制殺死孤兒 Pod 的程式。

好,分析了這麼多 kubelet 的程式碼,DELETE 和 REMOVE 的邏輯也大體清晰了。現在還有一個問題:根據官方文件的描述 Pod 刪除時在 kube-apiserver 中只是標記然後,最後真正確認刪除的是 kubelet,那麼為什麼 kubelet 會被動收到一個強制刪除的動作(REMOVE)呢?

image-20180430234659633.png

為什麼會被動觸發 REMOVE

我們知道 Kubernetes 所有的資料變動都會經過 kube-apiserver 的,接下來只能分析 kube-apiserver 的邏輯來排查為什麼 kubelet 會收到強制刪除的指令了。通過分析 kube-apiserver 的日誌發現如果使用我們編譯的 1.7 的 kubelet 刪除 Pod 的時候 node-controller 在 Pod 刪除前就會瘋狂的呼叫刪除 Pod 的介面。如果用從社群下載的 1.9.4 和 1.10 的 kubelet 二進位制 node-controler 就不會呼叫刪除 Pod 的介面。問題分析到這裡雖然不知道 Bug 的原因是什麼,但是可以隱約感覺到 node-controller 能夠感知到 kubelet 的一些資訊,這些資訊可能是 kubelet 啟動時註冊上來的,node-controller 在 Pod 刪除時可能會根據 kubelet 不同的資訊做了判斷。具體是什麼資訊要分析 node-controller 的程式碼才能知道。所以接下來就開始分析 node-controller 的程式碼。

因為已經知道是 node-controller 呼叫刪除 Pod 的介面導致的問題,所以 node-controller 這塊排查起來還是比較快的。到程式碼裡面直接搜尋 c.Core().Pods(pod.Namespace).Delete 函式的呼叫並且 DeleteOptions 中指定了 GracePeriodSeconds 為零的呼叫(因為是強制刪除,所以 GracePeriodSeconds 一定是零)。最後在 pkg/controller/node/controller_utils.go 的 maybeDeleteTerminatingPod 函式中發現了線索。

如下所示 maybeDeleteTerminatingPod 的程式碼片段

image-20180501000420495.png
首先會判斷 kubelet 的版本號是否符合語法規範,如果不符合就強制 kill Pod。如果符合再繼續判斷是否小於 1.1.0 版本,如果小於預設認為是不支援優雅下線操作的,所以強制刪掉 Pod。

接下來我分別看了一下正確的 kubelet 的版本號和錯誤的 kubelet 的版本號,如下所示:

[root@c46a091f6d7874538b52a55e5a57f019b-node6 ~]# ./ok-kubelet --version
Kubernetes v1.7.3-beta.0.444+4139877e213ead
[root@c46a091f6d7874538b52a55e5a57f019b-node6 ~]# ./err-kubelet --version
Kubernetes v1.7.3-beta.0+$Format:%h$
[root@c46a091f6d7874538b52a55e5a57f019b-node6 ~]#

可以看到有錯誤的 kubelet 的版本號是Kubernetes v1.7.3-beta.0+$Format:%h$ 明顯是模板字串沒有替換成變數。因為版本號字串不合法所以 Pod 就強制被刪掉了。

好現在彙總一下從頭到尾所有這些過程的分析:

  1. 發現 kubelet 優雅下線不生效
  2. 從社群下載最新的 1.10 和 1.94 版本的 kubelet 二進位制發現優雅下線可以生效
  3. 使用我的 Mac 重新編譯 kubelet 發現優雅下線可以生效但是別人的 Mac 編譯的 kubelet 優雅下線不生效,並且我的虛擬機器中編譯的 kubelet 也不生效。
  4. Pod 優雅下線不生效是因為 kubelet 收到了 REMOVE 的動作,而 REMOVE 觸發以後最長 2 秒內一定會觸發孤兒 Pod 的回收流程。所以 Pod 就被強制 kill 了
  5. 最後排查發現是 node-controller 判斷 kubelet 版本號不合法,所以在 Pod Terminating 的時候強制刪除了 Pod 從而觸發了 kubelet 的 REMOVE 操作

Kubernetes build/run.sh 分析

從錯誤的版本號中我們獲取了一個關鍵字串v1.7.3-beta.0+$Format:%h$ 通過這個字串在程式碼中定位到了 pkg/version/base.go 這個檔案,如下圖所示:

image-20180501001749159.png
由此推斷出了 GitVersion 關鍵字。編譯過 Golang 的人可能知道 Golang 是可以通過 ldflage 設定版本號的,所以初步推斷是編譯時設定沒有成功設定版本號導致的異常。

編譯 kubelet 的命令是:KUBE_BUILD_PLATFORMS=linux/amd64 && ./build/run.sh make WHAT=cmd/kubelet,那接下來從 build/run.sh 結合 GitVersion 關鍵字進行分析。

如下圖所示,最後定位到是 hack/lib/version.sh 執行 git describe –tags 命令獲取 tag 資訊的時候報錯(吐槽一下錯誤資訊居然被丟棄了),從而導致 KUBE_GIT_VERSION 變數為空。

image-20180428084123107.png
如下所示,如果這個變數為空就不會設定 gitVersion 這個 ldflags 引數,所以 kubelet 的版本號就異常了。

image-20180428084322342.png

那麼為什麼 git describe –tags 異常呢?檢視 git 文件可知因為我們的私有程式碼倉庫沒有設定 tag 所以執行此命令會就報錯。

那麼還有一個問題: 為什麼我的 Mac 上面編譯的 kubelet 就沒問題,而別的環境編譯的 kubelet 就有問題呢?經過進一步分析發現因為 gitlab 上面的 Kubernetes 程式碼是我從 github 上面 clone 下來又推上去的,所以本地有所有的 tag 資訊,所以 kubelet 的版本是正常了,也就沒有優雅下線的 BUG 了。

image-20180501002638470.png
既然知道問題出在 tag 這塊那麼也非常容易解了,我只要在本地執行一下 git push –tags 命令然後別的環境執行一下 git pull 再編譯就正常了。

總結

這個 Bug 的排查過程非常曲折,但最終定位到的原因又顯得非常不可思議,萬萬沒想到 Kubernetes 體系會根據版本號做這種業務操作。也沒有想到社群程式碼的 tag 沒有推到 gitlab 上面會導致這種問題。既然 Kubernetes 是這樣使用 tag 的那麼可能別人也會這樣用。看來以後我們向 gitlab 推程式碼的時候記得一定要把 tag 也推上去。

注:在最新的 node-controller 程式碼中判斷 kubelet 版本的合法性,如果 kubelet 版本不合法就強制 kill Pod 的邏輯已經去掉了

思考

在排查這個 Bug 的過程中對 kubelet 刪除 Pod 流程的各個邊界情況探索的比較清晰,從而看到了一些問題

  1. PreStop 必須要設定

Kubernetes 官方文件 中可以看見 kube-proxy 在監測到 Terminating 狀態的 Pod 時會從 Service 的 Endpoint 中摘掉當前 Pod。而 kubelet 監聽到此 Pod 的狀態為 Terminating 的時候會通過優雅下線殺死 Pod。那麼問題來了,仔細分析一下這個過程 kubelet 殺死 Pod 只需要相應的一個 kubelet 正常的感知到此 Pod 然後殺死 Pod 就行了,但是 kube-proxy 從 endPoint 中刪掉 Pod 例項需要所有的 kube-proxy 都感知到這個變化,所以理論上會出現 Pod 已經被 kubelet kill 掉但是 kube-proxy 還向 Pod 導流的情況。所以即使業務上不需要對應用進行 offline 操作也要在 PreStop 中執行一下 sleep 操作,讓 kubelet 強制等幾秒,等待 kube-proxy 全都摘掉 Pod 例項之後再執行 stopContainer。當然如果設定了 PreStop 操作執行時間太短的話也是有風險的,所以在集團內部建議判斷一下,如果 PreStop 沒設定或者執行時間太短就強制 sleep 一下。

  1. Pod Remove killPod 和清理 cgroup bug 分析

kubelet 接收到 REMOVE 動作以後會先從 podManager 中刪除此 Pod。然後把 Pod 資訊傳送到 channel,接著 PodKiller goroutine 感知到 channel 中有一個 Pod 需要刪除,就呼叫 killPod 執行刪除。killPod 最終使用超時時間為 2 秒的引數呼叫 stopContainer。通過執行順序可知先從 podManager 中同步的刪除 Pod 然後傳送到 channel,最終執行的時候還使用了 2 秒的超時整體的 stopContainer 時間肯定是大於 2 秒的。而一旦 Pod 從 podManager 中刪除孤兒 Pod 定時清理任務在 2 秒內就會感知到,然後就直接傳送 kill 訊號給程式非常粗暴的強制殺死程式。所以 Pod REMOVE 的正常 killPod 是不會被執行到的,這裡是有 Bug 的。

參考文獻


相關文章