記一次使用 redis 協議詭異的bug

我們使用 go-redis-server 開發具有 redis 協議的服務。 按照文檔，我們實現了如下接口，其背后訪問的是 AWS 的 Dynamodb，我們的服務也開發了監控接口，以供我們這些程序狗知道它發生了什么。

 

func (handler *RedisHandler) Get(key string) (result string, err error)
func (handler *RedisHandler) Set(key string, val string) (err error)
func (handler *RedisHandler) Del(key string) (count int, err error)

 

這樣，我們就能通過 redis 客戶端來執行 Get，Set，Del 操作。

問題背景

我在批量寫入幾千條數據時，通過監控接口，我看到服務突然卡住的樣子，沒有 Get，Set的統計信息了。但我能肯定的是客戶端一直有數據在往服務寫入，或者讀寫。 同時從 AWS 監控得到的反饋是 Dynamodb 使用超過預設值，我調高了讀寫預設值，重啟服務，就恢復可用（重啟大法好）。 程序試運行十多天，只發生過一次異常，之后再無重現。 這個事情沒有搞清楚，就成為我一個心結。

重現問題

我們來看看代碼

 

func (handler *RedisHandler) 
Set(key string, val string) (err error) {
    ...

    m, err := JSONToMap(val)
    _, err = table.PutItem(m)
    if err != nil {
        log.Log.Errorf("PutItem failed, 
        table: %s, primary key: %s, value: %+v, 
        err: %s", 
        tableName, primaryVal, m, err.Error())
        return
    }
    return
}

 

Set接口，簡單的將數據寫入 Dynamodb，Dynamodb 如果異常就返回錯誤，然后通過redis協議返回給客戶端。

我很大程度確定那時候是因為 AWS Dynamodb 的異常導致這個錯誤的。除非這個巧合太牛逼了，難道 go-redis-server 接口不支持返回錯誤不成嗎？這個猜想很快就被我們用實驗否定了。

我想重新觸發 AWS Dynamodb 返回寫容量超標的錯誤，測試了一陣子，并不容易重現。有點沮喪，這個時候我回憶起 aws-go-sdk 的特點，如果給Dynamodb 字段 賦予空值，是會有異常返回的， 類似如下：

 

ValidationException: One or more parameter values were invalid:
An AttributeValue may not contain an empty string
    status code: 400

空值的測試明顯容易制造。我在本地也開啟服務，端口是1234，用 pyredis 作為客戶端做測試。 測試腳本

 

import redis
import json
import random
r = redis.Redis(host='localhost',port=1234,db=0)

table_name = 'test'
primary_key = 'a'

i = 0
while True:
    if i > 2:
        break
    data = {
        'a': str(random.random()),
        'b': ‘’,
    }
    key = '{0}:{1}:{2}'.format(table_name, primary_key, data[primary_key])
    value = json.dumps(data)
    r.set(key, value)
    i = i + 1

 

發現測試程序卡在終端，一動不動，strace 測試程序

 

$ sudo strace -p 22404
Process 22404 attached
recvfrom(3,

 

感覺像是在等待服務器返回，但是等不到回報的樣子。

試著解決問題

難道 go-redis-server 這個框架有貓膩，我就開始了一下午的看源碼之旅。不得不說源碼寫的真好。回頭看我們出錯的代碼片段，我試著修改 err 信息，修改成自己定義的錯誤字符串。

 

func (handler *RedisHandler) Set(key string, val string) (err error) {
    ...

    m, err := JSONToMap(val)
    _, err = table.PutItem(m)
    if err != nil {
        err = errors.New("I am a Custom Error")
        return
    }
    return
}

 

再次執行測試腳本，這一次。2條測試數據很快就執行結束，并無阻塞。 好像看到了一絲曙光：error 內容的不一樣，導致不一樣的結果。類型一樣，那么我能懷疑的就是格式，或者長度了。

 

AWS 錯誤信息的格式：
ValidationException: One or more parameter values were invalid:
An AttributeValue may not contain an empty string
    status code: 400

我自定義錯誤信息的格式：
I am a Custom Error

 

我特意加長了自定義錯誤的長度，結果也是能順利執行不阻塞客戶端。但是我給自定義錯誤字符串加入了換行符，果然客戶端再次測試會出現阻塞。當出現錯誤的時候，源碼中是調用了 ErrorReply.WriteTo 這個函數，特別的。返回錯誤的協議格式是

第一個字節將是“-”,并以CR + LF 結尾

配合源碼，以下是 go-redis-server 最核心的邏輯調度代碼。

 

for {
    request, err := parseRequest(conn)
    if err != nil {
        return err
    }
        request.Host = clientAddr
        request.ClientChan = clientChan
        reply, err := srv.Apply(request)
        if err != nil {
            return err
        }
        if _, err = reply.WriteTo(conn); err != nil {
            return err
        }
    }
    return nil
}
func (er *ErrorReply) WriteTo(w io.Writer) (int64, error) {
    n, err := w.Write([]byte("-" + er.code + " " + er.message + "\r\n"))
    return int64(n), err
}

 

從 Redis協議官方文檔 ，可以確定客戶端與服務器端之間傳輸的每個 Redis 命令或者數據都以 \r\n 結尾。 我們的錯誤信息中間殺出了 \n ，導致協議錯亂，redis 客戶端不能理解協議，就阻塞了。

一點感悟

• 以后我們使用 go-redis-server 的服務時候，要記得檢查返回的字符串或者錯誤信息有沒有包含換行符，如果有，最好做一次過濾替換。

• 出現這個bug,我和同事都覺得不可思議，非常神奇。在沒有其他直觀線索的條件下，閱讀使用的庫的源碼，并在源碼加上一些輸出驗證語言加以輔助，收到了效果，的確需要一些耐心。但我覺得是值得的。

• 李笑來說有效閱讀就是精度，這次閱讀代碼過程中我還有意外的收獲，我發現了 reflect 的妙用，以及函數注冊在框架可以那么用，讀完覺得很滿足的樣子，值得再記錄一番。

 

 

來自：http://zheng-ji.info/blog/2016/09/28/ji-yi-ci-redis-server-bug/