如何進行kubernetes問題的排障

本文來自OPPO互聯網基礎技術團隊，轉載請註名做者。同時歡迎關注咱們的公衆號：OPPO_tech，與你分享OPPO前沿互聯網技術及活動。

1. 排障的前置條件

k8s的成熟度很高，伴隨着整個項目的擴增，以及新功能和新流程的不斷引入，也伴隨這產生了一些問題。雖然自動化測試能夠排除掉大部分，可是一些複雜流程以及極端狀況卻很難作到bug的徹底覆蓋。所以在實際的工做過程當中，須要對運行的集羣進行故障定位和解決。

固然，進行排障的前提是對於k8s的流程和概念進行掌握，對於源碼有必定的掌握能力，才能夠更好的進行。待排障的環境和版本和源代碼的版本須要進行匹配。版本號能夠經過version命令獲取，而後從源碼進行對照。並且kubectl version還能夠展現更爲git的commit id。這樣更爲精準一些。本文以一次排障過程爲例，介紹進行kubernetes問題排障的通常思路和方法。

2. 故障背景

在某個壓測的集羣(集羣版本爲v1.12.10)內，爲了測試極端性能，因而kubelet上配置了單節點能夠建立的容器數從110調整爲了600。而且進行反覆大批量的容器建立和刪除。在壓測後一段時間，陸續多個節點變爲NotReady，直到整個節點所有變爲了NotReady。

在節點上看到有大量的容器待刪除。kubelet雖然仍在運行，可是已經不進行任何的pod生命週期的管理了，已經呆住了。其餘組件大都正常。此時停了壓測工具，kubelet仍然不可以恢復正常。嘗試將一個節點的kubelet重啓後，節點恢復正常。

3. 故障分析

3.1 日誌分析

首先從日誌上進行分析。日誌是平常排障的最主要的工具。從長期經驗來看，咱們的主要方式是將日誌寫入到文件，並配合glogrotate進行日誌的回滾。不使用journal的主要緣由一個是習慣，另外就是使用效率上也沒有文件來的快速。

關於日誌級別，日誌級別過高，日誌量會很大；而級別過低，日誌信息量又不足。日誌級別按照經驗咱們通常定位4級。

從日誌上進行分析，能夠看到這樣一條日誌。

I1105 09:50:27.583544  548093 kubelet.go:1829] skipping pod synchronization - [PLEG is not healthy: pleg was last seen active 58h29m3.043779855s ago; threshold is 3m0s]

也就是PLEG再也不健康了。那麼這一行是怎麼報出來的呢？對照代碼，咱們能夠找到這樣的信息。

