介绍一下使用NMT协助排查内存问题的案例

从前面几篇文章，我们了解了 NMT 的基础知识以及 NMT 追踪区域分析的相关内容，本篇文章将为大家介绍一下使用 NMT 协助排查内存问题的案例。

6.使用 NMT 协助排查内存问题案例

我们在搞清楚 NMT 追踪的 JVM 各部分的内存分配之后，就可以比较轻松的协助排查定位内存问题或者调整合适的参数。

可以在 JVM 运行时使用 jcmd VM.native_memory baseline 创建基线，经过一段时间的运行后再使用 jcmd VM.native_memory summary.diff/detail.diff 命令，就可以很直观地观察出这段时间 JVM 进程使用的内存一共增长了多少，各部分使用的内存分别增长了多少，可以很方便的将问题定位到某一具体的区域。

比如我们看到 MetaSpace 的内存增长异常，可以结合 MAT 等工具查看是否类加载器数量异常、是否类重复加载、reflect 的 inflation 参数设置是否合理；如果 Symbol 内存增长异常，可以查看项目 String.intern 是否使用正常；如果 Thread 使用内存过多，考虑是否可以适当调整线程堆栈大小等等。

案例一：虚高的 VIRT 内存

我们还记得前文（NMT 内存 & OS 内存概念差异性章节）中使用 top 命令查看启动的 JVM 进程，仔细观察会发现一个比较虚高的 VIRT 内存（10.7g），我们使用 NMT 追踪的 Total: reserved 才 2813709KB（2.7g），这多出来的这么多虚拟内存是从何而来呢？

top

PIDUSERPRNIVIRTRESSHRS%CPU%MEMTIME+COMMAND
27420douyiwa+20010.7g69756017596S100.00.30:18.79java

NativeMemoryTracking:

Total:reserved=2813077KB,committed=1496981KB

使用pmap -X 观察内存情况:

27420:java-Xmx1G-Xms1G-XX:+UseG1GC-XX:MaxMetaspaceSize=256M-XX:MaxDirectMemorySize=256M-XX:ReservedCodeCacheSize=256M-XX:NativeMemoryTracking=detail-jarnmtTest.jar
AddressPermOffsetDeviceInodeSizeRssPssReferencedAnonymousLazyFreeShmemPmdMappedShared_HugetlbPrivate_HugetlbSwapSwapPssLockedMapping
c0000000rw-p0000000000:00010490886372366372366372366372360000000
100080000---p0000000000:000104806400000000000
aaaaea835000r-xp00000000fd:0245613083444400000000java
aaaaea854000r--p0000f000fd:0245613083444440000000java
aaaaea855000rw-p00010000fd:0245613083444440000000java
aaab071af000rw-p0000000000:0003041081081081080000000[heap]
fffd60000000rw-p0000000000:00013244440000000
fffd60021000---p0000000000:0006540400000000000
fffd68000000rw-p0000000000:00013288880000000
fffd68021000---p0000000000:0006540400000000000
fffd6c000000rw-p0000000000:00013244440000000
fffd6c021000---p0000000000:0006540400000000000
fffd70000000rw-p0000000000:000132404040400000000
fffd70021000---p0000000000:0006540400000
......

可以发现多了很多 65404 KB 的内存块（大约 120 个），使用 /proc//smaps 观察内存地址：

......
fffd60021000-fffd64000000---p0000000000:000
Size:65404kB
KernelPageSize:4kB
MMUPageSize:4kB
Rss:0kB
Pss:0kB
Shared_Clean:0kB
Shared_Dirty:0kB
Private_Clean:0kB
Private_Dirty:0kB
Referenced:0kB
Anonymous:0kB
LazyFree:0kB
AnonHugePages:0kB
ShmemPmdMapped:0kB
Shared_Hugetlb:0kB
Private_Hugetlb:0kB
Swap:0kB
SwapPss:0kB
Locked:0kB
VmFlags:mrmwmenr
......

对照 NMT 的情况，我们发现如 fffd60021000-fffd64000000 这种 65404 KB 的内存是并没有被 NMT 追踪到的。这是因为在 JVM 进程中，除了 JVM 进程自己 mmap 的内存（如 Java Heap，和用户进程空间的 Heap 并不是一个概念）外，JVM 还直接使用了类库的函数来分配一些数据，如使用 Glibc 的 malloc/free (也是通过 brk/mmap 的方式)：

既然 JVM 使用了 Glibc 的 malloc/free，就不得不提及 malloc 的机制，早期版本的 malloc 只有一个 arena（分配区），每次分配时都要对分配区加锁，分配完成之后再释放，这就导致了多线程的情况下竞争比较激烈。

所以 malloc 改动了其分配机制，甚至有了 arena per-thread 的模式，即如果在一个线程中首次调用 malloc，则创建一个新的 arena，而不是去查看前面的锁是否会发生竞争，对于一定数量的线程可以避免竞争在自己的 arena 上工作。

