离谱!Golang 请求已搞定,服务端却当起 “哑巴”,咋回事?

近期,我遭遇了一件颇为蹊跷的事情。具体而言,一个 HTTP 请求明明已经处理完毕,然而服务端却迟迟不返回响应,最终致使客户端请求超时……尽管最后我通过二分法定位到了问题所在,但其中涉及的原理着实值得深入探究并总结沉淀。

一个有去无回的请求

如下图所示,客户端将请求发送至采用 Gin 框架搭建的 Golang HTTP 服务。在服务端,业务逻辑代码已然执行完毕,可始终没有向请求方返回数据,最终造成请求超时。

我们可以看到,借助在服务端设置断点进行调试,程序已经执行到了业务代码的最后一步。

此时,我首先怀疑是不是存在 defer 函数影响了响应返回。于是我仔细排查代码,并未发现疑似的 defer 函数,这个猜测可以排除。

接着,我猜测会不会是某些公共的钩子函数在作祟。通过单步调试,我发现程序最终进入了 Gin 框架的代码部分,经过进一步分析,这个可能性也被排除。

随后,我怀疑是不是 Gin 框架本身存在 BUG。我继续进行单步调试,结果发现程序走到了 Golang 的内部代码,经过仔细查看,这个猜测同样不成立。

关键在于,不论是业务代码、Gin框架、Golang源代码都没有进入到任何异常逻辑,也没有报错

…历史的经验告诉我们,一般来说是 请求体 出现了问题

按照先少后多的原则,对请求体进行删减

curl -X POST "http://127.0.0.1:80/test/" -H "Content-Length: 504" -H "Content-Type: application/json" -H "Host: 127.0.0.212" -H "User-Agent: Http" -H "X-Forwarded-For: 127.175.66.27"  -H "Language: zh-CN" -H "Timestamp: 1732803011"  -d {
    "stringTest": "demo1",
    "StartTime": 1732662000000,
    "EndTime": 1732748400000,
    "TimeType": "houe",
    "numberTest": 0001,
    "Action": "helloworld",
    "Id": "1234567890"
}

最后发现:

问题出现在 Content-Length 这里,去掉就好了,那这里为什么有问题?

经对比,发现 Context-Length 与请求真实长度不一致,由于这个请求是从另一个请求借鉴而来,所以Header里面复用了之前的Content-Length

而如果Content-Length的长度大于body真实的长度,会发生什么呢?

我们问下AI

简单来说,导致服务端认为还有数据没有上报过来,所以一直在等待接收,从而导致超时

这里在请求的时候先去掉Content-Length,使用一些成熟的请求工具(比如jmeter)会自动计算并进行添加,这样就不会出现这个问题了

深入探究代码逻辑

表面上看,问题似乎并不复杂,但我们不妨深入剖析一番。

其一,为何业务代码会直接执行,而不是等待所有数据接收完毕后再启动执行呢?

其二,这一问题究竟是由 Gin 框架引起的,还是 Golang 自身的问题,亦或是更深层次的系统因素所致呢?

其三,在实际开发中,出于安全等多方面的考量,我们常常需要对收到的请求进行二次封装。若要对当前问题进行修改,在哪个层面进行操作会更为合适呢?

带着这几个问题,我开始仔细研读相关代码。

第一个可能的地方——Gin框架

这里首先看看AI能不能找到?

看来Gin对于这样标准的工作都为委托给了Golang的net/http库

第二个可能的地方——Golang的net/http库

还是先看看AI能不能找到?

AI给出了三个线索文件,去看一下

首先找到了一个疑似点

上图文件在transfer.go文件里面的525行,这里是对length进行了操作,仔细走查发现,其实这里只是为了确认Content-Length值有效性

再然后看下

上图文件在transfer.go文件里面的568行,这里是把读取body的值做一个限制,即用Content-Length进行限制

这里是关键

因为这里基本上确定了要读取的长度,而body比Content-Length小的话,是读不完的

再往下

上图文件在server.go的2009行,上图中是调用业务代码,这里也就解释了为什么业务代码会执行,即问题一

但问题点出现在2015行,看名字就知道这里是要确定request是否要处理完成

上图文件在server.go的1661行,经测试正常的请求会快速跳过1661行代码,但body比Content-Length小的话,会一直停在这里