func (kl *Kubelet) syncLoop(updates <-chan kubetypes.PodUpdate, handler SyncHandler) {
......
    for {
        if rs := kl.runtimeState.runtimeErrors(); len(rs) != 0 {
            glog.Infof("skipping pod synchronization - %v", rs)
            // exponential backoff
            time.Sleep(duration)
            duration = time.Duration(math.Min(float64(max), factor*float64(duration)))
            continue
        }
        // reset backoff if we have a success
        duration = base

        kl.syncLoopMonitor.Store(kl.clock.Now())
        if !kl.syncLoopIteration(updates, handler, syncTicker.C, housekeepingTicker.C, plegCh) {
            break
        }
        kl.syncLoopMonitor.Store(kl.clock.Now())
    }
......

PLEG再也不健康，這裏就會直接continue，也就不會走到下面的syncLoopIteration函數。而這個函數經過逐層調用，最終會到syncPod上。這也就解釋了爲何節點上kubelet再也不處理pod生命週期的緣由了。可是爲何PLEG再也不健康。那麼它的判斷標準又是什麼呢？繼續看代碼。

func (g *GenericPLEG) Healthy() (bool, error) {
    relistTime := g.getRelistTime()
    elapsed := g.clock.Since(relistTime)
    if elapsed > relistThreshold {
        return false, fmt.Errorf("pleg was last seen active %v ago; threshold is %v", elapsed, relistT
hreshold)
    }
    return true, nil
}

同時，這裏能夠看到PLEG的健康狀態是以上次relist的時間來肯定的。那麼relist的時間又是在哪更新的呢？這個能夠經過代碼找到func (g *GenericPLEG) relist(){...}函數，也就是在這個函數裏進行relist的時間更新的。那麼能夠初步斷定應該可能在這個函數的某個流程裏卡住了，致使的整個問題。可是這個函數有上百行，咱們怎麼定位呢？好像日誌分析可以提供的幫助已經頗有限了。那麼咱們須要一些其餘的工具來輔助定位。

3.2 pprof

pprof就是這樣的一個工具。pprof是什麼，怎麼用，這裏不展開講，能夠去搜具體的資料。kubelet裏有一個配置enable-debugging-handlers，經過配置爲true進行開啓（默認爲true）。開啓後，藉助於這個工具，咱們進行進一步的定位。kubelet的工做默認端口爲10250。由於咱們的集羣中kubelet開啓了認證，因此咱們這裏用curl命令直接把須要的堆棧信息拉取下來。

curl -k --cert admin.pem --key admin-key.pem "https://127.0.0.1:10250/debug/pprof/goroutine?debug=1" > stack.txt

由於卡住了，因此有很是多的goroutine信息。堆棧信息太長，這裏就不所有拉取了，這裏只截取咱們關心的，就是relist卡在了哪裏。咱們搜索relist，能夠看到這樣的信息。

goroutine profile: total 2814
...
1 @ 0x42fcaa 0x42fd5e 0x4066cb 0x406465 0x30d4f3e 0x30d682a 0xad7474 0xad6a0d 0xad693d 0x45d2f1
# 0x30d4f3d k8s.io/kubernetes/pkg/kubelet/pleg.(*GenericPLEG).relist+0x74d /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/pkg/kubelet/pleg/generic.go:261
# 0x30d6829 k8s.io/kubernetes/pkg/kubelet/pleg.(*GenericPLEG).(k8s.io/kubernetes/pkg/kubelet/pleg.relist)-fm+0x29 /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/pkg/kubelet/pleg/generic.go:130
# 0xad7473 k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.JitterUntil.func1+0x53 /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:133
# 0xad6a0c k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.JitterUntil+0xbc /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:134
# 0xad693c k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.Until+0x4c /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:88

並且咱們反覆對照了多個節點，能夠看到出現故障的節點，都卡在了這個261行的地方。這時候去找代碼。

func (g *GenericPLEG) relist() {
......
        for i := range events {
            // Filter out events that are not reliable and no other components use yet.
            if events[i].Type == ContainerChanged {
                continue
            }
            g.eventChannel <- events[i]    //261行
        }

位於261行的地方是g.eventChannel <- events[i]這個代碼。很奇怪，這個就發送一個event到channel裏，爲何會卡住？難道channel close掉了？這個eventChannel又是個什麼。追溯eventChannel的使用能夠看到channel是在syncLoopIteration中被消費。同時還發現，eventChannel是一個有固定容量，1000的一個channel。那麼問題逐漸變得清晰了起來。

3.3 故障推斷分析

反覆大量的建立和刪除，致使產生了很是多的event。這些event被髮送進了eventChannel裏，進而在syncLoopIteration的流程中進行消費。可是當syncLoopIteration消費的速度過慢，而events產生過快的時候，就會在g.eventChannel <- events[i]地方卡住。

因爲上面event發送卡住了，relist流程沒法正常進行。那麼這裏會致使PLEG變爲not healthy。PLEG not healthy以後，rs := kl.runtimeState.runtimeErrors(); 將會生成錯誤。生成的錯誤就是PLEG is not healthy。更加糟糕的事情就這樣發生了，PLEG不健康會致使調過syncLoopIteration的流程。而PLEG裏面的eventChannel的消費是在syncLoopIteration裏完成的。也就是說eventChannel沒有人去消費，會一直保持滿的狀態。致使總體死鎖了。新數據進不來，已有數據也無人消費。

3.4 故障模擬

分析完成後是否是就能夠徹底判定了呢？最爲安全保險的作法是在進行一下故障的模擬驗證，以便驗證本身的猜測。

那麼對於本次的問題，那麼咱們如何驗證呢？其實也很簡單，減小eventChannel的容量，增長几行日誌，打印channel的len，在進行一下壓測，很快就能復現了。這裏就不重複敘述了。

3.5 故障解決

知道了問題的定位以後，想辦法解決就能夠了。對於這個問題咱們如何解決呢？第一反應是能夠增長eventChannel的容量。這個會額外消耗一些資源，可是總體問題不大。可是有沒有更加優雅的方式呢？我試着去社區找一下，發如今今年已經有人發現並解決了這一問題了。https://github.com/kubernetes...

解決方式很簡潔，就是直接往eventChannel裏塞，若是塞滿了，直接記錄一個錯誤日誌，就無論了。

for i := range events {
            // Filter out events that are not reliable and no other components use yet.
            if events[i].Type == ContainerChanged {
                continue
            }
            select {
            case g.eventChannel <- events[i]:
            default:
                metrics.PLEGDiscardEvents.WithLabelValues().Inc()
                klog.Error("event channel is full, discard this relist() cycle event")
            }
        }

這樣的方式合理麼？會丟棄event麼？固然不會。由於relist是定時執行的。本次雖然丟棄了event，可是在下次relist的時候，會從新產生，並嘗試再次塞入eventChannel。所以這種方式仍是很簡潔和高效的。這個bug fix已經合入了1.14之後的版本，可是1.12的版本未能覆蓋。這裏咱們就將這個代碼手動合入了咱們本身的版本了。

4. 寫在最後

在生產和測試環境中，因爲種種緣由，多是k8s的問題，多是運維的問題，也多是用戶使用的問題，可能會出現種種情況。排查問題仍是務求謹慎細緻。個人通常原則是生產環境優先保存日誌和堆棧後，當即恢復環境，保障用戶使用。而在測試環境，優先把問題定位出來，儘可能把錯誤前置，在測試環境發現並解決，防止其擴散到生產環境。