[OOM] hbase堆外内存溢出底层定位

快来打我* 2022-03-29 17:24 691阅读 0赞

> 下文所说的 hbase client 版本，如无特指，则皆为 1.2.3。

之前项目中出现堆外内存溢出（[排查过程][Link 1]），虽然已经解决了问题，但当时没有深究底层的原理，最近抽空从底层入手，深入研究了 hbase client 读写源码，配合 jmeter 压测特定接口，并使用 mat 等工具分析，最终定位到了 hbase 堆外内存溢出的根本原因，本次就梳理下完整的过程，以及涉及的一些原理，防止以后踩坑。

# 一.溢出现象 #

单台服务器刚发布时 java 进程占用3g，以一天5%左右的速度增长，一定时间过后进程占用接近90%，触发服务器报警，而此时 old 区占用在 50%，未触发 CMS GC，而导致堆外内存溢出。

异常堆栈：

![20190109093506363.png][]

top 命令查看进程占用：

![20180918144334159][]

机器为 8核16G，JVM配置如下:

-Xms8g -Xmx8g -Xmn3g -Xss512k 
    -XX:MetaspaceSize=256m 
    -XX:MaxMetaspaceSize=512m 
    -XX:+UseConcMarkSweepGC 
    -XX:+DisableExplicitGC 
    -XX:-UseGCOverheadLimit
    -XX:+UseCMSInitiatingOccupancyOnly 
    -XX:CMSInitiatingOccupancyFraction=70
    -XX:+CMSParallelRemarkEnabled 
    -XX:+UseFastAccessorMethods

# 二.排查过程&原理分析 #

## 1.初步分析 ##

根据异常堆栈，可以看出是 hbase.write() 分配直接内存导致的堆外内存溢出。而直接内存分配空间不足时，会调用 System.gc()，由于 JVM 参数配置了 -XX:+DisableExplicitGC 禁用了 System.gc()，且 old 区占用才50%，未达到 CMS GC 阈值，因此抛出堆外内存溢出。

![20190109094033857.png][]

粗略的堆外内存计算方式：JVM 未设置直接内存大小参数 -XX:MaxDirectMemorySize, 则 CMS GC堆外内存为：old 区 - 1个survivor 区， 即 8G - 314M = 7.8G。

## 2.压测主要接口 ##

因为不能用线上机器做实验，且不能确定是否有其他因素导致溢出。于是在性能环境使用 jmeter 压测应用主要接口，并观察堆外内存占用。

压测后发现堆外内存占用平稳，未出现溢出现象。

## 3.释放 hbase client 资源 ##

此时将目光放到异常堆栈上，并查看系统封装的 hbase client ，发现使用完 HTable 后未调用 close() 释放资源，于是加上 close() 代码，并上线观察。但仍然出现溢出现象。

![20180928192051831][]

## 4.压测特定功能 ##

虽然不是hbase client使用的问题，但还是有相同的堆栈，说明 hbase 肯定有问题。

查找资料，发现 hbase 官方的 issue 列表里有一个堆外内存溢出的 case ([hbase direct memory leak issue][])。发现如果使用 jdk 的 HeapByteBuffer，在网络IO时，由于用户空间不能直接访问内核空间，因此会复制一个临时的 DirectByteBuffer 对象进行IO，且用 ThreadLocal 缓存该对象。如果使用多线程进行大数据量的网络IO，则可能导致内存溢出。

![2019010909513671.png][]

于是查看 hbase 源码，发现确实使用的是 HeapByteBuffer，使用 jVisualVM 查看 dump 文件中 java.nio.DirectByteBuffer 类的 GC Roots，发现是 HConnection 线程对象，而该对象在项目初始化时创建，并一直存活：

![20190109095441852.png][]

于是单独压测这两个接口，一次性读写10M左右的数据，并使用 gperftools 观察堆外内存占用。运行半小时出现溢出现象，观察 gperftools 文件，使用 malloc 分配堆外内存达到了 7900M:

![2019010909564313.png][]

至此复现了堆外内存溢出的现象，确实是 hbase 读写导致的。

## 5.升级 hbase client 至 2.1.0 ##

