生产环境这两天频繁上线代码。订单业务流量快速增长的同时,goroutine数量暴涨。临发现的时候,蹭蹭蹭已经冲到5、6百个goroutine,并且几乎没有下降的趋势。
严重的作妖现象,妖极必反,第一反应是暗暗心里发苦:goroutine泄漏!否则应该稳定最多一百多个 goroutine 左右。生产环境,pprof关闭状态。
先查了下 Kibana 的日志流量,差不多一个小时一个小时地有并发的日志量流量严重,日志里面搜了几个关键词:panic, runtine, stack, timeout, "invalid memory address"。没有什么订单项目的相关的异常。
这就离谱,没定位问题出处。
赶紧把 master 拉一个分支出来,发布到测试环境的k8s集群里。拉起一个api的镜像。暴露 pprof 出来一看,我勒个乖乖,复现了。也在一直增长,也是一样没有gotoutine 回落的迹象。
但是初步明确是对外网络连接的问题。既然测试环境能浮现,那我索性直接在本地run起来。
然后发了几个请求,看着goroutine 递增的同时,看那些程序在占用最多的 goroutine 消耗。
go tool pprof localhost:9091/pprof/goroutine?debug=1
top
tree 20
发现,订单列表查询和订单统计的 orm 是最大百分比份额。查了一下代码,gorm 好像查询结果返回了一个切片,但是没有进行初始化。于是改了一下,然后重新 debug 重复上面的调试步骤。
好开心:只有40个 goroutine 了。持续发起多个请求,我还是高兴的太早了。一开始只是重启,goroutine 数量因为程序重启暂时清零而已。过了一会儿,随着测试的各个接口持续下来,又上去了。
排查了好久,中间这玩意儿一度飙到了2000以上。
这整的我血压都上来了。赶紧上报直属 leader 和 技术大牛,一起来研究。
尝试把所有的对外 http 请求进行改造,我们基于 gin 进行了二次开发做的一个微服务架构。现在既然是网络问题,那最可能出问题的地方应该就是对外部第三方 API 调用或者 kafka 消费。这两大部分都是走的 http 。
队友怀疑是所有的对外的接口没有进行 context 上下文的 cancel,于是所有对外接口统一用 context.WithCancel 和context.WithTimeout 试了一遍,然而并没有起作用。
时间慢慢在消逝,断来断去,最后原因定位到落在创建订单的逻辑上。然后一段一段注释,打印 log。然后 google 搜索了不少,最后尝试了一下在我们二次封装的底层逻辑内增加参数。
我旁边的美女程序媛,她率先成功了!她直接修改网络连接客户端的结构体。增加了一个参数值。我其实之前在 stackoverflow 也查到类似的办法了。
t.DisableKeepAlives = true
底层的golang网络包,可以在这个 /go/src/net/http 目录找到 Transport 这个结构体。从注释看,客户端每个http请求都是用 Transport 做相应的机制处理的。而 DisableKeepAlives 这个参数如果没有设置,就是默认的长链接。
➜ http pwd
/usr/local/go/src/net/http
173
174 // DisableKeepAlives, if true, disables HTTP keep-alives and
175 // will only use the connection to the server for a single
176 // HTTP request.
177 //
178 // This is unrelated to the similarly named TCP keep-alives.
179 DisableKeepAlives bool
率先发布到测试环境,果然平复了goroutine。改造之后,像 Timeout 一样作为Client对象工厂方法创建时的可选参数传递。
赶紧通过 CI/CD 推送新的 merge hotfix/分支,20多秒之后,新版本替代pod Running 起来,替换了老版本的 pod。
刷新 Grafana ,启动时是60多个goroutine,最后稳定在120个上下。观察了10多分钟,基本稳定在130个以下,一块闷石终于缓缓落地。
下午6:50去楼下胡乱吃了碗米饭。
7:30,下班,撤,回家写篇公众号压压惊。还好不用跑路,虚惊一场。