看上面的两个图就会知道,基本上在网络IO那里等待接收数据,这里代码已经走到底层网络,不是HTTP了,那啥时候读取body的呢,也就是transfer.go文件里面的568行的reader的内容,因为这里的length设置的不对,答案在下图

比较意外的是并不是在writeBody方法里面,而是在writeHeader方法里面,因为这里需要对部分body进行丢弃,就提前读取了body,从而一直没有读取完毕

结论

1. 为何业务代码会先执行,而非等待所有数据接收完毕后再执行?

在 Gin 框架中,程序会先执行 server.go 的第 2009 行,随后再执行第 2015 行。这意味着,框架会先执行业务代码,之后才会判断请求(request)是否接收完毕。不过,在极端场景下,这种处理方式是否会引发问题,目前尚不确定。

2. 问题究竟是由 Gin 框架、Golang 还是更底层因素导致的?

实际上,Gin 框架在这个问题中只是起到了推波助澜的作用。问题的本质在于,读取的请求体(body)大小未达到 Content - Length 所指定的长度,从而导致网络输入输出(IO)操作一直处于等待状态。

3. 出于安全等因素考虑,对请求进行二次封装时,在哪个层面修改更为合适?

若需要对请求进行二次封装,可以在 Gin 框架的业务代码中对请求体(body)以及对应的 Content - Length 进行修改,然后重新发起一次重定向请求即可。

收工

另外,给大家分享一个小知识:并非所有的请求都需要添加 Content-Length 字段。若采用分块传输编码(Chunked transfer encoding),只需添加 Transfer-Encoding 字段即可。

需要特别留意的是,Transfer-EncodingContent-Length 这两个字段是相互排斥的。当它们同时出现在请求头中时,浏览器会以 Transfer-Encoding 为准进行处理。在 Go 语言里,程序会从请求头中移除这两个字段的信息,然后分别设置 TransferEncodingContentLength 属性。

具体可以参考net/http源码

// srs/net/http/transfer.go
// parseTransferEncoding sets t.Chunked based on the Transfer-Encoding header.
func (t *transferReader) parseTransferEncoding() error {
	raw, present := t.Header["Transfer-Encoding"]
	if !present {
		return nil
	}
	delete(t.Header, "Transfer-Encoding")

	// Issue 12785; ignore Transfer-Encoding on HTTP/1.0 requests.
	if !t.protoAtLeast(1, 1) {
		return nil
	}

	// Like nginx, we only support a single Transfer-Encoding header field, and
	// only if set to "chunked". This is one of the most security sensitive
	// surfaces in HTTP/1.1 due to the risk of request smuggling, so we keep it
	// strict and simple.
	if len(raw) != 1 {
		return &unsupportedTEError{fmt.Sprintf("too many transfer encodings: %q", raw)}
	}
	if !ascii.EqualFold(textproto.TrimString(raw[0]), "chunked") {
		return &unsupportedTEError{fmt.Sprintf("unsupported transfer encoding: %q", raw[0])}
	}

	// RFC 7230 3.3.2 says "A sender MUST NOT send a Content-Length header field
	// in any message that contains a Transfer-Encoding header field."
	//
	// but also: "If a message is received with both a Transfer-Encoding and a
	// Content-Length header field, the Transfer-Encoding overrides the
	// Content-Length. Such a message might indicate an attempt to perform
	// request smuggling (Section 9.5) or response splitting (Section 9.4) and
	// ought to be handled as an error. A sender MUST remove the received
	// Content-Length field prior to forwarding such a message downstream."
	//
	// Reportedly, these appear in the wild.
	delete(t.Header, "Content-Length")

	t.Chunked = true
	return nil
}

...
    // Unify output
    switch rr := msg.(type) {
    case *Request:
        rr.Body = t.Body
        rr.ContentLength = t.ContentLength
        if t.Chunked {
            rr.TransferEncoding = []string{"chunked"}
        }
        rr.Close = t.Close
        rr.Trailer = t.Trailer
    case *Response:
        rr.Body = t.Body
        rr.ContentLength = t.ContentLength
        if t.Chunked {
            rr.TransferEncoding = []string{"chunked"}
        }
        rr.Close = t.Close
        rr.Trailer = t.Trail

参考链接: https://loesspie.com/2021/12/17/http-content-length/