找到了泄露的点，那么解决方案就出来了：  
不使用 HeapByteBuffer 或复用 DirectByteBuffer : 升级 base client 至 2.x，默认使用 netty  
限制 jdk 缓存的堆外内存大小：jdk 升级至 jdk 9

考虑改动成本，将 hbase client 版本升级至 2.1.0，线上运行一段时间，系统稳定，无溢出现象。

## 6.主要是哪里申请的堆外内存呢？ ##

虽然已经解决了这个问题，但还有几个疑问：  
压测脚本是使用 hbase 同时读写，那么到底是读，还是写造成的泄露？还是两者都有泄露？  
hbase 读、写的溢出对应的是源码底层的哪一段，或是哪几段逻辑呢？  
带着这些疑问，查看了一下 hbase client 读写的源码。

### 1) hbase 写的源码 ###

主要分为获取 HTable、mutate、flushCommits 三个部分:

![20190109110555288.png][]

获取 HTable 会创建一个默认线程数256的线程池，并且创建一个新的 HTable 对象：

![20190109110642705.png][]

mutate 操作会将待写入的数据放到一个本地的 writeAsyncBuffer 缓存起来：

![2019010911080937.png][]

flushCommits 操作将 writeAsyncBuffer 中的数据写入到 hbase。这个过程中，hbase 把写入任务 SingleServerRequestRunnable 线程提交给线程池完成，调用方 wait 结果：

![2019010911085629.png][]

在 SingleServerRequestRunnable 线程中，调用 MultiServerCallable\#call 方法，默认的 rpc 实现类为 RpcClientImpl( tracedWriteRequest 中会调用 setupIOstreams 方法建立连接)，数据通过 HeapByteBuffer，经由 nio 的 SocketChannelImpl 写入，并循环调用 IOUtil.write() 方法，分配临时的堆外内存，造成泄露，整体流程为：

![SingleServerRunnable][]

由于传入的 totalSize 为写入数据的大小(10M)，因此 IOUtil.write() 申请的 DirectByteBuffer 大小为传入的大小（此处 HeapByteBuffer 的 limit 为 10338890，10M左右）:

![IOUtil.write()][IOUtil.write]

这里的线程池为前面获取 HTable 创建的，核心线程数默认256，那么最大占用堆外内存=256\*10=2560M，未达到溢出的量。是不是还有其他地方在分配堆外内存呢？

### 2) hbase 读的源码 ###

HTable.get() 通过匿名内部类的方式实现了 RetryingCallable  
\#call() 接口，在 RpcClientImpl\#call 方法内被调用，向 hbase 发送读请求之前初始化 socket 连接，并启动 RpcClientImpl.Connection 线程，接收数据。其中发起请求流程和 hbase 写的流程一样:

![hbase.get()][hbase.get]

断点查看 IOUtil.read() 一次读取的字节数为 8192:

![IOUtil.read()][IOUtil.read]

查看 BufferedInputStream 类默认一次读取的字节数为 8192：

![BufferedInputStream][]

因此虽然调用了 IOUtil.read() 也不会占用太大的堆外内存，而且由于 RpcClientImpl.Connection 线程接收完数据就消亡了，持有的堆外内存也会被 gc 回收。因此 hbase 读不会造成堆外内存泄露。

## 7.分析性能环境 dump 文件 ##

到这里，可以确定 hbase 写会造成泄露，但目前造成泄露的内存量远大于前面分析的值。查看性能环境的 dump 文件，使用 OQL 语句查看 java.nio.DirectByteBuffer 的数量和大小，发现占据 10M 空间的对象数量有 788个，总内存大约为=10338894\*788=7800M：

![OQL][]

查看 java.nio.DirectByteBuffer 对象的 GC Roots，发现大量对象只有 cleaner 引用:

![Cleaner][]

Cleaner 为 PhantomReference 的子类，在创建 DirectByteBuffer 对象时被创建。虚引用的作用在于跟踪垃圾回收过程，如果 GC 时发现一个对象的 GC Roots 只有虚引用，那么会将这个虚引用加入引用队列(ReferenceQueue)，系统有个后台线程 Reference.ReferenceHandler 会从这个队列获取 Cleaner 对象，调用它的 clean 方法，释放资源：

