问题复现

import java.util.UUID;
import java.util.concurrent.locks.LockSupport;

public class StringInterner {
    public static volatile String lastString;

    public static void main(String[] args) {
        for (int iterations = 0; iterations < 40;) {
            String baseName = UUID.randomUUID().toString();
            for (int i = 0; i < 1000000; i++) {
                lastString = (baseName + i).intern();
            }
            if (++iterations % 10 == 0) {
                System.gc();
            }
            LockSupport.parkNanos(500000000);
        }
    }
}

将代码编译(javac)打包(jar)后分别使用G1和CMS运行:

java -XX:NativeMemoryTracking=detail -XX:+UnlockDiagnosticVMOptions -XX:+PrintNMTStatistics -XX:+UseG1GC -XX:MetaspaceSize=100m -XX:MaxMetaspaceSize=100m -Xloggc:gc-jdk8-g1.log -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xms256m -Xmx256m -cp classes StringInterner
-->
Symbol (reserved=360278KB, committed=360278KB)
                            (malloc=359758KB #44949) 
                            (arena=520KB #1)
java -XX:NativeMemoryTracking=detail -XX:+UnlockDiagnosticVMOptions -XX:+PrintNMTStatistics -XX:MetaspaceSize=100m -XX:MaxMetaspaceSize=100m -XX:+UseStringDeduplication -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -Xloggc:gc-jdk8-marksweep.log -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xms256m -Xmx256m -cp classes StringInterner
-->
Symbol (reserved=20830KB, committed=20830KB)
                            (malloc=20310KB #2518) 
                            (arena=520KB #1)

上面的代码模拟了填充字符串缓存池的过程, 这里引出了java8(1.8.0_144-b01可复现,具体可见Bug描述补丁进度)中的一个G1垃圾收集器的bug:维护字符串缓冲区的数据结构内存泄漏(G1垃圾收集器)。

问题解释

在java6时代,字符串缓存区是放在永久代也就是MetaSpace中的,并且是一个固定大小,因此在java6中应该谨慎使用String.intern()方法, 以免造成OOM;
java7以后,字符串缓存区移到了堆内存中,同时可以进行垃圾回收。原文见:

the issue is that some C++ helper data structure for managing the interned string list leaks in G1; it is shown in the "Symbol" category in NMT output, but that has nothing to do with Metaspace.

NMT

NMT = Native Memory Tracking 本地内存跟踪
NMT是Java HotSpot VM提供的跟踪内部内存使用的工具,结合jcmd命令可以在不同级别上分析内存的使用, NMT的关键特性有:

  • NMT默认在HotSpot上是关闭的,要打开需要使用-XX:NativeMemoryTracking=summary 或者-XX:NativeMemoryTracking=detail
  • 内存跟踪数据可以使用jcmd命令查看,具体用法jcmd <pid> VM.native_memory [summary | detail | baseline | summary.diff | detail.diff | shutdown] [scale= KB | MB | GB]
  • NMT可以生成汇总和明细内存数据
  • 建立内存基线方便后面进行对比
  • JVM退出时可以输出内存使用报告, 具体用法-XX:+UnlockDiagnosticVMOptions -XX:+PrintNMTStatistics
  • NMT可以使用jcmd工具关闭,但无法start或者restart
  • NMT无法跟踪非java代码分配的内存,例如native方法

使用NMT检测内存泄漏

  • 开启NMT , -XX:NativeMemoryTracking=summary 或者-XX:NativeMemoryTracking=detail
  • 使用jcmd <pid> VM.native_memory baseline建立内存基线
  • 使用jcmd <pid> VM.native_memory detail.diff检测内存变化
  • 如果内存泄漏比较缓慢,那么需要多等待一会儿

读懂NMT输出的数据

下表展示了NMT的的内存分类

Category Description
Java Heap
Class 类元数据
Code 代码
GC GC使用的数据,例如卡表
Compiler 编译器生成代码使用的内存
Symbol 符号,例如变量名
Memory Tracking NMT
Pooled Free Chunks Arena内存块池使用
Shared space for classes 类共享存档映射的内存
Thread 线程使用,包括线程数据结构,资源区和句柄区
Thread stack 线程堆栈,被标记为已提交
Internal 不在以上类别,例如命令行解释器
Unknown 无法确定的内存

准备知识

committed已提交内存是实际使用的,例如-Xms100m -Xmx1000m,那么jvm会reserve 1000MB,因为初始内存为100MB, 因此committed 100MB
Arena是一块使用malloc分配出来的内存。当退出范围或离开代码区域时,内存会从这些块中大量释放。这些块可以在其他子系统中重用,以保存临时内存,例如线程前分配。Arena malloc策略确保没有内存泄漏。因此Arena是作为一个整体而不是单个对象进行跟踪的。某些初始内存无法被跟踪。
需要注意的是启用NMT会降低机器5%到10%的性能,并且会带来内存使用的提升,因为NMT会在每个malloc的内存头部添加2 machine words作为malloc header, NMT使用的内存也会被NMT追踪。文档原话如下:

Enabling NMT will result in a 5-10 percent JVM performance drop and memory usage for NMT adds 2 machine words to all malloc memory as malloc header. NMT memory usage is also tracked by NMT.


NMT汇总数据

使用NMT追踪内存分配汇总数据需要使用-XX:NativeMemoryTracking=summary开启
然后使用jcmd <pid> VM.native_memory summary打印汇总数据,样例如下:

Total:  reserved=664192KB,  committed=253120KB                                           <--- NMT追踪的总内存
 
-                 Java Heap (reserved=516096KB, committed=204800KB)                      <--- 堆内存
                            (mmap: reserved=516096KB, committed=204800KB)
 
-                     Class (reserved=6568KB, committed=4140KB)                          <--- 类的元数据
                            (classes #665)                                               <--- 类加载数 665
                            (malloc=424KB, #1000)                                        <--- malloc分配的内存大小,malloc数1000
                            (mmap: reserved=6144KB, committed=3716KB)
 
-                    Thread (reserved=6868KB, committed=6868KB)
                            (thread #15)                                                 <--- 线程数
                            (stack: reserved=6780KB, committed=6780KB)                   <--- 线程堆栈使用内存数
                            (malloc=27KB, #66)
                            (arena=61KB, #30)                                            <--- 资源&句柄
 
-                      Code (reserved=102414KB, committed=6314KB)
                            (malloc=2574KB, #74316)
                            (mmap: reserved=99840KB, committed=3740KB)
 
-                        GC (reserved=26154KB, committed=24938KB)
                            (malloc=486KB, #110)
                            (mmap: reserved=25668KB, committed=24452KB)
 
-                  Compiler (reserved=106KB, committed=106KB)
                            (malloc=7KB, #90)
                            (arena=99KB, #3)
 
-                  Internal (reserved=586KB, committed=554KB)
                            (malloc=554KB, #1677)
                            (mmap: reserved=32KB, committed=0KB)
 
-                    Symbol (reserved=906KB, committed=906KB)
                            (malloc=514KB, #2736)
                            (arena=392KB, #1)
 
-           Memory Tracking (reserved=3184KB, committed=3184KB)
                            (malloc=3184KB, #300)
 
-        Pooled Free Chunks (reserved=1276KB, committed=1276KB)
                            (malloc=1276KB)
 
-                   Unknown (reserved=33KB, committed=33KB)
                            (arena=33KB, #1)

NMT明细数据

使用-XX:NativeMemoryTracking=detail开启明细追踪,NMT会追踪分配内存最多的几个方法,然后使用jcmd <pid> VM.native_memory detail打印明细数据,样例如下:

Virtual memory map:
 
[0x8f1c1000 - 0x8f467000] reserved 2712KB for Thread Stack
                from [Thread::record_stack_base_and_size()+0xca]
        [0x8f1c1000 - 0x8f467000] committed 2712KB from [Thread::record_stack_base_and_size()+0xca]
 
[0x8f585000 - 0x8f729000] reserved 1680KB for Thread Stack
                from [Thread::record_stack_base_and_size()+0xca]
        [0x8f585000 - 0x8f729000] committed 1680KB from [Thread::record_stack_base_and_size()+0xca]
 
[0x8f930000 - 0x90100000] reserved 8000KB for GC
                from [ReservedSpace::initialize(unsigned int, unsigned int, bool, char*, unsigned int, bool)+0x555]
        [0x8f930000 - 0x90100000] committed 8000KB from [PSVirtualSpace::expand_by(unsigned int)+0x95]
 
[0x902dd000 - 0x9127d000] reserved 16000KB for GC
                from [ReservedSpace::initialize(unsigned int, unsigned int, bool, char*, unsigned int, bool)+0x555]
        [0x902dd000 - 0x9127d000] committed 16000KB from [os::pd_commit_memory(char*, unsigned int, unsigned int, bool)+0x36]
 
[0x9127d000 - 0x91400000] reserved 1548KB for Thread Stack
                from [Thread::record_stack_base_and_size()+0xca]
        [0x9127d000 - 0x91400000] committed 1548KB from [Thread::record_stack_base_and_size()+0xca]
 
[0x91400000 - 0xb0c00000] reserved 516096KB for Java Heap                                                                            <--- 保留的内存地址范围
                from [ReservedSpace::initialize(unsigned int, unsigned int, bool, char*, unsigned int, bool)+0x190]                  <--- 保留内存的方法调用(callsite)
        [0x91400000 - 0x93400000] committed 32768KB from [VirtualSpace::initialize(ReservedSpace, unsigned int)+0x3e8]               <--- 已提交的内存以及方法调用
        [0xa6400000 - 0xb0c00000] committed 172032KB from [PSVirtualSpace::expand_by(unsigned int)+0x95]
 
[0xb0c61000 - 0xb0ce2000] reserved 516KB for Thread Stack
                from [Thread::record_stack_base_and_size()+0xca]
        [0xb0c61000 - 0xb0ce2000] committed 516KB from [Thread::record_stack_base_and_size()+0xca]
 
[0xb0ce2000 - 0xb0e83000] reserved 1668KB for GC
                from [ReservedSpace::initialize(unsigned int, unsigned int, bool, char*, unsigned int, bool)+0x555]
        [0xb0ce2000 - 0xb0cf0000] committed 56KB from [PSVirtualSpace::expand_by(unsigned int)+0x95]
        [0xb0d88000 - 0xb0d96000] committed 56KB from [CardTableModRefBS::resize_covered_region(MemRegion)+0xebf]
        [0xb0e2e000 - 0xb0e83000] committed 340KB from [CardTableModRefBS::resize_covered_region(MemRegion)+0xebf]
 
[0xb0e83000 - 0xb7003000] reserved 99840KB for Code
                from [ReservedSpace::initialize(unsigned int, unsigned int, bool, char*, unsigned int, bool)+0x555]
        [0xb0e83000 - 0xb0e92000] committed 60KB from [VirtualSpace::initialize(ReservedSpace, unsigned int)+0x3e8]
        [0xb1003000 - 0xb139b000] committed 3680KB from [VirtualSpace::initialize(ReservedSpace, unsigned int)+0x37a]
 
[0xb7003000 - 0xb7603000] reserved 6144KB for Class
                from [ReservedSpace::initialize(unsigned int, unsigned int, bool, char*, unsigned int, bool)+0x555]
        [0xb7003000 - 0xb73a4000] committed 3716KB from [VirtualSpace::initialize(ReservedSpace, unsigned int)+0x37a]
 
[0xb7603000 - 0xb760b000] reserved 32KB for Internal
                from [PerfMemory::create_memory_region(unsigned int)+0x8ba]
 
[0xb770b000 - 0xb775c000] reserved 324KB for Thread Stack
                from [Thread::record_stack_base_and_size()+0xca]
        [0xb770b000 - 0xb775c000] committed 324KB from [Thread::record_stack_base_and_size()+0xca]

NMT内存基线以及对比

开启汇总或者明细追踪,然后使用jcmd <pid> VM.native_memory baseline建立内存基线,然后预热应用,然后使用jcmd <pid> VM.native_memory summary.diff 或者 jcmd <pid> VM.native_memory detail.diff打印内存变化的情况,
汇总样例如下:

Total:  reserved=664624KB  -20610KB, committed=254344KB -20610KB                         <--- 总内存与基线对比. '+'=增加 '-'=减少
 
-                 Java Heap (reserved=516096KB, committed=204800KB)
                            (mmap: reserved=516096KB, committed=204800KB)
 
-                     Class (reserved=6578KB +3KB, committed=4530KB +3KB)
                            (classes #668 +3)                                            <--- 新加载了3个类
                            (malloc=434KB +3KB, #930 -7)                                 <--- malloc的内存新增了3KB,但malloc数量减少了7次
                            (mmap: reserved=6144KB, committed=4096KB)
 
-                    Thread (reserved=60KB -1129KB, committed=60KB -1129KB)
                            (thread #16 +1)                                              <--- 新增了一个线程
                            (stack: reserved=7104KB +324KB, committed=7104KB +324KB)
                            (malloc=29KB +2KB, #70 +4)
                            (arena=31KB -1131KB, #32 +2)                                 <--- 新增2块arena(多了一个资源区和一个句柄区)
 
-                      Code (reserved=102328KB +133KB, committed=6640KB +133KB)
                            (malloc=2488KB +133KB, #72694 +4287)
                            (mmap: reserved=99840KB, committed=4152KB)
 
-                        GC (reserved=26154KB, committed=24938KB)
                            (malloc=486KB, #110)
                            (mmap: reserved=25668KB, committed=24452KB)
 
-                  Compiler (reserved=106KB, committed=106KB)
                            (malloc=7KB, #93)
                            (arena=99KB, #3)
 
-                  Internal (reserved=590KB +35KB, committed=558KB +35KB)
                            (malloc=558KB +35KB, #1699 +20)
                            (mmap: reserved=32KB, committed=0KB)
 
-                    Symbol (reserved=911KB +5KB, committed=911KB +5KB)
                            (malloc=519KB +5KB, #2921 +180)
                            (arena=392KB, #1)
 
-           Memory Tracking (reserved=2073KB -887KB, committed=2073KB -887KB)
                            (malloc=2073KB -887KB, #84 -210)
 
-        Pooled Free Chunks (reserved=2624KB -15876KB, committed=2624KB -15876KB)
                            (malloc=2624KB -15876KB)

明细样例如下:

Details:
 
[0x01195652] ChunkPool::allocate(unsigned int)+0xe2
                            (malloc=482KB -481KB, #8 -8)
 
[0x01195652] ChunkPool::allocate(unsigned int)+0xe2
                            (malloc=2786KB -19742KB, #134 -618)
 
[0x013bd432] CodeBlob::set_oop_maps(OopMapSet*)+0xa2
                            (malloc=591KB +6KB, #681 +37)
 
[0x013c12b1] CodeBuffer::block_comment(int, char const*)+0x21                <--- [方法调用地址] 方法名 + 偏移量
                            (malloc=562KB +33KB, #35940 +2125)               <--- malloc大小增加33KB #malloc数增加2125
 
[0x0145f172] ConstantPool::ConstantPool(Array<unsigned char>*)+0x62
                            (malloc=69KB +2KB, #610 +15)
 
...
 
[0x01aa3ee2] Thread::allocate(unsigned int, bool, unsigned short)+0x122
                            (malloc=21KB +2KB, #13 +1)
 
[0x01aa73ca] Thread::record_stack_base_and_size()+0xca
                            (mmap: reserved=7104KB +324KB, committed=7104KB +324KB)

关闭NMT

jcmd <pid> VM.native_memory shutdown