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().