【踩坑筆記】一次加鎖和逾時控制引起的交通事故

問題回顧

線上發現流量接入層好像扛不住，一直在被 OOM，並且客戶出現大面積的逾時。但是流量並沒有打到後端的業務層。
在復原代碼，並且加機器之後，問題被解決了。

問題定位與解決

首先，懷疑是流量過大引起的。但是奇怪的點在於大部分流量沒有打到業務層。通過分析流量接入層的日誌，我們發現 有兩個相鄰日誌輸出的時間間隔比較長。而這兩條日誌輸出之間正是有復原的代碼。所以，我們將問題定位的方向轉移到了代碼層面。

但是，線下壓測過程中，並沒有發現類似的嚴重耗時問題，（懷疑是測試 case 沒有覆蓋到）。於是，先人工 Review 一遍變動的代碼。我們發現，有一個程式碼片段是加鎖的，代碼如下所示（golang 省略部分細節）：

    // key1    if val, exist := rateMap.Load(key1); exist {        return true, val.(*RateLimit).Taken(count)    }    Lock.Lock()    defer Lock.Unlock()    if mapC, exist := RateLimitC[flag1]; exist {        for _, val := range mapC {            if key1_ok {                rateLimit := NewRateLimit(val.Qps)                rateLimit.Create()                rateMap.Store(key1, &rateLimit)                return true, rateLimit.Taken(count)            }        }    }    // key2    if val, exist := rateMap.Load(key2); exist {        return true, val.(*RateLimit).Taken(count)    }    for _, val := range RateLimitC[flag2] {        if key2_ok {            rateLimit := NewRateLimit(val.Qps)            rateLimit.Create()            rateMap.Store(key2, &rateLimit)            return true, rateLimit.Taken(count)        }    }

這是一段 QPS 限流的邏輯，內部實現利用了令牌桶演算法，（先忽略有待最佳化的邏輯，我們來看為什麼會出現問題）
代碼的大概意思是：

如果用 key1 擷取到了 token，就直接返回；否則，加鎖，看是 map 裡是否有 flag1 代表的限流資訊，如果有，則判斷是否有符合 key1 條件的，如果有，則走正常擷取 token 邏輯；如果沒有，則嘗試用 key2 擷取 token，（下邊邏輯類似 key1）

問題就出線上上大部分情況需要用 key2 來擷取 token，所以大部分請求都會進入加鎖地區。如果只是一個加鎖，應該很快就能處理完，但是會有堆積性的耗時呢。
我們來看一下 val.(*RateLimit).Taken(count) 的實現：

func (this *RateLimit) Taken(count int) error {    timer := time.NewTimer(time.Duration(count) * TimeDuration)    defer timer.Stop()    for i := count; i > 0; i-- {        select {        case <-this.BucketCh:        case <-timer.C:            return errors.New("not get bucket")        }    }    return nil}

裡邊有個逾時機制，如果限定時間內沒有擷取到 token，則返回錯誤。

那麼，現在的問題是，所有走通過 key2 擷取 token 都會在加鎖的地區串列通過，那麼，當沒有立即擷取 token 的請求，阻塞在計時器的時候，其他等待鎖的請求都會阻塞在加鎖的階段，直到上一個請求逾時，或者擷取到 token，他才能獲得鎖。
換句話說，這條路是一個單行道，一次只能有一人通過，這個人還經常卡在收費站口，那麼後邊來的人就可能會越積越多，等待的時間越來越長，最後把路都給壓垮了。

總結

像這種錯誤，想到之後是很容易複現的，而且只要滿足條件，這個 bug 必現。
反思：

1. 開發最瞭解代碼，功能完成之後，需要自己想一下測試的 case，盡量可以自己覆蓋到；
2. 如果只看鎖的部分，不覺得有什麼問題，但是跟上下文結合起來，問題顯而易見（lock + timer）；

另外，這種耗時問題，可以線上下用 go 官方的 pprof 包，查看一下程式的耗時情況，也是可以發現的。