終於解決了這個線上偶現的panic問題

來自公眾號：Gopher指北

不知道其他人是不是這樣，反正老許最怕聽到的詞就是“偶現”，至於原因我不多說，懂的都懂。

下面直接看panic資訊。

runtime error: invalid memory address or nil pointer dereference

panic(0xbd1c80, 0x1271710)
        /root/.go/src/runtime/panic.go:969 +0x175
github.com/json-iterator/go.(*Stream).WriteStringWithHTMLEscaped(0xc00b0c6000, 0x0, 0x24)
        /go/pkg/mod/github.com/json-iterator/go@v1.1.11/stream_str.go:227 +0x7b
github.com/json-iterator/go.(*htmlEscapedStringEncoder).Encode(0x12b9250, 0xc0096c4c00, 0xc00b0c6000)
        /go/pkg/mod/github.com/json-iterator/go@v1.1.11/config.go:263 +0x45
github.com/json-iterator/go.(*structFieldEncoder).Encode(0xc002e9c8d0, 0xc0096c4c00, 0xc00b0c6000)
        /go/pkg/mod/github.com/json-iterator/go@v1.1.11/reflect_struct_encoder.go:110 +0x78
github.com/json-iterator/go.(*structEncoder).Encode(0xc002e9c9c0, 0xc0096c4c00, 0xc00b0c6000)
        /go/pkg/mod/github.com/json-iterator/go@v1.1.11/reflect_struct_encoder.go:158 +0x3f4
github.com/json-iterator/go.(*structFieldEncoder).Encode(0xc002eac990, 0xc0096c4c00, 0xc00b0c6000)
        /go/pkg/mod/github.com/json-iterator/go@v1.1.11/reflect_struct_encoder.go:110 +0x78
github.com/json-iterator/go.(*structEncoder).Encode(0xc002eacba0, 0xc0096c4c00, 0xc00b0c6000)
        /go/pkg/mod/github.com/json-iterator/go@v1.1.11/reflect_struct_encoder.go:158 +0x3f4
github.com/json-iterator/go.(*OptionalEncoder).Encode(0xc002e9f570, 0xc006b18b38, 0xc00b0c6000)
        /go/pkg/mod/github.com/json-iterator/go@v1.1.11/reflect_optional.go:70 +0xf4
github.com/json-iterator/go.(*onePtrEncoder).Encode(0xc002e9f580, 0xc0096c4c00, 0xc00b0c6000)
        /go/pkg/mod/github.com/json-iterator/go@v1.1.11/reflect.go:219 +0x68
github.com/json-iterator/go.(*Stream).WriteVal(0xc00b0c6000, 0xb78d60, 0xc0096c4c00)
        /go/pkg/mod/github.com/json-iterator/go@v1.1.11/reflect.go:98 +0x150
github.com/json-iterator/go.(*frozenConfig).Marshal(0xc00012c640, 0xb78d60, 0xc0096c4c00, 0x0, 0x0, 0x0, 0x0, 0x0)

首先我堅信一條，開源的力量值得信賴。因此老許第一波操作就是，分析業務程式碼是否有邏輯漏洞。很明顯，同事也是值得信賴的，因此果斷猜測是某些未曾設想到的資料觸發了邊界條件。接下來就是儲存現場的常規操作。

如標題所說，這是偶現的panic問題，因此按照上面的分類採用符合當前技術棧的方法儲存現場即可。接下來就是坐等收穫的季節，而這一等就是好多天。中間數次收到告警，卻沒有符合預期的現場。

這個時候我不僅不慌，甚至還有點小激動。某某曾曰：“要敢於質疑，敢於挑戰權威”，一念至此便一發不可收拾，我老許又要為開源事業做出貢獻了嘛！說幹就敢幹，懷著小心思開始閱讀json-iterator的原始碼。

剛開始研讀我便明白了一個道理， “當上帝關了這扇門，一定會為你開啟另一扇門”這句話是騙人的。老許只覺得上帝不僅關上了所有的門甚至還關上了所有的窗。下面我們看看他到底是怎麼關門的。

func (cfg *frozenConfig) Marshal(v interface{}) ([]byte, error) {
    stream := cfg.BorrowStream(nil)
    defer cfg.ReturnStream(stream)
    stream.WriteVal(v)
    if stream.Error != nil {
        return nil, stream.Error
    }
    result := stream.Buffer()
    copied := make([]byte, len(result))
    copy(copied, result)
    return copied, nil
}


// WriteVal copy the go interface into underlying JSON, same as json.Marshal
func (stream *Stream) WriteVal(val interface{}) {
    if nil == val {
        stream.WriteNil()
        return
    }
    // 省略其他程式碼
}

根據panic棧知道是因為空指標造成了panic，而(*frozenConfig).Marshal函式內部已經做了非空判斷。到此，老許真的已經別無他法只得戰略性放棄解決此次panic。畢竟，這個影響也沒那麼大，而且程式設計師哪有修的完的bug呢。經過這樣一番安慰，心裡確實容易接受多了。

事實上，在較長一段時間內我都有意識地忽略這個問題，畢竟沒有找到問題的根因。這個問題線上上一直持續到一個說不上來什麼日子的日子，總而言之就是興致來了，我再次看了兩眼，而這兩眼很關鍵！

func doReq() {
    req := paramsPool.Get().(*model.Params)
    // defer 1
    defer func() {
        reqBytes, _ := json.Marshal(req)
        // 省略其他列印日誌的程式碼
    }()
    // defer 2
    defer paramsPool.Put(req)
    // req初始化以及發起請求和其他操作
}

注：
上述程式碼變數命名已經被老許通用化處理。
專案中實際程式碼遠比上述複雜，但上述程式碼依舊是造成本次問題的最小原型。

上面程式碼中paramsPool是sync.Pool型別的變數，而sync.Pool想必大家都很熟悉。sync.Pool是為了複用已經使用過的物件(協程安全)，減少記憶體分配和降低GC壓力。

type test struct {
    a string
}

var sp = sync.Pool{
    New: func() interface{} {
        return new(test)
    },
}

func main() {
    t := sp.Get().(*test)
    fmt.Println(unsafe.Pointer(t))
    sp.Put(t)
    t1 := sp.Get().(*test)
    t2 := sp.Get().(*test)
    fmt.Println(unsafe.Pointer(t1), unsafe.Pointer(t2))
}

根據上述程式碼和輸出結果知，t1變數和t變數地址一致，因此他們是複用物件。此時再回顧上面的doReq函式就很容易發現問題的根因。

defer 2和defer 1順序反了！！！

sync.Pool提供的Get和Put方法是協程安全的，但是高併發呼叫doReq函式時json.Marshal(req)和請求初始化會存在併發問題，極有可能引起panic的併發呼叫時間線如下圖所示。

既然已經找到原因，解決起來就容易多了，只需調整defer 2和defer 1的呼叫順序即可。老許將修改後的程式碼釋出到線上後也確實再沒有出現panic。造成這次事故的根本原因是一個微乎其微的細節，所以我們平時在開發中還是要謹慎加謹慎，避免因為這種小白錯誤造成不可挽回的損失。另外一個經驗之談就是，開發和查問題時儘量不要鑽牛角尖，適當的停頓可能會有意想不到的奇效。

最後，衷心希望本文能夠對各位讀者有一定的幫助。

終於解決了這個線上偶現的panic問題

相關文章