golang 的 goroutine 使用成本和资源开销都很低，因此在程序中很常见。但若使用不当会造成 goroutine 泄漏。泄漏原因一般都是在 goroutine 中使用 channel 阻塞读或阻塞写，但却没有回收/关闭该 channel，导致 goroutine 一直无法退出，造成 goroutine 泄漏。本文记录一次测试环境的服务因其依赖的开源基础日志切割（rotate）库存在 goroutine 泄漏，使得程序最终累积创建操作系统线程数超过 10000，导致进程直接 panic 问题的排查和分析过程。

问题背景

该问题最早出现在上周的组件压测中。压测背景是在 1000+ 台主机上安装 agent，然后通过前端产品界面构建一个至少向 1000 台主机下发任务的模版，然后启动模板并统计任务全部执行成功后返回的总耗时。在压测过程中发现，后端的 agent server proxy 组件突然就挂了，提示如下错误。当时只简单看了下 dump 出来的 goroutine stacktrace 包含了几十万个 goroutine 的堆栈信息。 且因压测时间紧迫，未仔细排查该问题，想着任务量过大出些问题也正常，就只是简单重启，就继续测试。

问题根因

经排查发现：

  • 组件依赖的一个开源基础日志切割库 lamberjack 存在 goroutine 泄漏。在多 goroutine 打印日志情况下，每次写入日志都开启一个 goroutine，在该 goroutine 中进行阻塞读，但未关闭该 channel 导致 goroutine 泄漏；
  • 如果应用程序中有多个 goroutine 基于同一个 logger 对象打印日志（我们挂掉的 agent server proxy 就是在大量 goroutine 中打印日志），或创建多个 logger 对象并基于这些 logger 打印日志，这两种情况都会导致 goroutine 严重泄漏。且使用的 goroutine 越多或创建的 logger 对象越多，泄漏越严重；
  • 关键是该问题在该日志库的 2.0 版本就已存在，且提过多个 PR，但一直未被合入，到 3.0 版本该问题都未被解决。

解决办法

  • 因为该日志库最新版本都未修复该 bug，因此不能再直接使用该日志库；
  • 可以参照这里提的 PR 的修复的版本。修复本身比较简单，在 logger close 的时候，将阻塞 goroutine 结束的 channel 关闭即可；
  • 更换其他日志库 :-)。

问题复现

可以构建两个测试用例来验证。一个是验证多个 goroutine 中使用同一个 logger 会造成 goroutine 泄漏，一个是验证创建多个 logger 也会造成泄漏。验证程序可参考这里。

排查过程

最开始看到 panic 日志后，猜想可能是因为代码有问题导致线程创建过多。因为组件事件模块的实现中，由于事件产生是异步的，因此针对每个主控 agent 实例和被管理的 agent 实例，都会启动一个 goroutine 去处理事件的监控和上报。但虽然存在 1000+ 主控 agent 实例，就算加上被管理的 agent 实例，也远未达到 10万+。

然后去网上查资料，基本都是说：一般应用不会同时创建这么多的 goroutine，因此要么程序中存在阻塞的 goroutine，要么自己通过 SetMaxThread 扩大线程数的上限（但不建议）。结合我的程序，监控事件的 goroutine 确实是阻塞的，但这仍然解释不了为什么程序中会同时存在10万+ goroutine，回头查看了下对应代码也没有问题。

因此想着用 pprof 看下。首先重启了程序，并等待了几十秒后 dump 出程序 goroutine 概览数据后，发现有一处同 logger 相关的代码调用竟然产生了 9000 来个 goroutine，因此基本可确认是该处代码出现 goroutine 泄漏。

随即在代码里搜索发现，该方法调用来在组件使用的日志库 lumberjack.v2，在源码中对应方法是创建一个 goroutine，且在 goroutine 中有一个从 channel 中进行阻塞读的操作，但没找到 channel 关闭的地方。然后继续查资料发现，在该日志库仓库中果然有对应的问题和 PR。一看依赖库的版本，发现在即使是最新的 3.0 版本该问题依然存在，可怕。

源码跟踪

基本定位问题原因后，想进一步弄清楚程序直接依赖的日志库 zap 如何调用底层的 lumberjack 日志切割库导致应用程序 goroutine 泄漏的。

底层日志切割库 lumberjack

Logger.millRunLogger.millonce.Do
Logger.millLogger.openExistingOrNewLogger.WriteLogger.Write

上层日志库 zap

在看程序直接依赖的日志库 zap。zap 是 uber 开源的高性能、可扩展的日志库。但 zap 不支持日志文件归档，因此若要支持文件按大小或时间归档，需要使用 lumberjack，lumberjack 也是 zap 官方推荐的。

zapcore.WriteSyncerzapCoreListzapcore.WriterSyncerWriteSync
zapCoreListWriterSyncer

至此，关于基于 zap 日志库如何调用到 lumberjack 库中存在 goroutine 泄漏的代码已经梳理完成。

参考