Java性能监控与故障处理分析工具(Heap memory和Native memory)

1,964 阅读25分钟

前言

在实际的工作中会不断的遇到各种线上问题,包括但不限于内存溢出、服务响应时间上升、线程block等各种情况,这时候就需要性能监控以及故障处理工具来分析和定位问题,google后发现并没有一篇分类清晰、实用的文章能够概括以上对于工具的需求,因此,决定整理一下相关的内容,以供大家学习参考。

本文意在介绍了有哪些常用的分析工具,以方便大家能够快速的分析定位问题。@空歌白石

文章的整个编写思路可以通过如下思维导图所示:

java-profile-xmind.png

这里有几点需要说明:

  1. JDK原生工具特别是jmc以及arthas是在线实时分析工具,mat是离线分析工具,jProfiler也可以支持离线和实时分析。
  2. 以上工具都是很大篇幅是针对堆内内存进行分析,对于堆外内存的问题分析能力十分有限甚至可以说没有。
  3. 如果如果确定是堆外内存问题,一般堆外内存溢出排查可结合 gperftoolsbtrace 排查。

Java process memory

在介绍工具前,先来了解下Java进程内存的分类:

  1. Heap memory(堆内存)
    • 供Java应用程序使用。
    • Heap memory 存在于 JVM 进程中,并用于保存 Java 对象,有 JVM 垃圾收集器维护的内存。
    • Heap Memory 及其内部各组成的大小可以通过JVM的一系列命令行参数来控制,也就是一般意义上提到的JVM参数(不同的GC参数也会不同)。
  2. Native memory/Off-heap(堆外内存)
    • 供JVM自身进程使用。
    • Native memory 是在进程地址空间内分配的内存,由操作系统负责。由于不在堆内,因此不会被 Java 垃圾收集器释放和管理。
    • Native Memory 没有相应的参数来控制大小,其大小依赖于操作系统进程的最大值(对于32位系统就是3~4G,各种系统的实现并不一样),以及生成的Java字节码大小、创建的线程数量、维持java对象的状态信息大小(用于GC)以及一些第三方的包,比如JDBC驱动使用的native内存。

除了以上来两种内存外,还经常会提到Direct memory,Direct memory类似于Native memory,会使用共享硬件内的底层缓冲区。例如,网络IO的缓冲区,设置Direct memory是减少相同字节在内存中被复制的次数。

Native Memory

为什么会有Native Memory?以下是Native Memory的一些职责。

  • 管理java heap的状态数据(用于GC);
  • JNI调用,也就是Native Stack;
  • JIT(即使编译器)编译时使用Native Memory,并且JIT的输入(Java字节码)和输出(可执行代码)也都是保存在Native Memory;
  • NIO direct buffer。对于IBM JVM和Hotspot,都可以通过-XX:MaxDirectMemorySize来设置nio直接缓冲区的最大值。默认是64M。超过这个时,会按照32M自动增大。
  • 对于IBM的JVM某些版本实现,类加载器和类信息都是保存在Native Memory中的。

Direct Memory

Direct Memory在Java中都是由DirectBuffer来负责维护的,DirectBuffer访问更快,避免了从HeapBuffer还需要从java堆拷贝到本地堆,操作系统直接访问的是DirectBuffer。DirectBuffer对象的数据实际是保存在native heap中,但是引用保存在HeapBuffer中。这也就是我们经常会遇到的一个问题,堆内内存很稳定,但是堆外的内存一直释放不掉,需要看下保存在HeapBuffer的引用是否已经被去掉了。

另外,DirectBuffer的引用是直接分配在堆得Old区的,因此其回收时机是在FullGC时。因此,需要避免频繁的分配DirectBuffer,这样很容易导致Native Memory溢出。

  • Direct Memory并非 JVMS 定义的标准 Java 运行时内存。
  • JDK1.4 加入了新的 NIO 机制,目的是防止 Java 堆 和 Native 堆之间往复的数据复制带来的性能损耗,此后 NIO 可以使用 Native 的方式直接在 Native 堆分配内存。
  • Direct Memory区域是全局共享的内存区域。
  • Direct Memory区域可以进行自动内存管理(GC),但机制并不完善。
  • 本机的 Native 堆(直接内存) 不受 JVM 堆内存大小限制。
  • 可能出现 OutOfMemoryError 异常。

OOM

Java进程内存由Heap memoryNative memory组成,也就是堆内内存和堆外内存。两块内存空间都有可能发生OOM。因此在遇到OOM的异常时,首先要区分是哪块内存空间发生了OOM,然后在针对性的定位。但不论怎样Native Memory发生OOM本质上就是因为耗尽了进程地址空间。

如果发现进程内存过高,可能需要注意下程序是否存在堆外内存泄漏问题,java进程出现的堆外内存泄漏常见有如下几个方面:

  • JNI
  • NIO directbuffer泄漏
    • 网络编程中程序中,NIO directbuffer有监控工具可以查看,directbuffer使用量、并且可以设置最大直接内存buffer。
  • gzip

下文中讲到的JDK原生工具arthasmatJProfiler都是针对Heap memory的,而针对Native memory请查看Native memory analysis小节。

堆外内存的优点

使用堆外内存有很多优点,但是对于开发人员的要求更高,因为没有JVM的GC来负责,对于内存的控制需要更加精确和小心,否则很容易就会造成堆内和堆外内存的OOM,并且排查起来也会很困难。

  • 减少了垃圾回收
    • 因为垃圾回收会暂停其他的工作。
  • 加快了复制的速度
    • 堆内在flush到远程时,会先复制到直接内存(非堆内存),然后在发送;而堆外内存相当于省略掉了这个工作。

JDK原生工具

JDK本身提供了丰富的监控工具,拥有强大的功能。在监控方面包含两大类:一类是监控应用的,一类是监控JVM的,在故障排查中也有诸多的工具可以用。

官方文档:docs.oracle.com/javase/8/do…

本文使用的Jdk版本:

[user@server-name ~]$ java -version
openjdk version "11.0.14.1" 2022-02-08
OpenJDK Runtime Environment Temurin-11.0.14.1+1 (build 11.0.14.1+1)
OpenJDK 64-Bit Server VM Temurin-11.0.14.1+1 (build 11.0.14.1+1, mixed mode)

jdk/bin目录下包含了全部的tools集合。

jdk-bin.png

Troubleshooting(排障工具)

jinfo

jinfo: Java配置信息工具,Configuration Info for Java,显示虚拟机配置信息,可以实时地查看和调整虚拟机各项参数。

  • 使用jps命令的-v参数可以查看虚拟机启动时显式指定的参数列表,但如果想知道未被显式指定的参数的系统默认值,除了去找资料外,就只能使用jinfo的-flag选项进行查询了(如果只限于 JDK 1.6或以上版本的话,使用java -XX : +PrintFlagsFinal查看参数默认值也是一个很好的选择 );
  • jinfo还可以使用-sysprops选项把虚拟机进程的System.getProperties() 的内容打印出来。

