出口带宽拉满

能够发现这个问题实属侥幸。依稀记得这是一个风雨交加的夜晚，这风、这雨注定了今夜的不平凡。果然线上百分百超时的根因被发现了！

我们的线上接口需要对外请求，而我们的流出带宽被拉满自然耗时就长因此导致超时。当然这都是结果，毕竟中间过程的艰辛已经远远超出老许的文字所能描述的范围。

反思

结果有了，该有的反思仍旧不能少。比如流出带宽被拉满为什么没有提前预警！无论是自信带宽足够还是经验不足都值得老许记上一笔。

而在带宽问题被真正发现之前，老许内心对带宽其实已有所怀疑，但是却没有认真进行验证，只听信了他人的推测导致发现问题的时间被推迟。

httptrace

有时候不得不吹一波Go对http trace的良好支持。老许也是基于此做了一个demo，该demo可以打印http请求各阶段耗时。

上述为一次http请求各阶段耗时输出，有兴趣的可去https://github.com/Isites/go-coder/blob/master/httptrace/trace.go拿到源码。

老许对带宽的怀疑主要就是基于此demo中的源码进行线上分析测试给到的推测。

框架问题

本部分更加适合腾讯系的兄弟们去阅读，其他非腾讯系技术可以直接跳过。

我司的框架为TarsGo，我们在线上设置handletimeout为1500ms，该参数主要用于控制某一接口总耗时不超过1500ms，而我们的超时告警均为3s，因此即使带宽已满这个百分百超时告警也不应出现。

为了研究这个原因，老许只好花些零碎的时间去阅读源码，最终发现了TarsGo@v1.1.6的handletimeout控制是无效的。

下面看一下有问题的源码:

func (s *TarsProtocol) InvokeTimeout(pkg []byte) []byte {
	rspPackage := requestf.ResponsePacket{}
	rspPackage.IRet = 1
	rspPackage.SResultDesc = "server invoke timeout"
	return s.rsp2Byte(&rspPackage)
}

当某接口总执行时间超过handletimeout时，会调用InvokeTimeout方法告知client调用超时，而上述的逻辑中忽略了IRequestId的响应，这就导致client收到响应包时无法将响应包和某次的请求对应起来，从而导致客户端一直等待响应直至超时。

最终修改如下：

func (s *TarsProtocol) InvokeTimeout(pkg []byte) []byte {
	rspPackage := requestf.ResponsePacket{}
	//  invoketimeout need to return IRequestId
	reqPackage := requestf.RequestPacket{}
	is := codec.NewReader(pkg[4:])
	reqPackage.ReadFrom(is)
	rspPackage.IRequestId = reqPackage.IRequestId
	rspPackage.IRet = 1
	rspPackage.SResultDesc = "server invoke timeout"
	return s.rsp2Byte(&rspPackage)
}