Kube-apiserver goroutine leak
背景
线上master的apiserver组件内存报警，内存使用量持续增长，监控如下
排查过程
从监控上看和另外一个程序（管理员平台）的内存使用情况吻合，使用率降下来是因为重启了apiserver和管理员平台，且问题只出现在最近两天的晚上，管理员平台中有一段逻辑是定时全量拉取集群数据（设计不合理，后续需要改），管理员平台的日志里显示拉取数据超时，基本猜测和管理员平台调用k8s api不合理有关，且k8s apiserver应该也有bug，导致内存泄露或者goroutine泄露。但是最近代码都没动过，为啥之前没事呢，后负责管理员平台的同事说近两天美东专线有问题，延迟是之前的3倍，而且出现问题的时间正好匹配，那接下来就查一下具体原因。
查看apiserver日志
apiserver错误日志里有大量的上述日志，可以看到是apiserver因为响应超时触发的，里面也有详细的函数调用堆栈信息，也有ip的信息，正好对应了master和管理员平台的地址，通过pprof也可以看到此时的goroutine使用量一直在增加，已45000+，确认是产生了goroutine泄露。下图为pprof tree看到的部分内容，里面显示了占用量最多的地方
同时在浏览器中访问http://ip:port/debug/pprof/goroutine 可以看到具体goroutine数量和执行函数的行号，此处忘记截图了，不过和上面的信息吻合，且更信息因为携带了行号的信息，可以看到是如下代码出的问题（代码版本1.12.4）
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 | // k8s.io/kubernetes/vendor/k8s.io/apiserver/pkg/server/filters/timeout.go func (t *timeoutHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) { r, after, postTimeoutFn, err := t.timeout(r) if after == nil { t.handler.ServeHTTP(w, r) return } errCh := make(chan interface{}) tw := newTimeoutWriter(w) go func() { defer func() { err := recover() if err != nil { const size = 64 << 10 buf := make([]byte, size) buf = buf[:runtime.Stack(buf, false)] err = fmt.Sprintf("%v\n%s", err, buf) } errCh <- err }() t.handler.ServeHTTP(tw, r) }() select { case err := <-errCh: if err != nil { panic(err) } return case <-after: postTimeoutFn() tw.timeout(err) } } |
|---|
泄露的goroutine就是第11行处的，简单解释一下上面的逻辑：生成一个timeout的handler，起一个新的goroutine进行后续handler的处理，当前goroutine中使用select进行等待，分为两种case，分别对应新goroutine中panic的情况和整个函数超时的情况，分别看两个case的内容
第25行：从errCh读取数据，其中errCh中的数据是在新的goroutine中产生的，对应到实际情况就是22行的代码出发生了panic，在13行捕获到了，最后在20行把err写入到errCh中，但是这里需要注意一下这个errCh是个无缓存的；
第30行：after是调用time.After后产生的一个chan，在超时后可以从这个chan中获取到数据，然后在32行处会调用tw.timeout函数，里面会触发panic；
那为什么11行处的goroutine泄露了呢？
问题就出现在了刚才提到的无缓冲的errCh上，因为触发了timeout，代码逻辑没有执行到25行，直接去了30行，然后整个函数panic，导致20行执行的时候卡住了，从而阻止了11行出的新的goroutine的退出，每有一个timeout的请求，这里就会泄露一个goroutine，从而导致内存随之泄露，cpu的话其实不受什么影响，因为泄露的goroutine已经执行过gopark，不是runnable状态的。
解决方案
印象中记得之前看k8s版本升级的release-note时有提到过修复apiserver leak字样的信息，然后就去官方项目中查，结果没找到，然后直接去看了对应文件的最新版本代码，看history，终于找到了相关的修复的commit，合入1.17。
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 | case <-after: defer func() { // resultCh needs to have a reader, since the function doing // the work needs to send to it. This is defer'd to ensure it runs // ever if the post timeout work itself panics. go func() { res := <-resultCh if res != nil { switch t := res.(type) { case error: utilruntime.HandleError(t) default: utilruntime.HandleError(fmt.Errorf("%v", res)) } } }() }() postTimeoutFn() tw.timeout(err) } |
|---|
可以看到其思想就是在外层panic后，新加一个defer func用来从之前的errCh（新版改名为resultCh）接收数据，从而避免之前的问题。
总结
通过上面的修改，确实可以解决goroutine泄露的问题，但是也存在一个隐患：第6行新加的goroutine会从resultCh读数据，因为在上一段代码处有个处理，无论是否panic，都会往errCh（resultCh）写入err，从而可以避免同时泄露两个goroutine的情况，但是如果短时间内大量请求到来且处理时间都比较慢直至超时，虽然goroutine不会泄露，但是会产生两倍于之前的goroutine，可能会在短时间内造成内存暴涨，也算是一个稳定性风险，需要合理设置限流来降低风险。
腾讯云开发者