![clean()][clean]

现在有大量的不可达对象，说明持有堆外内存的线程对象消亡了，但资源未被回收。jstat 查看 GC 情况，发现未进行 FGC，说明这些对象都进入了 old 区，而导致大量的堆外内存不能被释放，造成溢出。

而根据前面的分析，会持有堆外内存对象引用的只有 hconnection 线程池中的线程。于是仔细的再梳理一遍 hbase 写的链路，发现处理网络 IO 任务的线程池，创建的时候设置了allowCoreThreadTimeOut 为 true，允许核心线程消亡，keepAliveTime 为60s:

![20190109112155195.png][]

继续用 jmeter 压测 hbase 写接口，并使用 jstack 观察 hconnection 线程的情况，发现以1s一个线程的速度进行写入时，hconnection 线程数保持在60左右，只有一个线程是活跃的，其他线程都是等待状态(waiting)，且线程 count 数一直累加，说明进程一直在创建新线程并且一直有线程在消亡：

![threads' state][threads_ state]

再查看线程池 ThreadPoolExecutor 源码，当线程池内活跃线程数少于核心线程数时，有新请求进来，会直接创建一个新的线程处理：

![core thread][]

到这里基本定位到了泄露的原因了。

## 8.总结 ##

导致 hbase 堆外内存溢出的主要是下面几个条件**共同作用**的结果：

1.  **默认的 RpcClientImpl** 中使用了 **HeapByteBuffer**: 网络IO时数据会复制到堆外内存
2.  **sun.nio.ch.Util** 类会缓存堆外内存大小，且使用 **ThreadLocal** 方式: 引用由线程持有
3.  异步写的线程池设置 **allowCoreThreadTimeOut** 为 true: 导致线程频繁消亡
4.  写入的频率
5.  JVM 未进行 FGC: 已进入 old 区的不可达的线程对象，持有的堆外内存资源无法被回收

关于第四点，单独压测写入接口时，未限制频率，导致堆外内存到 3.5g 左右时，系统就直接进行 FGC 了，由于回收了堆外内存资源，因此未出现堆外内存溢出现象。

**完整导致流程描述**：hbase 创建的线程池内的线程使用 HeapByteBuffer 存储数据，网络IO前会将数据复制到堆外内存对象 DirectByteBuffer 中；而 jdk 会以 ThreadLocal 的方式缓存该 DirectByteBuffer 对象申请的堆外内存，如果线程不消亡则不释放该内存；同时该线程池允许核心线程消亡，当业务方以一定的频率调用 hbase 写接口时，导致有些线程对象消亡并进入 Old 区；由于未进行 FGC，这些线程对象无法被回收，占用的堆外内存资源也无法被 GC 回收。一段时间后，造成堆外内存溢出。

对象进入 Old 区有很多可能，比如：

*  Eden 区空间不足
 *  长期存活对象进入 Old 区(线上查看存活年龄配置: jinfo -flag MaxTenuringThreshold = 6)

梳理到这里，那么**解决方案**就多了几种，比如：

1.  配置 RpcClient 实现为 AsyncRpcClient (使用 netty 方式，性能环境已验证)
2.  使用 Connection\#getTable(tableName, pool) 传入自定义的线程池，设置allowCoreThreadTimeOut 为false，并限制每次写入的大小 (已验证)
3.  提高核心线程消亡时间
4.  控制 hbase 写入的频率
5.  调低FGC 的阈值
6.  调大JVM年龄计数器

以上就是完整的流程了，如有疑问可与我交流。

# 三.工具简介 #

前面排查堆外内存溢出的过程中，使用了很多工具，主要有：

*  jdk 命令行工具: jps, jstat, jmap
 *  jdk 提供的内存监控工具: jConsole, jVisualVM
 *  eclipse 提供的内存分析工具: mat
 *  google 的监控堆外内存工具: gperftools
 *  性能压测工具: jmeter
 *  查看进程内存: smaps, pmap, gdb
 *  sun 推出的针对 java 的动态追踪工具: btrace

具体的工具用法就不介绍了，可自行搜索资料。

# 四.后记 #

已反馈至 [hbase issue][hbase direct memory leak issue]:

![hbase issue][]

# 参考资料 #

[《深入理解Java虚拟机》][Java]  
[堆外内存完全解读][Link 2]  
[hbase direct memory leak issue][]  
[java byte buffer leak][]  
[jdk 8u102 update release notes: add MaxCachedBufferSize][jdk 8u102 update release notes_ add MaxCachedBufferSize]  
[记一次堆外内存排查过程][Link 3]  
[内存溢出分析之垃圾回收知识][Link 4]  
[内存溢出分析之工具篇][Link 5]  
[体系化认识RPC][RPC]  
[IO模型][IO]  
[线程模型][Link 6]

[Link 1]: https://blog.csdn.net/u012099869/article/details/82757999
[20190109093506363.png]: /images/20220329/eda2e57867d34cc5b7eaea5e3b4196ab.png
[20180918144334159]: /images/20220329/d6724df3cdf84615865464261d1a7a4d.png
[20190109094033857.png]: /images/20220329/daa36f8673ed4e479708f413d92385ac.png
[20180928192051831]: /images/20220329/2a7930d31f724a2da74c54fd3232abb1.png
[hbase direct memory leak issue]: https://issues.apache.org/jira/browse/HBASE-19320
[2019010909513671.png]: /images/20220329/24af0c75179248ed87a379b70d06cc3f.png
[20190109095441852.png]: /images/20220329/44b19e09365f4d75b5caf7264e3a86d4.png
[2019010909564313.png]: /images/20220329/d91eaf129bb348d28baafb32ce1d64cd.png
[20190109110555288.png]: /images/20220329/b19d928d2fac4d61b21d5cae45928def.png
[20190109110642705.png]: /images/20220329/e23a48fee4d440b6b393c5ae7bac08ea.png
[2019010911080937.png]: /images/20220329/b68d094be65c480fbd3b1e0893c6db80.png
[2019010911085629.png]: /images/20220329/95e32825a0414b36b12f07d4c8422b52.png
[SingleServerRunnable]: /images/20220329/0786c1733aa541d790449904fc9dbd6f.png
[IOUtil.write]: /images/20220329/b664ddae7e844656b08fc229bcc47f2b.png
[hbase.get]: /images/20220329/432b9e7f606b46b097d6437d146d9818.png
[IOUtil.read]: /images/20220329/5d94b25a1ef446d49a4ab8ac3fa49141.png
[BufferedInputStream]: /images/20220329/a5d174045bd646e9af92635e4af1cdee.png
[OQL]: /images/20220329/0d631c9fee134fca858a88d1111d34cb.png
[Cleaner]: /images/20220329/ab66e86893b34accaa309e67a7ca2240.png
[clean]: /images/20220329/5d443db37ef34e4286553db09164ca1c.png
[20190109112155195.png]: /images/20220329/a8e21915d57649bf9f24afb5f304ca56.png
[threads_ state]: /images/20220329/ef4b4d631edb4f879c6a8acb179c8a81.png
[core thread]: /images/20220329/1302ac5a697c438e8848dbe2317572ff.png
[hbase issue]: /images/20220329/225c07d46faa4206978f05e04c625537.png
[Java]: http://product.dangdang.com/23259731.html#ddclick_search_searchinput
[Link 2]: http://lovestblog.cn/blog/2015/05/12/direct-buffer/
[java byte buffer leak]: http://www.evanjones.ca/java-bytebuffer-leak.html
[jdk 8u102 update release notes_ add MaxCachedBufferSize]: https://www.oracle.com/technetwork/java/javase/8u102-relnotes-3021767.html?printOnly=1
[Link 3]: https://blog.csdn.net/u012099869/article/details/82757999#t13
[Link 4]: https://blog.csdn.net/u012099869/article/details/82870082#t15
[Link 5]: https://blog.csdn.net/u012099869/article/details/82870050#t1
[RPC]: https://www.infoq.cn/article/get-to-know-rpc
[IO]: http://www.52im.net/thread-1935-1-1.html
[Link 6]: http://www.52im.net/thread-1939-1-1.html