一次毕生难忘的 Java 内存泄漏排查经历

正文

请到「今天看啥」查看全文

一定是 GC 的问题

有时候把难题放一放，睡一觉，等脑子清醒了再去解决是一个好主意。没人知道当时发生了什么，服务表现的非常怪异。突然间，我想到了什么。Java 服务表现怪异的主要根源是什么？当然是垃圾回收。

为了应对目前这种情况的发生，我们一直打印着 GC 的日志。我马上把 GC 日志下载了下来，然后打开 Censum开始分析日志。我还没仔细看，就发现了一个恐怖的情况：每15分钟发生一次 full GC，每次 GC 引发长达 20 秒的服务停顿。怪不得连接 ZooKeeper 超时了，即使 ZooKeeper 和网络都没有问题。

这些停顿也解释了为什么整个服务一直是死掉的，而不是超时之后只打一条错误日志。我们的服务运行在 Marathon 上，它定时检查每个实例的健康状态，如果某个端点在一段时间内没有响应，Marathon 就重启那个服务。

知道原因之后，问题就解决一半了，因此我相信这个问题很快就能解决。为了解释后面的推理，我需要说明一下 Adventory 是如何工作的，它不像你们那种标准的微服务。

Adventory 是用来把我们的广告索引到 ElasticSearch (ES) 的。这需要两个步骤。第一步是获取所需的数据。到目前为止，这个服务从其他几个系统中接收通过 Hermes 发来的事件。数据保存到 MongoDB 集群中。数据量最多每秒几百个请求，每个操作都特别轻量，因此即便触发一些内存的回收，也耗费不了多少资源。第二步就是数据的索引。这个操作定时执行（大概两分钟执行一次），把所有 MongoDB 集群存储的数据通过 RxJava 收集到一个流中，组合为非范式的记录，发送给 ElasticSearch。这部分操作类似离线的批处理任务，而不是一个服务。

由于经常需要对数据做大量的更新，维护索引就不太值得，所以每执行一次定时任务，整个索引都会重建一次。这意味着一整块数据都要经过这个系统，从而引发大量的内存回收。尽管使用了流的方式，我们也被迫把堆加到了 12 GB 这么大。由于堆是如此巨大（而且目前被全力支持），我们的 GC 选择了 G1。

我以前处理过的服务中，也会回收大量生命周期很短的对象。有了那些经验，我同时增加了 -XX:G1NewSizePercent 和 -XX:G1MaxNewSizePercent 的默认值，这样新生代会变得更大，young GC 就可以处理更多的数据，而不用把它们送到老年代。Censum 也显示有很多过早提升。这和一段时间之后发生的 full GC 也是一致的。不幸的是，这些设置没有起到任何作用。

接下来我想，或许生产者制造数据太快了，消费者来不及消费，导致这些记录在它们被处理前就被回收了。我尝试减小生产数据的线程数量，降低数据产生的速度，同时保持消费者发送给 ES 的数据池大小不变。这主要是使用背压（backpressure）机制，不过它也没有起到作用。

请到「今天看啥」查看全文