arena 的数量限制在 32 位系统上是 2 * CPU 核心数，64 位系统上是 8 * CPU 核心数，当然我们也可以使用 MALLOC_ARENA_MAX （Linux 环境变量，详情可以查看 mallopt(3)[1]）来控制。

查看发现运行 JVM 进程的环境 CPU 信息（物理 CPU 核数）：Core(s) per socket: 64 。

我们给当前环境设置 MALLOC_ARENA_MAX=2，重启 JVM 进程，查看使用情况：

top

PIDUSERPRNIVIRTRESSHRS%CPU%MEMTIME+COMMAND
36319douyiwa+200310834069087217828S100.00.30:07.61java

虚高的 VIRT 内存已经降下来了，继续查看 pmap/smaps 会发现众多的 65404 KB 的内存空间也消失了（120 * 65404 KB = 7848480 KB 正好对应了 10.7g - 3108340 KB 的内存，即 VIRT 降低的内存）。

为什么我们的 JVM 进程会使用如此多的 arena 呢？因为我们在启动 JVM 进程的时候，并没有手动去设置一些进程的数目，如：CICompilerCount（编译线程数）、ConcGCThreads/ParallelGCThreads（并发 GC 线程数）、G1ConcRefinementThreads（G1 Refine 线程数）等等。

这些参数大多数根据当前机器的 CPU 核数去计算默认值，使用 jinfo -flags 查看机器参数发现：

-XX:CICompilerCount=18
-XX:ConcGCThreads=11
-XX:G1ConcRefinementThreads=43

这些线程数目都是比较大的，我们也可以不修改 MALLOC_ARENA_MAX 的数量，而通过参数减小线程的数量来减少 arena 的数量。

Glibc 的 malloc 有时会出现碎片问题，可以使用 jemalloc/tcmalloc 等替代 Glibc。

案例二：堆外内存的排查

有时候我们会发现，Java 堆、MetaSpace 等区域是比较正常的，但是 JVM 进程整体的内存却在不停的增长，此时我们就可以使用 NMT 的 baseline & diff 功能来观察究竟是哪块区域内存一直增长。

比如在一次案例中发现：

NativeMemoryTracking:
Total:reserved=8149334KB+1535794KB,committed=6999194KB+1590490KB
......
-Internal(reserved=1723321KB+1472458KB,committed=1723321KB+1472458KB)
(malloc=1723289KB+1472458KB#109094+47573)
(mmap:reserved=32KB,committed=32KB)
......
[0x00007fceb806607a]Unsafe_AllocateMemory+0x17a
[0x00007fcea1d24e68]
(malloc=1485579KBtype=Internal+1455929KB#2511+2277)
......

我们可以确认内存 1590490KB 的增长，基本上都是由 Internal 的 Unsafe_AllocateMemory 所分配的，此时可以优先考虑 NIO 中 ByteBuffer.allocateDirect / DirectByteBuffer / FileChannel.map 等使用方式是不是出现了泄漏，可以使用 MAT 查看 DirectByteBuffer 对象的数量是否异常，并可以使用 -XX:MaxDirectMemorySize 来限制 Direct 的大小。

设置 -XX:MaxDirectMemorySize 之后，进程异常的内存增长停止，但是 GC 频率变高，查看 GC 日志发现：.887+0800: 238210.127: [Full GC (System.gc()) 1175M->255M(3878),0.8370418 secs]。

FullGC 的频率大大增加，并且基本上都是由 System.gc() 显式调用引起的（HotSpot中的System.gc()为 FulGC），查看 DirectByteBuffer 相关逻辑：

#DirectByteBuffer.java

DirectByteBuffer(intcap){//package-private
......
Bits.reserveMemory(size,cap);

longbase=0;
try{
base=unsafe.allocateMemory(size);
}catch(OutOfMemoryErrorx){
Bits.unreserveMemory(size,cap);
throwx;
}
unsafe.setMemory(base,size,(byte)0);
if(pa&&(base%ps!=0)){
//Rounduptopageboundary
address=base+ps-(base&(ps-1));
}else{
address=base;
}
cleaner=Cleaner.create(this,newDeallocator(base,size,cap));
att=null;
}

#Bits.java

staticvoidreserveMemory(longsize,intcap){
......
System.gc();
......
}

DirectByteBuffer 在 unsafe.allocateMemory(size) 之前会先去做一个 Bits.reserveMemory(size, cap) 的操作，Bits.reserveMemory 会显式的调用 System.gc() 来尝试回收内存，看到这里基本可以确认为 DirectByteBuffer 的问题，排查业务代码，果然发现一处 ByteBufferStream 使用了 ByteBuffer.allocateDirect 的方式而流一直未关闭释放内存，修正后内存增长与 GC 频率皆恢复正常。

审核编辑：刘清