jinfo在JDK 1.5时期已经随着Linux版的JDK发布,当时只提供了信息查询的功能,JDK1.6之后,jinfo在Windows和Linux平台都有提供,并且加入了运行期修改参数的能力,可以使用-flag[+|-jname或者-flag name=value修改一部分运行期可写的虚拟机参数值。JDK 1.6中,jinfo对于Windows平台功能仍然有较大限制,只提供了最基本的-flag选项。

jinfo命令格式

Usage:
    jinfo <option> <pid>
       (to connect to a running process)

where <option> is one of:
    -flag <name>         to print the value of the named VM flag
    -flag [+|-]<name>    to enable or disable the named VM flag
    -flag <name>=<value> to set the named VM flag to the given value
    -flags               to print VM flags
    -sysprops            to print Java system properties
    <no option>          to print both VM flags and system properties
    -? | -h | --help | -help to print this help message
jinfo [option] pid

使用ps -ef | grep 'java'查看当前运行应用的PID。执行命令jinfo [option] pid后,可以看到当前JVM的运行参数,主要包含四部分:

  1. Java System Properties
    • 使用jinfo -sysprops pid命令单独查看
  2. VM Flags
    • 使用jinfo -flags pid命令单独查看
  3. VM Arguments
  4. Launcher Type

在最后的参数会有Launcher Type: SUN_STANDARD说明当前标准的Launcher。

查看java进程的更为丰富的指令ps -ef | grep java | grep -v grep | awk '{printf "%d\t%s",$2,$8}'

jmap

jmap: Java内存映像工具,Memory Map for Java,生成虚拟机的内存转储快照(一般称为heapdump或dump文件)

如果不使用jmap命令,要想获取Java堆转储快照,还有一些比较暴力的手段:

  • 譬如-XX:+HeapDumpOnOutOfMemoryError参数,可以让虚拟机在OOM异常出现之后自动生成dump文件
    • 此方法在频繁发生OOM需要准确捕获当时现场的需求场景下十分有效。但是并不推荐生产的全部机器都配置,仅仅配置1-2台能够抓取dump即可
    • 还需要注意一点是,由于某些情况下dump文件会很大,因此需要预留足够的磁盘空间。
  • 通过-XX:+HeapDumpOnCtrlBreak参数则可以使用[Ctrl]+[Break]键让虚拟机生成dump文件
  • 又或者在Linux系统下通过Kill -3命令发送进程退出信号吓唬下虚拟机,也能拿到dump文件

jmap的作用并不仅仅是为了获取dump文件,它还可以查询finalize执行队列、Java堆和永久代的详细信息,如空间使用率、当前用的是哪种收集器等。

jinfo命令一样,jmap有不少功能在Windows平台下都是受限的,除了生成dump文件的-dump选项和用于查看每个类的实例、空间占用统计的-histo选项在所有操作系统都提供之外,其余选项都只能在Linux/Solaris下使用。但是经过在本地测试,jdk1.8在Windows平台下支持的参数不仅仅是上面两个。

jmapjmap -h命令可以查看jmap的全部参数。

Usage:
    jmap -clstats <pid>
        to connect to running process and print class loader statistics
    jmap -finalizerinfo <pid>
        to connect to running process and print information on objects awaiting finalization
    jmap -histo[:live] <pid>
        to connect to running process and print histogram of java object heap
        if the "live" suboption is specified, only count live objects
    jmap -dump:<dump-options> <pid>
        to connect to running process and dump java heap
    jmap -? -h --help
        to print this help message

    dump-options:
      live         dump only live objects; if not specified,
                   all objects in the heap are dumped.
      format=b     binary format
      file=<file>  dump heap to <file>
      parallel=<number>  parallel threads number for heap iteration:
                         parallel=0 default behavior, use predefined number of threads
                         parallel=1 disable parallel heap iteration
                         parallel=<N> use N threads for parallel heap iteration

    Example: jmap -dump:live,format=b,file=heap.bin <pid>

jmap -dump

jmap –dump:[live, ]format=b, file=<filename>-dump参数应该是jmap命令最常用的部分,可以生成当前运行时的堆内存文件。

实际运行jmap -dump:live,format=b,file=/opt/logs/dump.hprof 37

[user@server-name ~]$ jmap -dump:live,format=b,file=/opt/logs/dump.hprof 37
Dumping heap to /mnt/mesos/sandbox/dump.hprof ...
Heap dump file created [191760650 bytes in 1.306 secs]

可以看到文件已经生成。

[user@server-name app]$ ls -lh | grep 'dump'
-rw------- 1 deploy deploy 183M Aug  4 15:20 dump.hprof
文件传输

接下来就是可以使用sz dump.hprof或者通过sftp可以将dump文件转移到其他可以分析dump的机器上进一步分析。

这里可能有个问题,如果dump文件较小使用sz命令还可以轻松处理,但是当dump有十几个GB甚至上百GB的时候会很难轻松传输。这个问题可以通过临时搭建一个httpServer来解决。

sudo -u ${user} python -m SimpleHTTPServer 8989

**注意:**上述指令需要到dump文件所在目录执行,8989可以替换为任意可用端口。

  • 如果使用sz可以轻松将文件传输到本地
  • 如果使用HttpServer的话
    • 对于Widnows系统,通过域名加端口,浏览器直接下载即可
    • 对于Linux系统,可以使用sudo wget http://ip:port/dump.hprof 方式下载

jmap -clstats

jmap -clstats {pid}查看当前class的统计情况。

[user@server-name ~]$ jmap -clstats 37
Index Super InstBytes KlassBytes annotations    CpAll MethodCount Bytecodes MethodAll    ROAll    RWAll     Total ClassName
    1    -1  68222800        504           0        0           0         0         0       24      688       712 [B
    2    -1  11901560        504           0        0           0         0         0       24      688       712 [Ljava.lang.Object;
    3    28  10398400        616         128    14272         109      4576     72768    18640    70528     89168 java.lang.String
    4    -1   6449920        504           0        0           0         0         0       24      688       712 [C
    5    28   5511744        592           0     1368           9       213      2776     1488     3656      5144 java.util.concurrent.Concurre                                ntHashMap$Node
    6 15988   5055040       1112           0     6824          47      1117     27072     6480    29344     35824 java.lang.reflect.Method
    7    28   4490304        584           0     1392           7       149      2280     1152     3496      4648 java.util.HashMap$Node
    8    28   4306256        672           0    22120         139      5679     92112    24632    92272    116904 java.lang.Class
    9    -1   3996512        504           0        0           0         0         0       32      688       720 [Ljava.util.HashMap$Node;
   10     7   3574208        584           0      512           1        10       624      304     1720      2024 java.util.LinkedHashMap$Entry
   11    -1   3218680        504           0        0           0         0         0       24      688       712 [J
   12    -1   2375040        504           0        0           0         0         0       32      688       720 [Ljava.util.concurrent.Concur                                rentHashMap$Node;
   13    -1   1419800        504           0        0           0         0         0       24      688       712 [I
   14    19   1304952       1096           0     3816          26       879     12840     4608    13824     18432 java.util.LinkedHashMap
   15    -1   1178632        504           0        0           0         0         0       56      688       744 [Ljava.lang.Class;

一般情况下我们使用以下命令打印当前Class信息,并输出到指定的文件中。

sudo -u ${loginUser} /usr/java/jdk11/bin/jmap -clstats ${pid} > /tmp/jamp-class-state.txt
  • loginUser:用当前登录用户替换
  • pid:上文中获取的PID

jmap -finalizerinfo

jmap -finalizerinfo {pid},查询finalize执行队列绝大部分情况,应该是如下信息。

No instances waiting for finalization found

jmap -histo

jmap -histo {pid},可以查看具体class的实例数量以及所占用的堆大小。

 num     #instances         #bytes  class name (module)
-------------------------------------------------------
   1:        341732       68106488  [B (java.base@11.0.14.1)
   2:         38389       11894656  [Ljava.lang.Object; (java.base@11.0.14.1)
   3:        326579       10450528  java.lang.String (java.base@11.0.14.1)
   4:          2737        6501528  [C (java.base@11.0.14.1)
   5:        114588        5500224  java.util.concurrent.ConcurrentHashMap$Node (java.base@11.0.14.1)
   6:         31594        5055040  java.lang.reflect.Method (java.base@11.0.14.1)
   7:         95935        4604880  java.util.HashMap$Node (java.base@11.0.14.1)
   8:         22224        4312488  java.lang.Class (java.base@11.0.14.1)
   9:         22770        4042288  [Ljava.util.HashMap$Node; (java.base@11.0.14.1)
  10:         55175        3531200  java.util.LinkedHashMap$Entry (java.base@11.0.14.1)
  11:          1889        3219520  [J (java.base@11.0.14.1)
  12:          2979        2364200  [Ljava.util.concurrent.ConcurrentHashMap$Node; (java.base@11.0.14.1)
  13:         18508        1420608  [I (java.base@11.0.14.1)

可以添加grep过滤结果,如jmap -histo 37 | grep 'sun'

  33:          3251         390120  sun.util.calendar.Gregorian$Date (java.base@11.0.14.1)
  45:          2555         224840  sun.util.calendar.ZoneInfo (java.base@11.0.14.1)
  63:          4162         166480  sun.reflect.annotation.AnnotationInvocationHandler (java.base@11.0.14.1)
  67:          3817         152680  sun.reflect.generics.tree.SimpleClassTypeSignature (java.base@11.0.14.1)
  76:          1038         124560  sun.util.calendar.JulianCalendar$Date (java.base@11.0.14.1)
  87:          3817         103720  [Lsun.reflect.generics.tree.TypeArgument; (java.base@11.0.14.1)
  93:          1476          94464  sun.util.locale.LocaleObjectCache$CacheEntry (java.base@11.0.14.1)
  99:          3676          88224  sun.reflect.generics.tree.ClassTypeSignature (java.base@11.0.14.1)
 111:          1543          74064  sun.security.util.ObjectIdentifier (java.base@11.0.14.1)
 127:           367          64592  sun.nio.ch.SocketChannelImpl (java.base@11.0.14.1)
 145:           796          57312  com.sun.beans.introspect.PropertyInfo (java.desktop@11.0.14.1)
 160:          1035          49680  sun.security.util.DerInputBuffer (java.base@11.0.14.1)
 166:          1165          46600  sun.reflect.generics.reflectiveObjects.ParameterizedTypeImpl (java.base@11.0.14.1)
 175:          1035          41400  sun.security.util.DerValue (java.base@11.0.14.1)
 176:           737          41272  sun.util.locale.BaseLocale (java.base@11.0.14.1)
 178:          1009          40360  sun.security.x509.RDN (java.base@11.0.14.1)
 181:           615          39360  sun.reflect.generics.repository.MethodRepository (java.base@11.0.14.1)
 191:          1138          36416  com.sun.beans.introspect.MethodInfo (java.desktop@11.0.14.1)
 193:          1307          36080  [Lsun.reflect.generics.tree.FieldTypeSignature; (java.base@11.0.14.1) 203:          1088          34816  sun.reflect.generics.factory.CoreReflectionFactory (java.base@11.0.14.1)

jhat

jhat: 堆转储快照分析工具,JVM Heap Analysis Tool的缩写,用于分析heapdump文件,它会建立一个HTTP/HTML服务器,让用户可以在浏览器上查看分析结果。

使用命令jhat dump.hprof

实际工作中,一般不会直接使用 jhat 命令来分析 dump 文件,主要原因:

  1. 一般不会在生产环境直接分析 dump 文件,主要包括几方面原因:
    • 分析工作一般比较耗时,而且消耗硬件资源,生产环境一般内存仅仅够程序正常运行使用,无法满足dump的分析需求
    • 如果在其他机器上进行时则没必要受到命令行工具的限制
  2. jhat 分析功能相对简陋,大部分情况下会使用后续介绍的Java VisualVMEclipse Memory Analyzer (mat)等更功能更加强大可视化工具分析。

因此,这里只是了解有这个命令即可,无需过多关注。

jstack

jstack: Java堆栈跟踪工具,Stack Trace for Java,生成虚拟机当前时刻的线程快照(一般称为 threaddumpjavacore 文件)。

线程快照就是当前虚拟机内每一条线程正在执行的方法堆栈的集合,生成堆栈快照的主要目的是定位线程出现长时间停顿的原因,如线程死锁、死循环、请求外部资源导致的长时间等待等都是导致线程长时间停顿的常见原因。

jstack命令说明:

[user@server-name ~]$ jstack
Usage:
    jstack [-l][-e] <pid>
        (to connect to running process)

Options:
    -l  long listing. Prints additional information about locks
    -e  extended listing. Prints additional information about threads
    -? -h --help -help to print this help message

一般使用时可按如下方式使用:加上more可以不必一下子展示出全部堆栈信息,引起刷屏,通过回车来分屏查看。

$ jstack -l 26472 | more

实际案例

[user@server-name ~]$ jstack -l 37
2022-08-04 15:51:44
Full thread dump OpenJDK 64-Bit Server VM (11.0.14.1+1 mixed mode):

Threads class SMR info:
_java_thread_list=0x00007f420f686e60, length=420, elements={
0x00007f422d20be00, 0x00007f422d20d200, 0x00007f422d20d700, 0x00007f422d20dc00,
0x00007f422d20e100, 0x00007f420fc77000, 0x00007f420fc77600, 0x00007f420fc77c00,
0x00007f422d20e600, 0x00007f420fd9b500, 0x00007f420fd9ce00, 0x00007f420fd9d300,
0x00007f420fd9e200, 0x00007f42076bc500, 0x00007f42076bca00, 0x00007f42076bcf00,
0x00007f42076bd400, 0x00007f42076bd900, 0x00007f42076bde00, 0x00007f42076be300,
0x00007f41f8e94000, 0x00007f41f8e94500, 0x00007f41f8e94a00, 0x00007f41f8e94f00,
0x00007f41f8e95400, 0x00007f41f8e95900, 0x00007f41f8e95e00, 0x00007f41f8e96300,
0x00007f41f8e96800, 0x00007f41f8b08000, 0x00007f41f8b08500, 0x00007f41f8b08a00,
0x00007f41f8b08f00, 0x00007f41f8b09400, 0x00007f42076be800, 0x00007f42076bf200,
0x00007f42076c0100, 0x00007f42076c0600, 0x00007f42076c0b00, 0x00007f41eaeeb000,
0x00007f41eaeeb500, 0x00007f41eaeeba00, 0x00007f41eaeebf00, 0x00007f41eaeec400,
0x00007f41eaeec900, 0x00007f42076bed00, 0x00007f41eaeece00, 0x00007f41eaeed300,
0x00007f420a63d000, 0x00007f41eaeed800, 0x00007f41eaeedd00, 0x00007f41eaeeec00,
0x00007f41eaeefb00, 0x00007f41eaeee700, 0x00007f41db84d000, 0x00007f41db84d500,
0x00007f41db84da00, 0x00007f41db84df00, 0x00007f41db84e400, 0x00007f41db84e900,
0x00007f41db84ee00, 0x00007f41db84f300, 0x00007f41db84f800, 0x00007f41db84fd00,
0x00007f41db850200, 0x00007f41db850700, 0x00007f41db850c00, 0x00007f41db851100,
0x00007f41db851600, 0x00007f41db851b00, 0x00007f41eaa63000, 0x00007f41eaa63500,

// 省略部分elements

"main" #1 prio=5 os_prio=0 cpu=1650.00ms elapsed=7743.71s tid=0x00007f422d20be00 nid=0x40 runnable  [0x00007f4230c9b000]
   java.lang.Thread.State: RUNNABLE
        at java.net.PlainSocketImpl.socketAccept(java.base@11.0.14.1/Native Method)
        at java.net.AbstractPlainSocketImpl.accept(java.base@11.0.14.1/AbstractPlainSocketImpl.java:474)
        at java.net.ServerSocket.implAccept(java.base@11.0.14.1/ServerSocket.java:565)
        at java.net.ServerSocket.accept(java.base@11.0.14.1/ServerSocket.java:533)
        at org.apache.catalina.core.StandardServer.await(StandardServer.java:466)
        at org.apache.catalina.startup.Catalina.await(Catalina.java:769)
        at org.apache.catalina.startup.Catalina.start(Catalina.java:715)
        at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@11.0.14.1/Native Method)
        at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@11.0.14.1/NativeMethodAccessorImpl.java:62)
        at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.14.1/DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(java.base@11.0.14.1/Method.java:566)
        at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:353)
        at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:493)

   Locked ownable synchronizers:
        - None

"Reference Handler" #2 daemon prio=10 os_prio=0 cpu=345.87ms elapsed=7743.06s tid=0x00007f422d20d200 nid=0x4b waiting on condition  [0x00007f4230b5c000]
   java.lang.Thread.State: RUNNABLE
        at java.lang.ref.Reference.waitForReferencePendingList(java.base@11.0.14.1/Native Method)
        at java.lang.ref.Reference.processPendingReferences(java.base@11.0.14.1/Reference.java:241)
        at java.lang.ref.Reference$ReferenceHandler.run(java.base@11.0.14.1/Reference.java:213)

   Locked ownable synchronizers:
        - None

"Finalizer" #3 daemon prio=8 os_prio=0 cpu=37.68ms elapsed=7743.06s tid=0x00007f422d20d700 nid=0x4c in Object.wait()  [0x00007f4230b1b000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(java.base@11.0.14.1/Native Method)
        - waiting on <no object reference available>
        at java.lang.ref.ReferenceQueue.remove(java.base@11.0.14.1/ReferenceQueue.java:155)
        - waiting to re-lock in wait() <0x000010017182af78> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(java.base@11.0.14.1/ReferenceQueue.java:176)
        at java.lang.ref.Finalizer$FinalizerThread.run(java.base@11.0.14.1/Finalizer.java:170)

   Locked ownable synchronizers:
        - None

// 省略剩余的堆栈

jcmd

jcmd是在JDK1.7以后,新增了一个命令行工具。jcmd是一个多功能的工具,可以用它来导出堆、查看Java进程、导出线程信息、执行GC、还可以进行采样分析(jmc 工具的飞行记录器)。

[user@server-name ~]$ jcmd -h
Usage: jcmd <pid | main class> <command ...|PerfCounter.print|-f file>
   or: jcmd -l
   or: jcmd -h

  command must be a valid jcmd command for the selected jvm.
  Use the command "help" to see which commands are available.
  If the pid is 0, commands will be sent to all Java processes.
  The main class argument will be used to match (either partially
  or fully) the class used to start Java.
  If no options are given, lists Java processes (same as -l).

  PerfCounter.print display the counters exposed by this process
  -f  read and execute commands from the file
  -l  list JVM processes on the local machine
  -? -h --help print this help message

查看当前Java进程

[user@server-name ~]$ jcmd
2819 jdk.jcmd/sun.tools.jcmd.JCmd
37 org.apache.catalina.startup.Bootstrap start

jcmdjcmd -ljps三个命令都可以达到查看当前Java进程的效果。

性能统计

jcmd ${pid} PerfCounter.print,查看指定进程的性能统计信息。

[user@server-name ~]$ jcmd 37 PerfCounter.print
37:
java.ci.totalTime=171142524855
java.cls.loadedClasses=20965
java.cls.sharedLoadedClasses=0
java.cls.sharedUnloadedClasses=0
java.cls.unloadedClasses=0
// 省略其他信息

当前运行的 java 进程可以执行的操作

jcmd ${pid} help使用这个命令,可以查看jcmd可以执行哪些操作,可以理解过对其他部分指令的一个封装。

[user@server-name ~]$ jcmd 37 help
37:
The following commands are available:
// 省略部分信息
GC.finalizer_info
GC.heap_dump
GC.heap_info
// 省略部分信息

For more information about a specific command use 'help <command>'.

举个例子:使用jcmd 37 VM.uptime查看VM的运行时长

[user@server-name ~]$ jcmd 37 VM.uptime
37:
9435.434 s

这里列举几个等价的命令:

  • jcmd PID GC.class_histogram,查看系统中类统计信息,等价于jmap -histo pid
  • jcmd PID Thread.print,查看线程堆栈信息,等价于jstack -l pid
  • jcmd PID GC.heap_dump FILE_NAME,查看 JVM 的Heap Dump,等价于jmap -dump:format=b,file=heapdump.phrof pid

jsadebugd

命令格式:jsadebugd PID [ServerId]

jsadebugd pid [ server-id ]

jsadebugd executable core [ server-id ]

pid

    The process ID of the process to which the debug server attaches. The process must be a Java process. To get a list of Java processes running on a machine, use the jps(1) command. At most one instance of the debug server can be attached to a single process.
executable

    The Java executable from which the core dump was produced.
core

    The core file to which the debug server should attach.
server-id

    An optional unique ID that is needed when multiple debug servers are started on the same machine. This ID must be used by remote clients to identify the particular debug server to which to attach. Within a single machine, this ID must be unique.

使用jinfo,jmap,jstack命令不仅可监控本地主机上的JVM进程,也可监控远端主机上的JVM进程,前者称为“本地模式”,后者称为“联网模式”。“联网模式”下的整个监控体系实质上是一个RMI应用程序。在“联网模式”下,一般情况下,远端主机上“运行rmiregistry服务,运行RMI Server”,本地主机上“运行RMI Client”,整个体系中“无需运行Web Server服务(因为所有相关类都可在本地获取)”。

在远端主机上,通过运行jsadebugd命令开启RMI Server(需要注意的是,运行jsadebugd命令同时会自动运行rmiregistry服务,而无需手动运行),使用“PID”选项值指定远端主机上待被监控的JVM进程ID,使用“ServerId”选项值作为RMI Server内向rmiregistry服务注册所生成Remote Object实例的名称(如果未指定,则使用默认名称);在本地主机上,运行jinfo,jmap,jstack命令作为RMI Client。

jsadebugd在JDK11中已经没有这个命令,这里不再过多介绍。

Monitor the JVM

jps

jps:虚拟机进程状况工具,JVM Process Status Tool的缩写,显示指定系统内所有的HotSpot虚拟机进程。jps可以有什么用处呢?

  1. 可以列出正在运行的虚拟机进程;
  2. 显示虚拟机执行主类(main函数坐在的类)名称;
  3. 显示进程的本地虚拟机唯一ID(Local Virtual Machine Identifier,LVMID);
  • jps是使用频率最高的JDK命令行工具,因为其他的JDK工具大多数需要输入它查询到的LVMID来确定要监控的是哪一个虚拟机进程。

  • 对于本地虚拟机进程来说,LVMID与操作系统的进程ID ( Process Identifier,PID ) 是一致的。

  • 使用Windows的任务管理器或者UNIX的ps命令也可以查询到虚拟机进程的LVMID ,但如果同时启动了多个虚拟机进程,无法根据进程名称定位时,那就只能依赖jps命令显示主类的功能才能区分了。

  • jps命令格式: jps [options] [hostid]

[user@server-name ~]$ jps -h
usage: jps [--help]
       jps [-q] [-mlvV] [<hostid>]

Definitions:
    <hostid>:      <hostname>[:<port>]
    -? -h --help -help: Print this help message and exit.
  • jps可以通过RMI协议查询开启了RMI服务的远程虚拟机进程状态,hostid为RMI注册表中注册的主机名。
  • 需要远程主机提供RMI支持,Sun提供的jstatd工具可以很方便地建立远程RMI服务器。

各个参数执行后详情:

[user@server-name  ~]$ jps -l
3436 jdk.jcmd/sun.tools.jps.Jps
[user@server-name ~]$ jps -m
3463 Jps -m
[user@server-name  ~]$ jps -v
3483 Jps -Dapplication.home=/usr/java/jdk11 -Xms8m -Djdk.module.main=jdk.jcmd
[user@server-name  ~]$ jps -V
3502 Jps
[user@server-name  ~]$ jps -q
3549

jstat

jstat: 虚拟机统计信息监视工具,JVM Statistics Monitoring Tool的缩写,用于收集HotSpot虚拟机各方面的运行数据。它可以显示本地或者远程虚拟机进程中的类装载、内存、垃圾收集、JIT编译等运行数据。

在没有GUI图形界面,只提供了纯文本控制台环境的服务器上,它将是运行期定位虚拟机性能问题的首选工具。

jstat命令格式:

jstat [option vmid [interval [s|ms] [count]] ]
[user@server-name ~]$ jstat
Usage: jstat --help|-options
       jstat -<option> [-t] [-h<lines>] <vmid> [<interval> [<count>]]

Definitions:
  <option>      An option reported by the -options option
  <vmid>        Virtual Machine Identifier. A vmid takes the following form:
                     <lvmid>[@<hostname>[:<port>]]
                Where <lvmid> is the local vm identifier for the target
                Java virtual machine, typically a process id; <hostname> is
                the name of the host running the target Java virtual machine;
                and <port> is the port number for the rmiregistry on the
                target host. See the jvmstat documentation for a more complete
                description of the Virtual Machine Identifier.
  <lines>       Number of samples between header lines.
  <interval>    Sampling interval. The following forms are allowed:
                    <n>["ms"|"s"]
                Where <n> is an integer and the suffix specifies the units as
                milliseconds("ms") or seconds("s"). The default units are "ms".
  <count>       Number of samples to take before terminating.
  -J<flag>      Pass <flag> directly to the runtime system.
  -? -h --help  Prints this help message.
  -help         Prints this help message.
[user@server-name ~]$ jstat -options
-class
-compiler
-gc
-gccapacity
-gccause
-gcmetacapacity
-gcnew
-gcnewcapacity
-gcold
-gcoldcapacity
-gcutil
-printcompilation
  • 对于命令格式中的VMIDLVMID需要特别说明一下:
    • 如果是本地虚拟机进程,VMIDLVMID是一致的;
    • 如果是远程虚拟机进程,那VMID的格式应当是: [protocol:][//]lvmid[@hostname[:port]/servername]
  • 参数intervalcount代表查询间隔次数,如果省略这两个参数,说明只查询一次
    • 假设需要每250毫秒查询一次进程2764垃圾收集状况,一共查询20次,那命令应当是:jstat -gc 2764 250 20
  • 选项option代表着用户希望查询的虚拟机信息,主要分为3类:类装载、垃圾收集、运行期编译状况。
    • 类装载
      • -class:监视类装载、卸载数量、总空间以及类装载所耗费的时间。
    • 垃圾收集
      • -gc:监视Java堆状况,包括Eden区、两个survivor区、老年代、永久代等的容量、已用空间、GC时间合计等信息
      • -gccapacity:监视内容与-gc基本相同,但输出主要关注Java堆各个区域使用到的最大、最小空间
      • -gcutil:监视内容与-gc基本相同,但输出主要关注已使用空间占总空间的百分比
      • -gccause:与-gcutil功能一样,但是会额外输出导致上一次GC产生的原因
      • -gcnew:监视新生代GC状况
      • -gcnewcapacity:监视内容与-gcnew基本相同,输出主要关注使用到的最大、最小空间
      • -gcold:监视老年代GC状况
      • -gcoldcapacity:监视内容与-gcold基本相同,输出主要关注使用到的最大、最小空间
      • -gcpermcapacity:输出永久代使用到的最大、最小空间
    • 运行期编译状况
      • -compiler:输出JIT编译器编译过的方法、耗时等信息
      • -printcompilation:输出已经被JIT编译的方法

GC优化中,利用jstat -gc ${pid}较多,实际执行如下:

[user@server-name ~]$ jstat -gc 37
 S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT    CGC    CGCT     GCT
  -      -      -      -       -        -     6213632.0  1847296.0  135680.0 133830.1  0.0    0.0        -        -   -          -   -          -    0.000

每隔一秒打印GC信息,输出10次。jstat -gc 37 1000 10

[user@server-name ~]$ jstat -gc 37 1000 10
 S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT    CGC    CGCT     GCT
  -      -      -      -       -        -     6213632.0  2279424.0  135680.0 133855.6  0.0    0.0        -        -   -          -   -          -    0.000
  -      -      -      -       -        -     6213632.0  2279424.0  135680.0 133855.6  0.0    0.0        -        -   -          -   -          -    0.000
  -      -      -      -       -        -     6213632.0  2279424.0  135680.0 133855.6  0.0    0.0        -        -   -          -   -          -    0.000
  -      -      -      -       -        -     6213632.0  2279424.0  135680.0 133855.6  0.0    0.0        -        -   -          -   -          -    0.000
  -      -      -      -       -        -     6213632.0  2279424.0  135680.0 133855.6  0.0    0.0        -        -   -          -   -          -    0.000
  -      -      -      -       -        -     6213632.0  2279424.0  135680.0 133855.6  0.0    0.0        -        -   -          -   -          -    0.000
  -      -      -      -       -        -     6213632.0  2279424.0  135680.0 133855.6  0.0    0.0        -        -   -          -   -          -    0.000
  -      -      -      -       -        -     6213632.0  2279424.0  135680.0 133855.6  0.0    0.0        -        -   -          -   -          -    0.000
  -      -      -      -       -        -     6213632.0  2279424.0  135680.0 133855.6  0.0    0.0        -        -   -          -   -          -    0.000
  -      -      -      -       -        -     6213632.0  2279424.0  135680.0 133855.6  0.0    0.0        -        -   -          -   -          -    0.000

具体的参数说明:

参数说明
S0C年轻代中第一个survivor区的容量(字节)
S1C年轻代中第二个survivor区的容量(字节)
S0U年轻代中第一个survivor区目前已使用空间(字节)
S1U年轻代中第二个survivor区目前已使用空间(字节)
EC年轻代中Eden区的容量 (字节)
EU年轻代中Eden区目前已使用空间(字节)
OC老年代的容量(字节)
OU老年代目前已使用空间(字节)
PCPerm(永久代)的容量(字节)
PUPerm(永久代)目前已使用空间(字节)
YGC从应用程序启动到采样时年轻代中gc次数
YGCT从应用程序启动到采样时年轻代中gc所用时间(s)
FGC从应用程序启动到采样时老年代(全gc)gc次数
FGCT从应用程序启动到采样时老年代(全gc)gc所用时间(s)
GCT从应用程序启动到采样时gc用的总时间(s)

jstat -class命令执行情况。

[user@server-name ~]$ jstat -class 37
Loaded  Bytes  Unloaded  Bytes     Time
 21021 39147.3        0     0.0      17.62

jstat -compiler命令执行情况。

[user@server-name ~]$ jstat -compiler 37
Compiled Failed Invalid   Time   FailedType FailedMethod
   33141      2       0   182.55          1 com/mysql/jdbc/AbandonedConnectionCleanupThread run

jmc

jmcJava Mission Control的缩写,是一个集成了分析、监视和诊断等功能的工具套件,可以用于对HotSpot JVM进行生产时间分析和诊断的工具。jmc的两个主要功能是管理控制台Java飞行记录仪,但还有一些功能是作为插件提供的,可以从该工具下载。jmc也可以作为Eclipse IDE的一组插件使用。

官方文档:docs.oracle.com/en/java/jav…

JMC的两大功能如下图: jmc-type.png

其中MBean服务器是免费的,飞行记录器(Java Flight Recorder)是需要收费的。

服务端如何开启jmc

首先,JDK从JDK8-u265版本开始支持jmc,如果需要想要使用jmc需要先明确jdk的版本,如果过低需要升级才可以。

在确定JDK版本支持jmc后,需要在/tomcat/bin/setenv.sh文件的JAVA_OPTS属性中添加-XX:StartFlightRecording \这样一句话。可以直接手动修改,也可以使用sed命令添加内容,如下:

sudo sed -i '/Dcom.sun.management.jmxremote.ssl/a-XX:StartFlightRecording \\' /opt/tomcat/bin/setenv.sh

添加后效果如下:

JAVA_OPTS="${JAVA_OPTS} \
            # 省略不相关配置
           -Dcom.sun.management.jmxremote \
           # 8780端口需要记住,在jmc远程连接时,需要填写
           -Dcom.sun.management.jmxremote.port=8780 \
           -Dcom.sun.management.jmxremote.rmi.port=8780 \
           -Dcom.sun.management.jmxremote.authenticate=false \
           -c=false \
           # 需要添加的配置项
           -XX:StartFlightRecording \
            # 省略不相关配置
           "

修改配置后,重启tomcat容器。

sudo supervisorctl restart tomcat

属性介绍:

  • -Dcom.sun.management.jmxremote
    • 此选项用于切换 JMXRMI 的使用。默认情况下启用该选项,因此无需设置该选项就可以使用 JVM 的监视功能。要为 JVM 禁用 JMXRMI,请指定 -Dcom.sun.management.jmxremote=false。
  • -Dcom.sun.management.jmxremote.authenticate
    • 该选项用于切换对 JMXRMI 连接使用口令验证。默认情况下此选项是启用的。要为 JVM 禁用口令验证,请指定 -Dcom.sun.management.jmxremote.authenticate=false。
    • 注意:禁用验证是不安全的。任何知道 (或猜中) JMX 端口号和主机名的远程用户都能够监视和控制 Java 应用程序和 VM。虽然开发时这是可接受的,但对于生产系统不建议这样设置。
  • -Dcom.sun.management.jmxremote.port ` - 此选项用于设置 JMXRMI 连接的端口号。必须设置未使用的端口号才能启用 JVM 的监视和管理功能。
  • -Dcom.sun.management.jmxremote.ssl
    • 此选项用于切换安全套接字层 Sockets Layer (SSL) 验证的使用。默认情况下启用该选项。要为 JVM 禁用 SSL 验证,请指定 -Dcom.sun.management.jmxremote.ssl=false。

jmc在哪里

从Java11开始,Java分为了OracleJDK和AdoptOpenJDK两个版本,目前由于版权问题,都要求使用开源的AdoptOpenJDK,这里就有一个问题,在AdoptOpenJDKbin目录下是找不到jmc应用的。有几个方法可以解决

  1. 如果安装过JDK8-u265以上版本,可以使用jdk8 bin目录下的jmc,这个不受服务端jdk版本影响,也就是说如果应用是jdk11,我用jdk 8的jmc仍然可以进行问题分析。
  2. 如果只安装了jdk11甚至更高版本的jdk。可以单独下载jmc

MBean服务器

详细的使用可以参考:JVM——jmc使用说明,以下部分内容也援引此文。

创建新的连接。

jmc-new-connect.png

overview

默认布局提供 CPU 和内存使用情况的概览。

概览:可以添加自定义图表,通过概览的加号”添加图表”实现;可以重置,通过”重置为默认控件”实现。 添加图表后,可以通过图表的加号添加相应的子项,并可以在图表上右键详细设置。

jmc-overview.png

mbean-brower

JMC使用托管Bean (MBean) 为监视和管理 Java 应用程序性能提供统一且一致的界面。MBean 是采用符合 JMX 规范的设计模式的托管对象。MBean 可以表示一个设备、一个应用程序或需要托管的任何资源。MBean 的管理界面由一组属性、操作和通知组成。

MBean功能:

  1. 属性:列出所选 MBean 的属性。
  2. 操作:列出可从所选 MBean 调用的操作。
  3. 通知:列出在运行时期间 MBean 所提示的通知。
  4. 元数据:包含描述 MBean 的信息。

jmc-mbean-brower.png

trigger

使用触发器选项卡可以管理满足特定条件时触发事件的规则。这是一种无需持续地监视应用程序即可跟踪运行时问题的有用方法。以灰色显示的规则在监视的 JVM 中不可用。默认情况下,停用所有规则。要激活某个规则,请选中该规则旁边的复选框。

jmc-trigger.png

system

系统选项卡提供了运行 JVM 的系统的信息、JVM 的性能属性以及系统属性列表。

  • 服务器信息
    • 在系统选项卡顶部的服务器信息面板中,包含运行 JVM 的服务器的类别和值列表。这些信息对调试应用程序开发问题和运行时问题以及提出支持请求非常有用。这是一般系统信息,不能更改。
  • JVM 统计信息
    • JVM 统计信息面板包含 JVM 主要性能属性的当前值。默认情况下,表中显示以下属性:
  • 当前已加载类计数
    • 运行时间
    • 要向表中添加属性,请单击 JVM 统计信息面板右上角的添加属性按钮。要删除属性,请在表中右键单击该属性,然后选择删除。右键单击属性后,可以更改其更新间隔、单位,而对于一些属性,还可以设置值。
  • 系统属性
    • 系统属性面板包含一个表,其中列出使用 JVM 调用的所有属性的关键字和值。要筛选属性,请选择筛选列 (关键字或值),并在表上方的文本字段中指定筛选器字符串。
    • 要配置表外观,请单击系统属性面板右上角的表设置按钮,然后选择要显示或隐藏的列。对于各列,可以设置最小宽度、比例和初始排序顺序。展示的是一般系统信息,不能更改。

jmc-system.png

memory

使用内存选项卡可以监视应用程序使用内存资源的效率。此选项卡主要提供以下方面的信息:堆使用量、垃圾收集和活动内存池。此选项卡上提供的信息可帮助确定是否已将 JVM 配置为提供最佳应用程序性能。

  • GC表
    • GC 表面板包含可用垃圾收集器的主要性能属性的当前值。该面板分为标有活动垃圾收集器名称的多个选项卡
      • 总收集时间
      • 收集计数
      • GC 开始时间
      • GC 结束时间
      • GC 持续时间
      • GC ID
      • GC 线程计数
  • 活动内存池
    • 活动内存池面板包含一个表,其中列出可供 JVM 使用的内存池的信息。默认情况下,该表包含以下列:
      • 池名称:内存池的名称。
      • 类型:内存池的类型。如果内存池属于 Java 堆,则类型为 HEAP,否则为 NON_HEAP。
      • 已用:当前已用的内存池大小。
      • 最大值:内存池的最大大小。
      • 占用率:当前使用量占最大内存池大小的百分比。
      • 已用峰值:在受监视 JVM 的有效期内内存池已用内存的峰值。
      • 最大值峰值:在受监视 JVM 的有效期内最大内存池大小的峰值。

jmc-memory.png

thread

使用线程选项卡可以监视线程活动。此选项卡包含一个绘制应用程序随时间推移的活动线程使用情况的图形、一个由该应用程序使用的所有活动线程的表以及选定线程的堆栈跟踪。

  • 活动线程图
    • 活动线程图显示 Java 应用程序随时间推移启动的线程数。默认情况下,图形中显示以下属性:
      • 高峰活动线程计数
      • 活动线程总计数
      • 守护程序活动线程计数
  • 活动线程
    • 活动线程面板包含一个表,其中列出 Java 应用程序所启动活动线程的信息。默认情况下,该表包含以下列:
      • 线程名称:线程的名称。
      • 线程状态:线程的状态。线程可以是以下状态之一:NEW、RUNNABLE、BLOCKED、WAITING、TIMED_WAITING 或 TERMINATED。
      • 受阻计数:线程处于 BLOCKED 状态的次数。
      • CPU 总体占用率:线程所使用 CPU 资源占总 CPU 资源的百分比。默认情况下不提取此值。要启用它,请在表上方选择 CPU 概要分析。
      • 死锁:线程是否已死锁。默认情况下不提取此值。要启用它,请在表上方选择死锁检测。
      • 已分配的字节:已分配给线程的字节数。默认情况下不提取此值。要启用它,请在表上方选择分配。
  • 选定线程的堆栈跟踪
    • 在活动线程表中选择线程后,其整个堆栈跟踪将显示在下面的选定线程的堆栈跟踪面板中。堆栈跟踪包含所有方法 (一直到当前执行的方法) 的调用路径。它非常有用,例如,当需要确定导致死锁或代码执行过程中意外中断的方法时。

jmc-thread.png

command

使用诊断命令可监视 Java 应用程序的效率和性能。JMC 使用大量不同的诊断工具,包括一组可以使用诊断命令选项卡针对应用程序运行的命令。 jmc-command.png

jstatd

jstatd用于启动jvm监控服务。它是一个基于rmi的应用,向远程机器提供本机jvm应用程序的信息。默认端口1099。只能够监控具有适当的本地访问权限的JVM。因此,jstatd进程必须以与目标JVM相同的用户凭证来运行。

jstatd使用的并不多,只作为了解即可。

Monitor Java Applications

JConsole是在JDK 1.5时期就已经提供的虚拟机监控工具,而Java VisualVM在JDK 1.6 Update7中才首次发布,现在已经成为Sun ( Oracle ) 主力推动的多合一故障处理工具,并且已经从JDK中分离出来成为可以独立发展的开源项目。

jconsole

jconsole(Java Monitoring and Management Console): JVM 性能监控,是—种基于JMX的可视化监视管理工具。它管理部分的功能是针对JMX MBean进行管理,由于MBean可以使用代码、中间件服务器的管理控制台或者所有符合JMX规范的软件进行访问,所以本节将会着重介绍JConsole监视部分的功能。

jconsole逐步被jvisualvm替代,因此这里只需要了解有jconsole即可,就不做过多的展开说明。

VisualVM(All-in-One Java Troubleshooting Tool)

Java VisualVM也被称为jvisualvmVisualVM,是到目前为止随JDK发布的功能最强大的运行监视和故障处理程序,并且可以预见在未来一段时间内都是官方主力发展的虚拟机故障处理工具。它拥有自己独立的官网:visualvm.github.io/index.html。

官方在VisualVM的软件说明中写上了All-in-One的描述字样,预示着它除了运行监视、故障处理外,还提供了很多其他方面的功能,如性能分析(Profiling),VisualVM的性能分析功能甚至比起JProfiler、YourKit等专业且收费的Profiling工具都不会逊色多少。

而且VisualVM的还有一个很大的优点:不需要被监视的程序基于特殊 Agent运行,因此它对应用程序的实际性能的影响很小,使得它可以直接应用在生产环境中。这个优点是JProfiler、YourKit等工具无法与之媲美的。

VisualVM基于NetBeans平台开发,因此它一开始就具备了插件扩展功能的特性,通过插件扩展支持,VisualVM可以做到:

  1. 显示虚拟机进程以及进程的配置、环境信息(jps、 jinfo)。
  2. 监视应用程序的CPU、GC、堆、方法区以及线程的信息(jstat、jstack)。
  3. dump以及分析堆转储快照(jmap、jhat)。
  4. 方法级的程序运行性能分析,找出被调用最多、运行时间最长的方法。
  5. 离线程序快照:收集程序的运行时配置、线程dump、内存dump等信息建立个快照, 可以将快照发送开发者处进行Bug反馈。
  6. 其他plugins的无限的可能性

BTrace

BTrace是一个很有趣的VisualVM插件,可以负责动态日志跟踪,本身也是可以独立运行的程序。

它的作用是在不停止目标程序运行的前提下,通过HotSpot虚拟机的HotSwap技术动态加入原本并不存在的调试代码。

这项功能对实际生产中的程序很有意义:经常遇到程序出现问题,但排查错误的一些必要信息,譬如方法参数、返回值等,在开发时并没有打印到日志之中,以至于不得不停掉服务,通过调试增量来加入日志代码以解决问题。当遇到生产环境服务无法随便停止时,缺一两句日志导致排错进行不下去是一件非常郁闷的事情。

这里额外提一点,BTrace是后文中准备介绍的arthas的基础开源框架,arthas也是在BTrace基础上升级而来。

arthas

Arthas 是一款线上监控诊断产品,通过全局视角实时查看应用 load、内存、gc、线程的状态信息,并能在不修改应用代码的情况下,对业务问题进行诊断,包括查看方法调用的出入参、异常,监测方法执行耗时,类加载信息等,大大提升线上问题排查效率。

arthas官方地址:arthas.aliyun.com/doc/quick-s…

github地址:github.com/alibaba/art…

start arthas

在命令行下面执行:

curl -O https://arthas.aliyun.com/arthas-boot.jar
java -jar arthas-boot.jar

使用和目标进程一致的用户启动,否则可能 attach 失败。

运行截图: arthas-start.png

help

arthas启动后,可以通过help命令查看有哪些指令可使用,可以作为临时的开发手册。后续只是简单介绍一些常用的命令,未介绍到的可以翻阅官方文档使用,使用起来都很方面简洁。

命令列表:arthas.aliyun.com/doc/command…

[arthas@5301]$ help
 NAME         DESCRIPTION
 help         Display Arthas Help
 keymap       Display all the available keymap for the specified connection.
 sc           Search all the classes loaded by JVM
 sm           Search the method of classes loaded by JVM
 classloader  Show classloader info
 jad          Decompile class
 getstatic    Show the static field of a class
 monitor      Monitor method execution statistics, e.g. total/success/failure count, average rt, fail rate, etc.
 stack        Display the stack trace for the specified class and method
 thread       Display thread info, thread stack
 trace        Trace the execution time of specified method invocation.
 watch        Display the input/output parameter, return object, and thrown exception of specified method invocation
 tt           Time Tunnel
 jvm          Display the target JVM information
 perfcounter  Display the perf counter information.
 ognl         Execute ognl expression.
 mc           Memory compiler, compiles java files into bytecode and class files in memory.
 redefine     Redefine classes. @see Instrumentation#redefineClasses(ClassDefinition...)
 dashboard    Overview of target jvm's thread, memory, gc, vm, tomcat info.
 dump         Dump class byte array from JVM
 heapdump     Heap dump
 options      View and change various Arthas options
 cls          Clear the screen
 reset        Reset all the enhanced classes
 version      Display Arthas version
 session      Display current session information
 sysprop      Display, and change the system properties.
 sysenv       Display the system env.
 vmoption     Display, and update the vm diagnostic options.
 logger       Print logger info, and update the logger level
 history      Display command history
 cat          Concatenate and print files
 echo         write arguments to the standard output
 pwd          Return working directory name
 mbean        Display the mbean information
 grep         grep command for pipes.
 tee          tee command for pipes.
 profiler     Async Profiler. https://github.com/jvm-profiling-tools/async-profiler
 stop         Stop/Shutdown Arthas server and exit the console.

jvm相关

dashboard

当前系统的实时数据面板。dashboard官方文档

[arthas@5301]$ dashboard

每一列的说明:

  • ID: Java 级别的线程 ID,注意这个 ID 不能跟 jstack 中的 nativeID 一一对应。
  • NAME: 线程名
  • GROUP: 线程组名
  • PRIORITY: 线程优先级, 1~10 之间的数字,越大表示优先级越高
  • STATE: 线程的状态
  • CPU%: 线程的 cpu 使用率。比如采样间隔 1000ms,某个线程的增量 cpu 时间为 100ms,则 cpu 使用率=100/1000=10%
  • DELTA_TIME: 上次采样之后线程运行增量 CPU 时间,数据格式为秒
  • TIME: 线程运行总 CPU 时间,数据格式为分:秒
  • INTERRUPTED: 线程当前的中断位状态
  • DAEMON: 是否是 daemon 线程
    • daemon 线程是个服务线程,准确地来说就是服务其他的线程。
    • 比如垃圾回收线程,就是最典型的守护线程。

arthas-dashboard.png

jvm

jvm可以查看当前 JVM 信息。jvm官方文档

实际实行效果如下(其中把部分value已删除)

[arthas@5301]$ jvm
 RUNTIME
-------------------------------------------------------------------------------------------------------------------------------------------------------------
 MACHINE-NAME                                 
 JVM-START-TIME                               
 MANAGEMENT-SPEC-VERSION                      
 SPEC-NAME                                    
 SPEC-VENDOR                                  
 SPEC-VERSION                                 
 VM-NAME                                      
 VM-VENDOR                                    
 VM-VERSION                                   
 INPUT-ARGUMENTS                              --add-opens=java.base/java.lang=ALL-UNNAMED
                                              --add-opens=java.base/java.io=ALL-UNNAMED
                                              --add-opens=java.rmi/sun.rmi.transport=ALL-UNNAMED
 CLASS-PATH                                   
 BOOT-CLASS-PATH
 LIBRARY-PATH                                 /usr/java/packages/lib:/usr/lib64:/lib64:/lib:/usr/lib

-------------------------------------------------------------------------------------------------------------------------------------------------------------
 CLASS-LOADING
-------------------------------------------------------------------------------------------------------------------------------------------------------------
 LOADED-CLASS-COUNT                           21745
 TOTAL-LOADED-CLASS-COUNT                     21745
 UNLOADED-CLASS-COUNT                         0
 IS-VERBOSE                                   false

-------------------------------------------------------------------------------------------------------------------------------------------------------------
 COMPILATION
-------------------------------------------------------------------------------------------------------------------------------------------------------------
 NAME                                         HotSpot 64-Bit Tiered Compilers
 TOTAL-COMPILE-TIME                           152700
 [time (ms)]

-------------------------------------------------------------------------------------------------------------------------------------------------------------
 GARBAGE-COLLECTORS
-------------------------------------------------------------------------------------------------------------------------------------------------------------
 ZGC                                          name : ZGC
 [count/time (ms)]                            collectionCount : 173
                                              collectionTime : 2118


-------------------------------------------------------------------------------------------------------------------------------------------------------------
 MEMORY-MANAGERS
-------------------------------------------------------------------------------------------------------------------------------------------------------------
 CodeCacheManager                             CodeHeap 'non-nmethods'
                                              CodeHeap 'profiled nmethods'
                                              CodeHeap 'non-profiled nmethods'

 Metaspace Manager                            Metaspace

 ZGC                                          ZHeap


-------------------------------------------------------------------------------------------------------------------------------------------------------------
 MEMORY
-------------------------------------------------------------------------------------------------------------------------------------------------------------
 HEAP-MEMORY-USAGE                            init : 3865051136(3.6 GiB)
 [memory in bytes]                            used : 650117120(620.0 MiB)
                                              committed : 5024776192(4.7 GiB)
                                              max : 6442450944(6.0 GiB)

 NO-HEAP-MEMORY-USAGE                         init : 7667712(7.3 MiB)
 [memory in bytes]                            used : 215572512(205.6 MiB)
                                              committed : 222756864(212.4 MiB)
                                              max : 520093696(496.0 MiB)

 PENDING-FINALIZE-COUNT                       0

-------------------------------------------------------------------------------------------------------------------------------------------------------------
 OPERATING-SYSTEM
-------------------------------------------------------------------------------------------------------------------------------------------------------------
 OS                                           Linux
 ARCH                                         amd64
 PROCESSORS-COUNT                             4
 LOAD-AVERAGE                                 38.85
 VERSION                                      

-------------------------------------------------------------------------------------------------------------------------------------------------------------
 THREAD
-------------------------------------------------------------------------------------------------------------------------------------------------------------
 COUNT                                        430
 DAEMON-COUNT                                 416
 PEAK-COUNT                                   431
 STARTED-COUNT                                1314
 DEADLOCK-COUNT                               0

-------------------------------------------------------------------------------------------------------------------------------------------------------------
 FILE-DESCRIPTOR
-------------------------------------------------------------------------------------------------------------------------------------------------------------
 MAX-FILE-DESCRIPTOR-COUNT                    -1
 OPEN-FILE-DESCRIPTOR-COUNT                   -1
  • THREAD 相关
    • COUNT: JVM 当前活跃的线程数
    • DAEMON-COUNT: JVM 当前活跃的守护线程数
    • PEAK-COUNT: 从 JVM 启动开始曾经活着的最大线程数
    • STARTED-COUNT: 从 JVM 启动开始总共启动过的线程次数
    • DEADLOCK-COUNT: JVM 当前死锁的线程数
  • 文件描述符相关
    • MAX-FILE-DESCRIPTOR-COUNT:JVM 进程最大可以打开的文件描述符数
    • OPEN-FILE-DESCRIPTOR-COUNT:JVM 当前打开的文件描述符数

thread

使用thread ${ID}会打印线程 ID 的栈,类似下图。thread官方文档

arthas-thread.png

class/classloader相关

sc & sm

  • sc - 查看 JVM 已加载的类信息
    • “Search-Class” 的简写,这个命令能搜索出所有已经加载到 JVM 中的 Class 信息。
  • sm - 查看已加载类的方法信息。
    • “Search-Method” 的简写,这个命令能搜索出所有已经加载了 Class 信息的方法信息。

jad

反编译指定已加载类的源码,可以查看部署在线上服务器的.class文件对应的java源码。该功能基于一个第三方的反编译工具CFR实现。

注: 可以使用reset命令对增强后的class文件还原, 或者shutdown服务端关闭时也会重置所有增强过的类。

jad官方文档:arthas.aliyun.com/doc/jad.htm…

redefine

加载外部的.class文件替换掉当前的类。类似于热加载或热修复的功能, 修改java文件编译后的, 将替换掉jvm已加载的.class类, 基于jdk本身的限制, 修改的class文件里不允许新增加成员变量和方法

基于这个功能可以模拟一个简单的监控功能, 比如在java文件的某个方法里加上调用耗时和请求参数的打印功能, 然后使用redefine即可看到该方法的耗时时间和参数值, 并且不用重启服务

redefine -p D:/XOrderDetailLoungeMapper.class

注意: 使用时需谨慎,确保修改的代码能正确编译并且逻辑正确,毕竟这个命令的杀伤力太大,验证过之后最好通过 reset 命令还原回来。

redefine官方文档:arthas.aliyun.com/doc/redefin…

monitor/watch/trace 相关

watch

观察指定方法的调用情况, 包括返回值、异常、入参、对象属性值。 格式: watch 类名 方法名 [params:入参, target:当前对象, returnObj:返回值] -x 表示展开或遍历的深度,可以调整来打印具体的参数和结果内容

watch官方文档:arthas.aliyun.com/doc/watch.h…

trace

方法内部调用路径,并输出方法路径上的每个节点上耗时。

主要用于统计整个调用链路上的所有性能开销和追踪调用链路,使用下来感觉这个命令也是很有用的,包括本地环境, 尤其是要排查接口响应时间慢这样的场景下,可以快速定位到具体哪个方法或哪些方法导致的,甚至包括第三方的方法.

trace官方文档:arthas.aliyun.com/doc/trace.h…

stack

输出当前方法被调用的路径。

stack官方文档:arthas.aliyun.com/doc/stack.h…

tt

time tunnel 时间轴, 记录下指定方法每次调用的入参和返回信息。

tt官方文档:arthas.aliyun.com/doc/tt.html

profiler/火焰图

profiler可能是arthas中使用的最多的一个命令了,arthas里的火焰图也是集成的开源项目 async-profiler

火焰图可以直观的分析代码占用cpu, 内存, 锁争用的情况, 比较直观, 但是这个命令只支持Linux和Mac系统, 一般可以用于线上环境的诊断

说明: 纵轴表示栈帧深度, 横轴表示代码占用CPU/内存的比例, 点击可以查看详情。

[arthas@5301]$ profiler start
Started [cpu] profiling
[arthas@5301]$ profiler getSamples
97
[arthas@5301]$ profiler status
[perf] profiling is running for 61 seconds
[arthas@5301]$ profiler stop  --file /tmp/result.html
OK
profiler output file: /tmp/result.html

以上操作是将profiler启动后,再手动停止。也可以定时生成一定时间内的火焰图。以下指令生成了开始采样后10秒内的火焰图。

profiler start -d 10 --file /tmp/flame-graph.svg

生成的文件目录

[user@server-name tmp]$ ls -lh | grep result.html
-rw-r----- 1 deploy deploy 122K Aug  5 11:30 result.html

profiler官方文档:arthas.aliyun.com/doc/profile…

mat

MAT(全名:Memory Analyzer Tool),是一款快速便捷且功能强大丰富的 JVM 堆内存 离线 分析工具。通过展现 JVM 异常时所记录的运行时堆转储快照(Heap dump)状态(正常运行时也可以做堆转储分析),帮助定位内存泄漏问题或优化大内存消耗逻辑。

官网地址:www.eclipse.org/mat/

官方说明文档:help.eclipse.org/2020-09/ind…

MAT 的工作原理是对 dump 文件建立多种索引,并基于索引来实现以下四大核心功能,在这些功能的基础上再通过可视化展现辅助 Developer 精细化了解 JVM 堆内存全貌。

  1. 内存分布
  2. 对象间依赖(如实体对象引用关系、线程引用关系、ClassLoader引用关系等)
  3. 对象状态(内存占用量、字段属性值等)
  4. 条件检索(OQL、正则匹配查询等)

应用场景

  1. 内存溢出,JVM堆区或方法区放不下存活及待申请的对象。
    • 如:高峰期系统出现 OOM(Out of Memory)异常,需定位内存瓶颈点来指导优化。
  2. 内存泄漏,不会再使用的对象无法被垃圾回收器回收。
    • 如:系统运行一段时间后出现 Full GC,甚至周期性 OOM 后需人工重启解决。
  3. 内存占用高。
    • 如:系统频繁 GC,需定位影响服务实时性、稳定性、吞吐能力的原因。

使用介绍

Overview

堆内存大小、对象个数、类的个数、类加载器的个数、GC root 个数、线程概况等全局统计信息。主要包括以下一个主要模块。

  • 全局概览信息
    • 堆内存大小、类数量、实例数量、Class Loader数量。
  • Unreachable Object Histogram
    • 展现转储快照时可被回收的对象信息
    • 一般不需要关注,除非 GC 频繁影响实时性的场景分析才用到
  • Biggest Objects by Retained Size
    • 展现经过统计过的哪几个实例所关联的对象占内存总和较高,以及具体占用的内存大小,一般相关代码比较简单情况下,往往可以直接分析具体的引用关系异常,如内存泄漏等。
    • 此外也包含了最大对象和链接支持继续深入分析。

mat-overview.png

Object View

通过mat页面左侧的 inspector 面板可以查看对象的属性信息、类继承关系信息等数据,协助分析内存占用高与业务逻辑的关系。

mat-object-view.png

集合状态的检测,如:通过 ArrayList 或数组的填充率定位空集合空数组造成的内存浪费、通过 HashMap 冲突率判定 hash 策略是否合理等。

Actions

histogram

罗列每个类实例的内存占比,包括自身内存占用量(Shallow Heap)及支配对象的内存占用量(Retain Heap),支持按 package、class loader、super class、class 聚类统计,最常用的功能之一。

mat-histogram.png

dominator-tree

按对象的 Retain Heap 排序,也支持按多个维度聚类统计,并提供详细的支配关系,结合 references 可以实现大对象快速关联分析,最常用的功能之一。

mat-dominator-tree.png

top-consumer

展现哪些类、哪些 class loader、哪些 package 占用最高比例的内存。 mat-top-consumer.png

duplicate-classes

mat-duplicate-classes.png

Reports

leak-suspects

直击引用链条上占用内存较多的可疑对象,可解决一些基础问题,但复杂的问题往往帮助有限。

mat-leak-suspects.png

top-components

mat-top-components.png

mat-top-components-2.png

使用技巧

索引构建

mat很多时候启动会很慢,慢的原因就是mat为提升检索速率,需要在初始化时构建索引index文件。这一点当dump文件特别大的时候尤其明显,所以建议如果有可能的话,一开始可以将dump文件放在一台内存和CPU都相对较高的机器上完成初始化的索引构建,再将类似下图的文件全部拷贝到用于分析的机器上。这样可以大大提升分析效率。

mat-index-file.png

条件搜索

如下图,可以在搜索框中输入需要查找的类名或关键字,内存分布及对象间依赖的众多功能,均支持按字符串检索、按正则检索等操作。

mat-search.png

除以上输入框的搜索外,mat还支持OQL虚拟内存地址寻址

  • OQL,提供一种类似于SQL的对象(类)级别统一结构化查询语言。
    • 查找 size=0 且未使用过的 ArrayList。
      • select * from java.util.ArrayList where size=0 and modCount=0
    • 查找所有的String的length属性的
      • select s.length from instanceof String s

mat-oql-1.png

mat-oql-2.png

  • 虚拟内存地址寻址
    • 根据对象的十六进制地址查找对象 mat-hex.png

References

提供对象的外部引用关系、被引用关系。通过任一对象的直接引用及间接引用详情(主要是属性值及内存占用),进而提供完善的依赖链路详情。通过outgoing referencesincoming references 可以直击对象间依赖关系,MAT 也提供了链式快速操作。

  • outgoing references

    • 对象引用的外部对象(注意不包含对象的基本类型属性。基本属性内容可在 inspector 查看)。
  • incoming references

    • 直接引用了当前对象的对象,每个对象的 incoming references 可能有 0 到多个。
  • 外部引用关系:

    • with outgoing references
    • with incoming references mat-list-object.png
  • 被引用关系:

    • by outgoing references
    • by incoming references mat-show-objects-by-class.png

Path To GC Roots

Path To GC Roots:提供任一对象到GC Root的链路详情,帮助了解不能被 GC 回收的原因。

mat-merge-shortest-paths-to-gc-roots.png

mat-java-basics.png

GC Root:GC Root 代表通过可达性分析来判定 JVM 对象是否存活的起始集合。JVM 采用追踪式垃圾回收(Tracing GC)模式,从所有 GC Roots 出发通过引用关系可以关联的对象就是存活的(且不可回收),其余的不可达的对象(Unreachable object:如果无法从 GC Root 找到一条引用路径能到达某对象,则该对象为Unreachable object)可以回收。

JProfiler

JProfiler是一款同时支持离线和在线的性能分析工具,需要注意JProfiler是收费的应用,需要激活。这里简单介绍下相关的使用情况。

打开hprof文件,进入classes视图,可以查看instance Count和Size等基本信息,大部分情况下占用多的都是byte[]long[]等,需要根据具体的业务分析具体对应的class。 jprofiler-classes.png

allocations视图可以查看具体的分配情况,但是本次dump的格式为.hprofJProfiler不支持读取。 jprofiler-allocations.png

biggest-objects视图中可以查看当前堆中较大的对象。 jprofiler-biggest-objects.png

选中需要分析的大对象后,可以右击选中show in graphjprofiler-show-in-graph.png

graph视图中可以查看类之间的应用关系。 jprofiler-graph.png

thread dump视图中可以查看具体的线程堆。 jprofiler-thread-dump.png

先前介绍的jmcvisualVMarthas等基本已经包含了JProfiler的大部分功能,且不收费,因此对于JProfiler只是简单介绍下,就不再做更深入的分析。有兴趣的同学,可以自己尝试使用下。

Native memory analysis

本小节介绍下关于堆外内存的一些分析工具。有一点可以明确,堆外内存是由操作系统负责维护和分配的,这也就是为什么下文中会涉及到部分Linux等操作系统的命令。

pmap

使用pmap可以查看进程内存信息。pmapreport memory map of a process的缩写,也就是查看进程的内存映像信息。

pmap命令用于报告进程的内存映射关系,是Linux调试及运维一个很好的工具。

pmap -x pid 如果需要排序  | sort -n -k3**

gperftools

gperftools是由google出品的一个性能分析工具。官网地址:github.com/gperftools/…

我们见过的最快的malloc;尤其适用于线程和 STL。另外:线程友好的堆检查器、堆分析器和 cpu 分析器。 gperftools 是一个高性能多线程 malloc() 实现的集合,以及一些非常漂亮的性能分析工具。gperftools 是根据 BSD 许可证的条款分发的。

  1. install gcc
sudo yum -y install gcc make
sudo yum -y install gcc gcc-c++
  1. install libunwind
wget http://download.savannah.gnu.org/releases/libunwind/libunwind-0.99-beta.tar.gz
./configure  --prefix=/data0/java/deploy/google-perftools/local/libunwind
make
make install
  1. install gperftools
wget https://github.com/gperftools/gperftools/releases/download/gperftools-2.5/gperftools-2.5.tar.gz
./confighre --prefix=/data0/java/deploy/google-perftools/local/gperftools-2.5/
make
make install
  1. modify setting
vi /etc/ld.so.conf.d/usr_local_lib.conf
local/gperftools-2.5/bin/pprof --text /usr/local/java/jdk1.7.0_55/bin/java test.0132.heap
  1. dump profile
gcc [...] -o myprogram -ltcmalloc
HEAPPROFILE=/tmp/netheap ./myprogram
  1. Cpu Profiler:
gcc [...] -o myprogram -lprofiler
CPUPROFILE=/tmp/profile ./myprogram

gdb

pmap找到内存申请的地址块,可以使用gdb attachdump某一段的内存地址,后查看内存的数据。

注意: gdb attach 进程会暂停,线上谨慎操作。

  1. 安装gdb
    • sudo yum install -y gdb
  2. attach
    • sudo -u deploy gdb --pid={pid}
  3. dump内存
    • dump memory {path} {start_address} {end_address}
    • 内存地址可以使用pmap或less /proc/{pid}/maps查看
  4. 查看内存中的字面量:
    • strings {path}

NMT

Native Memory Tracking (NMT) 堆外内存跟踪,是Hotspot VM用来分析VM内部内存使用情况的一个功能。我们可以利用上文提到的jcmd工具来访问NMT的数据。官方文档:docs.oracle.com/javase/8/do…

NMT必须先通过VM启动参数-XX:NativeMemoryTracking打开,打开NMT会带来5%-10%的性能损耗。还有点需要注意,NMT能够分析JVM自身分配的一些内存,但是无法追踪非JVM分配的内存,例如JNI等native code,

-XX:NativeMemoryTracking=[off | summary | detail]
  • off
    • 默认关闭
  • summary
    • 只统计各个分类的内存使用情况.
  • detail
    • Collect memory usage by individual call sites.

开启NMT后,运行进程,可以使用下面的jcmd命令查看直接内存:

jcmd <pid> VM.native_memory [summary | detail | baseline | summary.diff | detail.diff | shutdown] [scale= KB | MB | GB]
  • summary
    • 分类内存使用情况.
  • detail
    • 详细内存使用情况,除了summary信息之外还包含了虚拟内存使用情况。
  • baseline
    • 创建内存使用快照,方便和后面做对比
  • summary.diff
    • 和上一次baseline的summary对比
  • detail.diff
    • 和上一次baseline的detail对比
  • shutdown
    • 关闭NMT

总结

本文所阐述的是实际开发中经常会使用到的一些Java性能监控与排障处理工具,可能在不远的将来会有更加优秀的分析工具面世。

但是,无论用什么工具,最终一定会定位到具体的业务代码或者框架的代码,再加上对于业务和技术的理解相互配合才能准确的定位到问题,单单为了使用工具而来学习工具,这样做的意义不大。

只有多多分析问题,排查问题才能对发挥出各种工具应有的价值。

重要的事情说三遍:实践实践实践

image.png

参考文献