01

概述

kafka集群中的某些broker会随机重启，并且重启没有什么规律。broker重启对于client端使用层面是无感知的，但是在数据一致性、稳定性方面存在风险。broker重启时，连接在这台broker的连接会重连到其他正常的broker，增加集群中其他broker的压力。同时这个broker上的leader partition也会触发切主操作，频繁切主会影响该partition的一致性和可用性。partition的变动也会触发消费端的重平衡，从而影响消费端的稳定性。

通过查看 kafka 服务端日志，并未发现明显的 ERROR 级别日志。通过和运维同学的共同排查，最终定位并解决了这个问题，由于这个问题比较典型，因此通过这篇文章记录问题排查和定位过程。

02

找问题现场

1、分析 java core dump 文件：/tmp/hs_err_pid128144.log ，在文件头中发现以下线索，每次crash都是由OOM触发导致。

      2、在 core dump 文件头部和尾部找到内存分配的细节：分配 12288Byte 空间失败，然而物理内存还剩余 461984KB，显然可以排除 crash 不是内存不够导致。

Native memory allocation (mmap) failed to map 12288 bytes for committing reserved memory.

Memory: 4k page, physical 131519612k(461984k free), swap 0k(0k free)

3、在core dump文件的线程调用栈中发现分配page相关的函数 os::pd_create_stack_guard_pages，我们进入到 os::Linux::commit_memory_impl 函数，发现其实是做了一次mmap系统调用。

4、从上面代码进入到  warn_fail_commit_memory 方法，理论上，日志中会打印 warning 内容，kafka集群的日志为INFO级别，因此 warning 日志就看不到了。如果日志能看到的话，至少我们知道mmap发生的具体errorno是什么，从而断定mmap到底是为什么失败了。由于线上集群规模较大，修改日志级别重启broker数量较多，为了不影响业务，暂时选择不重启。到现在好像基本上断了思路，只能等待修改日志级别之后看看其效果。

03

分析gc日志

1、查看 grafana 监控指标，在进程内存占用发现线索。通过下图的gc监控情况，我们可以发现 gc 过后有个别机器内存占用大幅减少，甚至可以观察到某些broker明显重启了。此时观察gc异常的broker已经crash了，因此我们可以判断crash可能和gc有关。

2、通过分析gc日志，full gc之前新生代、老生代使用率都不高，gc次数也不是很频繁，因此 GC Locker 基本没有可能，那么最有可能的就是System GC了。那什么情况下会发生 System GC 呢？

• 代码显示调用；

• RMI（Remote Method Invocation）里定时调用；

• 堆外内存不够导致的调用；

这几种情况基本都可以排除：

• kafka 为 scala 语言写的，通过翻看kafka代码，未发现System GC的显示调用；

• RMI（Remote Method Invocation）也不可能，因为我们从线程列表里看不到GC Deamon线程，因此不存在RMI调用；

• 堆外内存主要是说 DirectByteBuffer，这也不太可能。因为我们从 JVM 参数来看，第一没有设置最大值MaxDirectMemorySize，第二Xmx设置为40G，那默认堆外内存最大值差不多也这么大。通过下图我们发现 DirectByteBuffer 占用不到200MB，所以堆外内存满了而导致的System GC也基本可以排除。

3、kafka由scala语言编写，依赖了JDK。通过翻看 JDK 代码，寻找可能抛出 System GC 的情况，结果发现了 `sun.nio.ch.FileChannelImpl` 的 map 方法里有类似的逻辑。

04

确定问题现场

1、我们看下 sun.nio.ch.FileChannelImpl.map0 的 native 方法实现 Java_sun_nio_ch_FileChannelImpl_map0，因为这是触发 crash 的地方，然后看到下面的逻辑。因为 crash 的时候确实是抛出了一个 OOM 的异常，因此我们完全可以确定 mmap 返回的 errno 是 ENOMEM 。所以我们在前面提出的，warning日志中没有打印出来的具体 mmap 异常，从这个地方也基本可以确认 mmap 异常返回了 ENOMEM 这个错误码。

2、下面是 mmap 的手册里关于 ENOMEM 的介绍

ENOMEM：没有可用的内存。

ENOMEM将超过该进程的最大映射数。当在现有映射的中间取消映射区域时，munmap() 也可能发生此错误，

因为这会导致在该区域的任一侧取消两个较小的映射。

3、我们确认了物理内存是足够的，因此我们只能怀疑是否达到了 mappings 的最大个数，我们再结合下 kernel 里的 mmap 的实现（`mm/mmap.c:do_mmap`）。通过 mmap 的实现，我们发现当 mmap 的 vma（virtual memory areas） 个数达到了最大值的时候确实会返回 ENOMEM，于是确认了下 `/proc/sys/vm/max_map_count` 的值为 65530。也就是说我们 mmap 的 vma（virtual memory areas）最多只能是 65530 个，再统计下  java core dump 文件里虚拟地址映射的个数（Dynamic libraries下面的条数）正好为 65531，刚好达到这个上限。

经过上面的分析过程，我们确定了案发现场：

kafka 做了很多索引文件的内存映射，并且这些索引文件一直占着内存没有释放，随着索引文件数的增多，而慢慢达到了内存的一个上限。每次创建一个索引文件都会触发 mmap 系统调用，而在 mmap 的时候 check 是否达到了 vma（virtual memory areas）的最大限制，也就是  /proc/sys/vm/max_map_count 里的 65530，如果超过了，就直接 crash 了。

05

解决方案

通过排查我们的解决方案有下面两种思路：

• 增大系统限制 /proc/sys/vm/max_map_count；

• kafka 的索引文件是否不需要一直有？是否可以限制一下？kafka 在读取消息时，要通过索引文件中的索引定位消息。如果对于读取频率相对低的消息释放索引文件的引用，当读取历史数据时需要重新遍历数据文件重建索引，这个过程磁盘IO开销比较大，会严重影响 kafka 的吞吐。因此我们选择增大系统参数 /proc/sys/vm/max_map_count ；