rpc應答太快造成請求超時
(金慶的專欄 2020.9)
在壓測中發現總有幾個請求超時,超時時長設大也會有,而成功的請求延時遠小于超時時間。
查錯的第一方向是查網絡庫中有消息丟失。
跟蹤所有消息,發現超時的消息應該是正常處理并返回了。
于是查接收應答消息后的處理,最終找到代碼:
```go
func (c *Client) onRpcRet(cbIndex uint32, ...) {
ii, ok := c.callbacks.Load(cbIndex)
if !ok {
// logger.Errorf("onRpcRet can not find cbIndex %d", cbIndex) // 可能是超時已刪
return
}
```
打開日志,發現超時的請求對應有該條錯誤日志。
此處回調不存在的情況,正常是先超時刪除回調,然后再收到應答。
現在是先收到了應答,發現找不到回調,然后過了一段時間會被判為超時無響應。
將下面代碼換個次序就好了:
```go
if err := c.Session.Send(msg); err != nil {
...
return
}
c.callbacks.Store(cbIndex, ...)
```
改為
```go
// 必須先設回調,然后發送,因為應答可能會很快
c.callbacks.Store(cbIndex, ...)
if err := c.Session.Send(msg); err...
```
壓測時因為加壓機CPU是滿負載運轉,所以 Send() 和 Store() 之間可能會間隔數毫秒,
足夠 rpc 請求處理完成并返回,而應答返回時回調還沒設置。
先 Send() 后 Store() 寫代碼會稍微簡單點,因為 Send() 失敗后可以直接返回。
先 Store() 后 Send() 時,Send() 失敗則需要相應 Delete().
(金慶的專欄 2020.9)
在壓測中發現總有幾個請求超時,超時時長設大也會有,而成功的請求延時遠小于超時時間。
查錯的第一方向是查網絡庫中有消息丟失。
跟蹤所有消息,發現超時的消息應該是正常處理并返回了。
于是查接收應答消息后的處理,最終找到代碼:
```go
func (c *Client) onRpcRet(cbIndex uint32, ...) {
ii, ok := c.callbacks.Load(cbIndex)
if !ok {
// logger.Errorf("onRpcRet can not find cbIndex %d", cbIndex) // 可能是超時已刪
return
}
```
打開日志,發現超時的請求對應有該條錯誤日志。
此處回調不存在的情況,正常是先超時刪除回調,然后再收到應答。
現在是先收到了應答,發現找不到回調,然后過了一段時間會被判為超時無響應。
將下面代碼換個次序就好了:
```go
if err := c.Session.Send(msg); err != nil {
...
return
}
c.callbacks.Store(cbIndex, ...)
```
改為
```go
// 必須先設回調,然后發送,因為應答可能會很快
c.callbacks.Store(cbIndex, ...)
if err := c.Session.Send(msg); err...
```
壓測時因為加壓機CPU是滿負載運轉,所以 Send() 和 Store() 之間可能會間隔數毫秒,
足夠 rpc 請求處理完成并返回,而應答返回時回調還沒設置。
先 Send() 后 Store() 寫代碼會稍微簡單點,因為 Send() 失敗后可以直接返回。
先 Store() 后 Send() 時,Send() 失敗則需要相應 Delete().