问题:
使用了brpc的长连接,但是为何耗时和短链接一样呢?
brpc文档里介绍,使用http协议,则默认使用pooled,只要连接数不超过max_connection_pool_size,则都可以使用长连接。
但是在实际使用中,发现整个请求耗时很长,使用curl结果如下:
curl -s -w %{time_namelookup}"\r\n"%{time_connect}"\r\n"%{time_pretransfer}"\r\n"%{time_starttransfer}"\r\n"%{time_total}"\r\n" -d ""
time_namelookup : 0.000
time_connect : 0.033 tcp建立连接耗时.
time_pretransfer : 0.033 tcp连接建立完成后,客户端开始传递第一个字节的时间
time_starttransfer : 0.070 服务端响应开始传输第一个字节的时间 (虽然很多资料上说是服务端响应第一个字节的时间,但是根据我多次试验数据我更认为是:客户端收到服务端响应的第一个字节的时间)
time_total : 0.070 整个请求到响应完成的耗时
由此看出:
tcp建立连接,三次握手,耗时1.5rtt,耗时33ms;
数据传输:70-33=37ms,也就是客户端把数据传给服务端(0.5rtt) 服务端处理(对方说5ms) 服务端把数据传回客户端(0.5rtt) = 37ms;也就是说1rtt = 32ms.
误区:
开始一直认为服务端内部有32ms(37-5)不知道哪去了,但是没想到的是我竟然把数据传输的1rtt给忽略了。
因为建立连接需要33ms,传输数据也需要32ms,服务端数据处理需要5ms,如果每次请求建立成功了长连接,则就可以省去tcp建联的33ms,也就是整个请求是37ms,符合预期。
结论:
从线上统计请求好时看,平均耗时70ms,所以可以确定长连接没建立成功。
解决:
既然brpc介绍用pooled连接池是长连接,那会不会是连接超过max_connection_pool_size了,所以很多都是短连接? 于是调得更长,也不行。
netstat -ant|awk '{print $nf}'|sort|uniq -c 分析:
61 close_wait
1 established)
2212 established
1 fin_wait2
19 listen
1 state
2016 time_wait
time_wait有2016个,说明有很多连接主动关闭,也就意味着请求是短链接,频繁连接关闭,那么可以确定,尽管使用了pooled,依然是端连接。
继续分析:发现有个defer_close_second参数,表示连接是立即关闭还是延迟多少秒后关闭。将该参数值从0改为120后,请求耗时从70ms降低到35ms了。
也是奇怪,既然pooled用长连接了,为何还要用defer_close_second来把问题复杂化?