目录
一、jdk工具之jps(JVM Process Status Tools)命令使用
二、jdk命令之javah命令(C Header and Stub File Generator)
三、jdk工具之jstack(Java Stack Trace)
四、jdk工具之jstat命令(Java Virtual Machine Statistics Monitoring Tool)
四、jdk工具之jstat命令2(Java Virtual Machine Statistics Monitoring Tool)详解
五、jdk工具之jmap(java memory map)、 mat之四--结合mat对内存泄露的分析
六、jdk工具之jinfo命令(Java Configuration Info)
七、jdk工具之jconsole命令(Java Monitoring and Management Console)
八、jdk工具之JvisualVM、JvisualVM之二--Java程序性能分析工具Java VisualVM
九、jdk工具之jhat命令(Java Heap Analyse Tool)
十、jdk工具之Jdb命令(The Java Debugger)
十一、jdk命令之Jstatd命令(Java Statistics Monitoring Daemon)
十一、jdk命令之Jstatd命令(Java Statistics Monitoring Daemon)
十二、jdk工具之jcmd介绍(堆转储、堆分析、获取系统信息、查看堆外内存)
十三、jdk命令之Java内存之本地内存分析神器:NMT 和 pmap
一、概述
NMT是Native Memory Tracking的缩写,是Java7U40引入的HotSpot新特性。 pmap,众所周知,就是Linux上用来看进程地址空间的。
二、NMT
Java7U40之后JDK提供了Native Memory Tracking工具,跟踪JVM内部的内存使用,并可以通过jcmd命令来访问。不过要注意的是NMT是通过在JVM代码中添加跟踪点的方式实现内存跟踪的,因此NMT不能跟踪第三方Native库的内存使用。
2.1、如何开启NMT
NMT功能默认关闭,可以通过以下方式开启:
-XX:NativeMemoryTracking=[off | summary | detail]
配置项 | 说明 |
---|---|
off | 默认配置 |
summary | 只收集汇总信息 |
detail | 收集每次调用的信息 |
注意,根据Java官方文档,开启NMT会有5%-10%的性能损耗;
如果想JVM退出时打印退出时的内存使用情况,可以通过如下配置项:
-XX:+UnlockDiagnosticVMOptions -XX:+PrintNMTStatistics
2.2、访问NMT数据
JDK提供了jcmd命令来访问NMT数据:
jcmd <pid> VM.native_memory [summary | detail | baseline | summary.diff | detail.diff | shutdown] [scale= KB | MB | GB]
配置项 | 说明 |
---|---|
summary | 只打印打印按分类汇总的内存用法 |
detail | 打印按分类汇总的内存用法、virtual memory map和每次内存分配调用 |
baseline | 创建内存快照,以比较不同时间的内存差异 |
summary.diff | 打印自上次baseline到现在的内存差异,显示汇总信息 |
detail.diff | 打印自上次baseline到现在的内存差异, 显示详细信息 |
shutdown | 关闭NMT功能 |
scale | 指定内存单位,默认为KB |
2.3、示例
启动时,加上如下的jvm参数:
-XX:MaxDirectMemorySize=10m -XX:NativeMemoryTracking=detail -XX:+UnlockDiagnosticVMOptions -XX:+PrintNMTStatistics
分析
服务通过-Xmx=6G指定最大堆分配为6G,但实际RSS已达到11G,开始怀疑堆外内存是否有内存泄露。为了有更好详细的数据,就在本地重现这个问题,并且打开了NMT持续监控。
NMT的Report如下,重点关注每个分类下的commit大小,这个是实际使用的内存大小。
命令:[root@ip-172-29-206-104 applogs]# jcmd 6739 VM.native_memory summary scale=MB
6739: #进程ID Native Memory Tracking: Total: reserved=8491110KB, committed=7220750KB
- Java Heap (reserved=6293504KB, committed=6291456KB)
(mmap: reserved=6293504KB, committed=6291456KB) - Class (reserved=1107429KB, committed=66189KB)
(classes #11979)
(malloc=1509KB #18708)
(mmap: reserved=1105920KB, committed=64680KB) - Thread (reserved=159383KB, committed=159383KB)
(thread #156)
(stack: reserved=158720KB, committed=158720KB)
(malloc=482KB #788)
(arena=182KB #310) - Code (reserved=255862KB, committed=41078KB)
(malloc=6262KB #9319)
(mmap: reserved=249600KB, committed=34816KB) - GC (reserved=449225KB, committed=449225KB)
(malloc=166601KB #1714646)
(mmap: reserved=282624KB, committed=282624KB) - Compiler (reserved=395KB, committed=395KB)
(malloc=265KB #856)
(arena=131KB #3) - Internal (reserved=146041KB, committed=146041KB)
(malloc=132185KB #276370)
(mmap: reserved=13856KB, committed=13856KB) - Symbol (reserved=31487KB, committed=31487KB)
(malloc=29209KB #91080)
(arena=2278KB #1) - Native Memory Tracking (reserved=33212KB, committed=33212KB)
(malloc=168KB #2575)
(tracking overhead=33044KB) - Arena Chunk (reserved=2284KB, committed=2284KB)
(malloc=2284KB) - Unknown (reserved=12288KB, committed=0KB)
(mmap: reserved=12288KB, committed=0KB) Virtual memory map:
......
并且在服务器上通过cron job来定期抓取NMT的report保存下来做分析,而且同时也把其对应的RSS和PMAP都抓取了一份。
COLLECTOR_PID=`ps -ef|grep "ProcessName" | grep -v grep | awk '{print $2}'`
OUTDIR=/opt/chkmem
HOSTNAME=`hostname` prstat -s rss 1 1 > ${OUTDIR}/${HOSTNAME}_coll_${COLLECTOR_PID}_prstat_`date '+%Y%m%d_%H%M%S'`.txt /opt/jdk1.8.0_40/bin/jcmd ${COLLECTOR_PID} VM.native_memory detail > ${OUTDIR}/${HOSTNAME}_coll_${COLLECTOR_PID}_nmd_`date '+%Y%m%d_%H%M%S'`.txt pmap -x ${COLLECTOR_PID} > ${OUTDIR}/${HOSTNAME}_coll_${COLLECTOR_PID}_pmap_`date '+%Y%m%d_%H%M%S'`.txt
分析发现NMT中的Symbol域持续增大,从最开始的几十兆已经增加到了2G左右,而且整个jvm的内存使用量也在持续增加。见下图:
验证后发现问题和JDK8的一个bug https://bugs.java.com/view_bug.do?bug_id=8180048 非常类似,测试后也证实确实如此,最后通过升级JDK解决了这个问题。具体是那个组件命中了JDK的这个bug,会在下一篇文章中详细描述。
jcmd 14179 VM.native_memory detail
首先,你要在Java启动项中,加入启动项: -XX:NativeMemoryTracking=detail 然后,重新启动Java程序。执行如下命令: jcmd 14179 VM.native_memory detail 你会在标准输出得到类似下面的内容(本文去掉了许多与本文无关或者重复的信息):
14179: Native Memory Tracking: Total: reserved=653853KB, committed=439409KB
- Java Heap (reserved=262144KB, committed=262144KB)
(mmap: reserved=262144KB, committed=262144KB) - Class (reserved=82517KB, committed=81725KB)
(classes #17828)
(malloc=1317KB #26910)
(mmap: reserved=81200KB, committed=80408KB) - Thread (reserved=20559KB, committed=20559KB)
(thread #58)
(stack: reserved=20388KB, committed=20388KB)
(malloc=102KB #292)
(arena=69KB #114) - Code (reserved=255309KB, committed=41657KB)
(malloc=5709KB #11730)
(mmap: reserved=249600KB, committed=35948KB) - GC (reserved=1658KB, committed=1658KB)
(malloc=798KB #676)
(mmap: reserved=860KB, committed=860KB) - Compiler (reserved=130KB, committed=130KB)
(malloc=31KB #357)
(arena=99KB #3) - Internal (reserved=5039KB, committed=5039KB)
(malloc=5007KB #20850)
(mmap: reserved=32KB, committed=32KB) - Symbol (reserved=18402KB, committed=18402KB)
(malloc=14972KB #221052)
(arena=3430KB #1) - Native Memory Tracking (reserved=2269KB, committed=2269KB)
(malloc=53KB #1597)
(tracking overhead=2216KB) - Arena Chunk (reserved=187KB, committed=187KB)
(malloc=187KB) - Unknown (reserved=5640KB, committed=5640KB)
(mmap: reserved=5640KB, committed=5640KB)
. . .
Virtual memory map: [0xceb00000 - 0xcec00000] reserved 1024KB for Class from
[0xced00000 - 0xcee00000] reserved 1024KB for Class from
. . .
[0xcf85e000 - 0xcf8af000] reserved and committed 324KB for Thread Stack from
[0xd4eaf000 - 0xd4f00000] reserved and committed 324KB for Thread Stack from
[0xf687866e] Thread::record_stack_base_and_size()+0x1be
[0xf68818bf] JavaThread::run()+0x2f
[0xf67541f9] java_start(Thread*)+0x119
[0xf7606395] start_thread+0xd5
[0xd5a00000 - 0xe5a00000] reserved 262144KB for Java Heap from
. . .
[0xe5e00000 - 0xf4e00000] reserved 245760KB for Code from
[0xf737f000 - 0xf7400000] reserved 516KB for GC from
[0xf745d000 - 0xf747d000] reserved 128KB for Unknown from
[0xf7700000 - 0xf7751000] reserved and committed 324KB for Thread Stack from
[0xf7762000 - 0xf776a000] reserved and committed 32KB for Internal from
上面的输出也就两大部分:Total和Virtual Memory Map. Total部分就是Java进程所使用的本地内存大小的一个分布: Heap用了多少,所有的Class用了多少。其中,最重要的一个就是Heap大小,此处它的Reserved值为262144KB, 其实也就是256MB, 因为该Java启动参数最大堆设为了256M:-Xmx256M。 Virtual Memory Map部分就是细节了,也就是Java进程的地址空间的每一段是用来干什么的,大小是多少。这些进程空间段按照用途分可以分为以下几种:
Reserved for Class (总共有76段)
例如:[0xceb00000 - 0xcec00000] reserved 1024KB for Class from
[0xced00000 - 0xcee00000] reserved 1024KB for Class from
大部分的为Class分配的进程空间都是1024KB的。
Reserved for Heap ( 总共只有1段)
例如:[0xd5a00000 - 0xe5a00000] reserved 262144KB for Java Heap from
简单演算一下:0xe5a00000-0xd5a00000=0x10000000=pow(2, 28)。很明显2的28方个比特就是256MB.
Reserved for Internal (总共只有1段)
例如:[0xf7762000 - 0xf776a000] reserved and committed 32KB for Internal from
Reserved for Thread Stack(总共有57段)
例如:[0xcf85e000 - 0xcf8af000] reserved and committed 324KB for Thread Stack from
从输出看,大部分的 Stack的地址空间都是324KB的,还有不少部分是516KB的。
Reserved for Code( 总共有2段 )
例如:[0xe5e00000 - 0xf4e00000] reserved 245760KB for Code from
这个地方用了好大的进程空间。后面,我们会在pmap的输出中找到它。它用了很大的Virtual Address Space, 但是RSS却相对比较小。
Reserved for Unknown( 总共有4 段)
例如: [0xf745d000 - 0xf747d000] reserved 128KB for Unknown from
Reserved for GC (总共有2段)
例如: [0xf737f000 - 0xf7400000] reserved 516KB for GC from
pmap的输出
使用命令行: pmap -p PID, 我们就可以得到对应进程的VSS&RSS信息。
pmap输出的中,我们把其中我们比较关心的部分列在下面:
START SIZE RSS PSS DIRTY SWAP PERM MAPPING
0000000008048000 4K 4K 4K 0K 0K r-xp /usr/java/jre1.8.0_65/bin/java
0000000008049000 4K 4K 4K 4K 0K rw-p /usr/java/jre1.8.0_65/bin/java
000000000804a000 74348K 71052K 71052K 71052K 0K rw-p [heap]
…
00000000ced00000 1024K 976K 976K 976K 0K rw-p [anon]
…
00000000d4eaf000 12K 0K 0K 0K 0K ---p [anon]
00000000d4eb2000 312K 28K 28K 28K 0K rwxp [stack:21151]
00000000d4f00000 1024K 1024K 1024K 1024K 0K rw-p [anon]
00000000d5000000 32K 32K 32K 0K 0K r-xp /usr/java/jre1.8.0_65/jre/lib/i386/libmanagement.so
00000000d5008000 4K 4K 4K 4K 0K rw-p /usr/java/jre1.8.0_65/jre/lib/i386/libmanagement.so
00000000d500d000 324K 24K 24K 24K 0K rwxp [stack:18608]
00000000d505e000 4376K 4376K 4376K 4376K 0K rw-p [anon]
00000000d54a4000 24K 0K 0K 0K 0K ---p [anon]
00000000d54aa000 92824K 92824K 92824K 92824K 0K rw-p [anon]
00000000daf50000 174784K 174784K 174784K 174784K 0K rw-p [anon]
00000000e5a40000 544K 544K 544K 544K 0K rw-p [anon]
00000000e5ac8000 3296K 0K 0K 0K 0K ---p [anon]
00000000e5e00000 34656K 34300K 34300K 34300K 0K rwxp [anon]
00000000e7fd8000 211104K 0K 0K 0K 0K ---p [anon]
00000000f4e00000 100K 60K 60K 0K 0K r-xp /usr/java/jre1.8.0_65/jre/lib/i386/libzip.so
00000000f4e19000 4K 4K 4K 4K 0K rw-p /usr/java/jre1.8.0_65/jre/lib/i386/libzip.so
00000000f4e5e000 648K 68K 68K 68K 0K rwxp [stack:18331]
00000000f4f00000 1024K 1024K 1024K 1024K 0K rw-p [anon]
…
Total: 735324K 482832K 479435K 462244K 0K
我们对几个重要部分的pmap输出一一作出分析,
- 000000000804a000: 该部分是Java进程的Heap区,此处的Heap指的不是Java那种特殊的Heap, 还是一个任何C/C++内存区域中Heap区。VSS和RSS差不多,都在70M上下。
- 00000000ced00000: 该区域就是用来存放class的。在NMT输出中可以找到对应项。Mapping那一栏是[anon], 因为pmap并不知道这部分区域是干什么用的,而直有JVM自己知道,所以, NMT的输出可以看出该内存区域的用处。
- 00000000d4eaf000 00000000d4eb2000: 这两部分合起来就是一个324K大小的Java Thread Stack。NTM输出中可以找到对应项。
- 00000000d54aa000, 00000000daf50000: 这两部分就非常重要的。它对应就是我们Java意义上的堆的那一部分。简单地讲,- 00000000daf50000那一块就是老年代(Java内存分布分析要以垃圾收集算法为前提)。00000000d54aa000这一部分包含了新生代。结合jstat –gc的输出可以得出这个结论。