Go 服務遷到 K8s 後老抽風重啓? 記一次完整的線上問題解決過程

前言

之前把Go服務都遷到Kubernetes上後有些服務的某個 Pod總是時不時的重啓一下，通過查業務日誌根本查不到原因，我分析了一下肯定是哪裏代碼不嚴謹造成引用空指針導致Go發送運行時panic纔會掛掉的，但是容器重啓後之前輸出到stderr的panic是會被清空的，所以纔有了這篇文章裏後面的分析和方案解決。

解決思路分析

在 Go 編寫的應用程序裏無論是在主協程（main goroutine）還是其他子協程裏，一旦出了運行時panic錯誤後，整個程序都會宕掉。一般的部署 Go 項目的時候都會使用supervisor監控應用程序進程，一旦應用程序發生panic停掉後supervisor會把進程再啓動起來。

那麼在把項目部署到Kubernetes集羣后，因爲每個節點上的kubelet會對主進程崩潰的容器進行重啓，所以就再引入supervisor就有些功能重疊。但是Go的panic信息是直接寫到標準錯誤的，容器重啓後之前的panic錯誤就沒有了，沒法排查導致容器崩潰的原因。所以排查容器重啓的關鍵點就變成了：怎麼把 panic 從 stderr 重定向到文件，這樣就能通過容器的 volume 持久化日誌文件的目錄方式保留程序崩潰時的信息。

那麼以前在supervisor裏可以直接通過配置 stderr_logfile 把程序運行時的標準錯誤設置成一個文件：

[program: go-xxx...]
directory=/home/go/src...
environment=...
command=/home/go/src.../bin/app
stderr_logfile=/home/xxx/log/..../app_err.log

現在換成了Kubernetes，不再使用supervisor後就只能是想辦法在程序裏實現了。針對在 Go 裏實現記錄 panic 到日誌文件你可能首先會考慮：在recover裏把導致 panic 的錯誤記錄到文件裏，不過引用的第三方包裏也有可能panic，這個不現實。而且Go 也沒有其他語言那樣的 Exception，未捕獲的異常能由全局的 ExceptionHandler 捕獲到的機制，實現不了用一個recover捕獲所有的panic的功能。

最後就只有一個辦法了，想辦法把程序運行時的標準錯誤替換成日誌文件，這樣Go再panic的時候它還是往標準錯誤裏寫，只不過我們偷偷把標準錯誤的文件描述符換成了日誌文件的描述符（在系統眼裏 stderr 也是個文件，Unix 系統裏一切皆文件）。

方案試錯

按照這個思路我先用下面的例子試了一下：

package main

import (
    "fmt"
    "os"
)

const stdErrFile = "/tmp/go-app1-stderr.log"

func RewriteStderrFile() error {
    file, err := os.OpenFile(stdErrFile, os.O_RDWR|os.O_CREATE|os.O_APPEND, 0666)
    if err != nil {
      fmt.Println(err)
        return err
    }
    os.Stderr = file
    return nil
}


func testPanic() {
    panic("test panic")
}

func main() {
    RewriteStderrFile()
    testPanic()
}

這個例子，我們嘗試使用 os.Stderr = file 來強制轉換，但運行程序後，發現不起作用，/tmp/go-app1-stderr.log 沒有任何信息流入，panic信息照樣輸出到標準錯誤裏。

最終方案

關於原因，搜索了一下，幸運的是 Rob Pike 有專門對類似問題的解答，是這樣說的：

把高層包創建的變量直接賦值到底層的runtime是不行的，我們用syscall.Dup2實現替換描述符再試一次，並且增加一個全局變量對日誌文件描述符的引用，避免常駐線程運行中文件描述符被 GC 回收掉：

var stdErrFileHandler *os.File

func RewriteStderrFile() error {
   if runtime.GOOS == "windows" {
      return nil
   }
  
    file, err := os.OpenFile(stdErrFile, os.O_RDWR|os.O_CREATE|os.O_APPEND, 0666)
    if err != nil {
      fmt.Println(err)
        return err
    }
    stdErrFileHandler = file //把文件句柄保存到全局變量，避免被GC回收
    
    if err = syscall.Dup2(int(file.Fd()), int(os.Stderr.Fd())); err != nil {
        fmt.Println(err)
        return err
    }
    // 內存回收前關閉文件描述符
   runtime.SetFinalizer(stdErrFileHandler, func(fd *os.File) {
      fd.Close()
   })
   
    return nil
}

因爲Windows系統不支持的syscall.Dup2這個函數，所以我加了個判讀，Windows環境下的Go運行時加載系統的一個dll文件也能實現這裏的功能，不過我們服務器環境都是Linux的，所以我認爲這部分要兼容Windows是無用功，保證項目在Windows下能跑不受影響就行了。

再次運行程序後，打開日誌文件 /tmp/go-app1-stderr.log 後就能看到剛纔程序崩潰時的panic信息，以及導致panic時整個調用棧的信息：

➜  ~ cat /tmp/go-app1-stderr.log 
panic: test panic

goroutine 1 [running]:
main.testPanic(...)
        /Users/kev/Library/Application Support/JetBrains/GoLand2020.1/scratches/scratch_4.go:39
main.main()
        /Users/kev/Library/Application Support/JetBrains/GoLand2020.1/scratches/scratch_4.go:44 +0x3f
panic: test panic

goroutine 1 [running]:
main.testPanic(...)
        /Users/kev/Library/Application Support/JetBrains/GoLand2020.1/scratches/scratch_4.go:39
main.main()
        /Users/kev/Library/Application Support/JetBrains/GoLand2020.1/scratches/scratch_4.go:44 +0x3f

方案實施後的效果

目前這個方案已經在我們線上運行一個月了，已發現的Pod重啓事件都能把程序崩潰時的調用棧準確記錄到日誌文件裏，幫助我們定位了幾個代碼裏的問題。其實問題都是空指針相關的問題，這些問題我在之前的文章《如何避免用動態語言的思維寫 Go 代碼》也提到過，項目一旦複雜起來誰寫的代碼也不能保證說不會發生空指針，不過我們事先做好檢查很多都是能夠避免的明顯錯誤，對於特別細微條件下引發的錯誤只能靠分析事故當時的日誌來解決啦。

本文由 Readfog 進行 AMP 轉碼，版權歸原作者所有。
來源：https://mp.weixin.qq.com/s/hw5GXHgI7TgdbGcbRiquiw

前言

解決思路分析

方案試錯

最終方案

方案實施後的效果

猜你喜歡