JVM 性能调优监控工具

  • Post author:
  • Post category:其他


本篇主要学习记录下工作中常用的

JDK

自带的一些

JVM

性能调优监控工具,通过了解这些工具,可以在排查问题时给予我们非常大的帮助,将一些隐藏在底下的东西拿到明面上来做分析。

jps(Java Virtual Machine Process Status Tool)


jps

主要用来输出

JVM

中运行的进程状态信息。语法格式如下:

jps [options] [hostid] 复制代码

如果不指定

hostid

就默认为当前主机或服务器,命令行参数选项说明如下:

-q 不输出类名、Jar名和传入main方法的参数

➜  ~ jps -q 42060 复制代码

-m 输出传入 main 方法的参数(与默认 jps 指令返回的信息相同)

➜  ~ jps -m 42060 TestSofaBootApplication 复制代码

-l 输出 main 类或 jar 的全限名

➜  ~ jps -l 42060 com.glmapper.bridge.boot.TestSofaBootApplication 复制代码

-v 输出传入 JVM 的参数

➜  ~ jps -v 42060 TestSofaBootApplication -agentlib:jdwp=transport=dt_socket,address=127.0.0.1:51645,suspend=y,server=n -XX:TieredStopAtLevel=1 -Xverify:none -Dspring.output.ansi.enabled=always -Dcom.sun.management.jmxremote -Dspring.jmx.enabled=true -Dspring.liveBeansView.mbeanDomain -Dspring.application.admin.enabled=true -javaagent:/Users/xxxx/Library/Caches/JetBrains/IntelliJIdea2020.1/captureAgent/debugger-agent.jar -Dfile.encoding=UTF-8 复制代码

在排查问题时,我们通过都会通过

jps

来看下当前机器运行的进程有哪些,通过不同的参数来快速找到我们目标进程所在的

pid

,以便于我们后续的一系列排查操作。

jstack(Java Stack Trace)


jstack

主要用来查看某个

Java

进程内的线程堆栈信息。如果

java

程序崩溃生成

core

文件,

jstack

工具可以用来获得

core

文件的

java stack



native stack

的信息,从而可以轻松地知道

java

程序是如何崩溃和在程序何处发生问题。另外,

jstack

工具还可以附属到正在运行的

java

程序中,看到当时运行的

java

程序的

java stack



native stack

的信息, 如果现在运行的

java

程序呈现

hung

的状态,

jstack

是非常有用的。

下面是

jstack

语法格式:

jstack [option] pid jstack [option] executable core jstack [option] [server-id@]remote-hostname-or-ip 复制代码


不管是什么指令,我们都要学会先通过 -h 去查一下

➜  ~ jstack -h Usage:     jstack [-l] <pid>         (连接到正在运行的进程)     jstack -F [-m] [-l] <pid>         (连接到挂起的进程)     jstack [-m] [-l] <executable> <core>         (连接到 core 文件)     jstack [-m] [-l] [server_id@]<remote server IP or hostname>         (连接到远程调试服务器) Options:     -F  to force a thread dump. Use when jstack <pid> does not respond (process is hung)     -m  to print both java and native frames (mixed mode)     -l  long listing. Prints additional information about locks     -h or -help to print this help message 复制代码


Options

参数说明如下:

选项 作用
-F 当正常输出的请求不被响应时,强制输出线程堆栈
-m 如果调用到本地方法的话,可以显示 C/C++ 的堆栈
-l 除堆栈外,显示关于锁的附加信息,在发生死锁时可以用 jstack -l pid 来观察锁持有情况

下面我们重点来聊一聊,

jstack

中信息到底要怎么看。

jstack 堆栈信息介绍

下面是

jstack

输出的一段

tacer

数据

"main" #1 prio=5 os_prio=31 tid=0x00007fb93b802000 nid=0x2703 waiting on condition [0x0000700005e5d000]    java.lang.Thread.State: TIMED_WAITING (sleeping) at java.lang.Thread.sleep(Native Method) at com.glmapper.bridge.boot.TestJstack.testWaitingOnConditionCondition(TestJstack.java:19) at com.glmapper.bridge.boot.TestJstack.main(TestJstack.java:10) 复制代码

通过这段数据我们大概能

get

到的点主要包括以下信息:

  • main 线程名

  • #1 堆栈序号,没有实际含义,可忽略

  • prio 线程优先级

  • os_prio 操作系统层次的优先级

  • tid 线程标识

  • nid 线程id

线程状态介绍

从上面 jstack 输出的信息可以看到线程状态相关的信息,比如

TIMED_WAITING

java.lang.Thread.State: TIMED_WAITING (sleeping) 复制代码

RUNNABLE

java.lang.Thread.State: RUNNABLE 复制代码

还有一些

"GC task thread#0 (ParallelGC)" os_prio=31 tid=0x00007fcee9004000 nid=0x1f07 runnable

信息,这种是 jvm 用来回收内存的,先不关注,这里主要看下

java.lang.Thread.State

;

public enum State {     /**      * 当线程对象创建时存在的状态,此时线程不可能执行      */     NEW,    /**     * 当调用thread.start()后,线程变成为 Runnable 状态。只要得到CPU,就可以执行;     */     RUNNABLE,     /**      * 如果进入同步方法或同步代码块,没有获取到锁,则会进入该状态;      */     BLOCKED,     /**      * 执行thread.join()或在锁对象调用obj.wait()等情况就会进该状态,表明线程正处于等待某个资源或条件发生来唤醒自己;      */     WAITING,     /**      * 执行Thread.sleep(long)、thread.join(long)或obj.wait(long)等就会进该状态,与Waiting的区别在于Timed_Waiting的等待有时间限制;      */     TIMED_WAITING,     /**      * 终止      */     TERMINATED; } 复制代码

再回到上面堆栈信息,可以观察到,当状态是 TIMED_WAITING 时,堆栈中会出现

waiting on condition xxxx

信息,类似的还有:

  • waiting on monitor entry : 在等待获取锁,一般对应 BLOCKED

  • in Object.wait() : 获取锁后又执行obj.wait()放弃锁,一般对应 WAITING

下面就针对这些状态举一些简单的小例子。

线程状态举例及 jstack 分析

waiting on condition


1、执行代码

/**  * 产生 waiting on condition  */ private static void testWaitingOnConditionCondition(){     while (true){         try {             Thread.sleep(60000);         } catch (InterruptedException e) {             e.printStackTrace();         }     } } 复制代码


2、执行结果

"main" #1 prio=5 os_prio=31 tid=0x00007fb93b802000 nid=0x2703 waiting on condition [0x0000700005e5d000]    java.lang.Thread.State: TIMED_WAITING (sleeping) at java.lang.Thread.sleep(Native Method) at com.glmapper.bridge.boot.TestJstack.testWaitingOnConditionCondition(TestJstack.java:19) at com.glmapper.bridge.boot.TestJstack.main(TestJstack.java:10) 复制代码


3、结果分析

这里就比较明显的是 main 线程中正在 sleep 方法。不过这里 TIMED_WAITING 后面的括号里还特殊表明了

sleeping

,在一些场景下



常见的还有 parking,下面继续看例子。

waiting on condition (parking)


1、执行代码

private static void testWaitingOnConditionConditionWithParking(){     // 提供一个阻塞对了     BlockingQueue<String> blockingQueue = new ArrayBlockingQueue<String>(1);     // 先加一个     blockingQueue.add("test-parking");     try {         //继续加,这里肯定加不进去,所以会阻塞         blockingQueue.put("test-parking-xxx");     } catch (InterruptedException e) {         e.printStackTrace();     } } 复制代码


2、执行结果

"main" #1 prio=5 os_prio=31 tid=0x00007fd6d5008800 nid=0x2803 waiting on condition [0x000070000ffc1000]    java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for  <0x000000076af3a938> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039) at java.util.concurrent.ArrayBlockingQueue.put(ArrayBlockingQueue.java:353) at com.glmapper.bridge.boot.TestJstack.testWaitingOnConditionConditionWithParking(TestJstack.java:113) at com.glmapper.bridge.boot.TestJstack.main(TestJstack.java:13) 复制代码


3、结果分析

main 线程进入了 waiting on conditon 状态,等待某一个资源,可以看到是在

a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObjec

进行了等待,阻塞住了。

waiting on monitor entry


1、执行代码

/**  * 产生 waiting on monitor entry  */ private static void testWaitingOnMonitorEntry(){     final Object obj = new Object();     final Thread thread = new Thread(){         @Override         public void run() {             // 锁 obj 对象             synchronized (obj){                 System.out.println(Thread.currentThread().getName());                 try {                     Thread.sleep(60000);                 } catch (InterruptedException e) {                     e.printStackTrace();                 }             }         }     };     final Thread thread1 = new Thread(){         @Override         public void run() {             // 锁 obj 对象             synchronized (obj){                 System.out.println(Thread.currentThread().getName());                 try {                     Thread.sleep(60000);                 } catch (InterruptedException e) {                     e.printStackTrace();                 }             }         }     };     thread.setName("test-thread");     thread.start();     thread1.setName("test-thread1");     thread1.start(); } 复制代码


2、执行结果

"test-thread1" #14 prio=5 os_prio=31 tid=0x00007f9563880800 nid=0x5c03 waiting for monitor entry [0x000070000b029000]    java.lang.Thread.State: BLOCKED (on object monitor) at com.glmapper.bridge.boot.TestJstack$2.run(TestJstack.java:50) - waiting to lock <0x000000076af261d0> (a java.lang.Object) "test-thread" #13 prio=5 os_prio=31 tid=0x00007f956387f800 nid=0x5a03 waiting on condition [0x000070000af26000]    java.lang.Thread.State: TIMED_WAITING (sleeping) at java.lang.Thread.sleep(Native Method) at com.glmapper.bridge.boot.TestJstack$1.run(TestJstack.java:38) - locked <0x000000076af261d0> (a java.lang.Object) 复制代码


3、结果分析

test-thread 获取到 obj 对象上的锁,因此正在执行 sleep 操作,状态为 TIMED_WAINTING, 而 test-thread1 由于未获取到 obj 对象上的锁,因此处于BLOCKED 状态。

test-thread1 正在 “waiting to lock <0x000000076af261d0>”,试图在地址为 0x000000076af261d0 所在的对象获取锁,而该锁却被 test-thread 线程占有 [locked <0x000000076af261d0>]。test-thread 线程正在 “waiting on condition”,说明正在等待某个条件触发,由 jstack 来看,此线程正在sleep。

object.wait()


1、执行代码

private static void testObjectWait() {     final Thread thread = new Thread() {         @Override         public void run() {             synchronized (this) {                 System.out.println(Thread.currentThread().getName());                 try {                     wait();                 } catch (InterruptedException e) {                     e.printStackTrace();                 }             }         }     };     thread.start();     thread.setName("test-object-wait");     try {         Thread.sleep(5000);     } catch (InterruptedException e) {         e.printStackTrace();     }     synchronized (thread) {         System.out.println(Thread.currentThread().getName());         try {             Thread.sleep(30000);         } catch (InterruptedException e) {             e.printStackTrace();         }         thread.notify();     } } 复制代码


2、执行结果

"test-object-wait" #13 prio=5 os_prio=31 tid=0x00007fd43a809000 nid=0xa803 in Object.wait() [0x0000700010926000]    java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x000000076af26140> (a com.glmapper.bridge.boot.TestJstack$3) at java.lang.Object.wait(Object.java:502) at com.glmapper.bridge.boot.TestJstack$3.run(TestJstack.java:73) - locked <0x000000076af26140> (a com.glmapper.bridge.boot.TestJstack$3) "main" #1 prio=5 os_prio=31 tid=0x00007fd43b001800 nid=0x2603 waiting on condition [0x000070000f2e4000]    java.lang.Thread.State: TIMED_WAITING (sleeping) at java.lang.Thread.sleep(Native Method) at com.glmapper.bridge.boot.TestJstack.testObjectWait(TestJstack.java:93) - locked <0x000000076af26140> (a com.glmapper.bridge.boot.TestJstack$3) at com.glmapper.bridge.boot.TestJstack.main(TestJstack.java:10) 复制代码


3、结果分析

由于调用了 object.wait() 方法的时候放弃了锁,所以

test-object-wait

这个线程就出现了 Object.wait() 状态,线程的状态就是 waiting;等待 notify 来进行唤醒。由于 mian 线程在获得

test-object-wait

的线程锁后,调用了 Thread.sleep 方法,所以此时进入了 wating on condition 等待某一个资源,进入到 time_waiting 状态。

小结

一般情况我们在做问题排查时,如果系统非常慢,我们需要特别关注

Blocked



Waiting on condition

这些状态。如果系统的 cpu 负载比较高的话,则可以死循环等思路去摸查,此时要关注下

Runable

状态;那如果堆栈中有

Deadlock

,那就是产生了死锁。

jstat(JVM统计监测工具)


jstat

是 JVM 统计监测工具,其语法格式如下:

jstat -<option> [-t] [-h<lines>] <vmid> [<interval> [<count>]] 复制代码


vmid



Java

虚拟机

ID

,在

Linux/Unix

系统上一般就是进程

ID



interval

是采样时间间隔;

count

是采样数目。比如下面输出的是

GC

信息,采样时间间隔为 1000ms,采样数为 3:

➜  ~ jstat -gc 58950 1000 3 S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT 10752.0 10752.0  0.0    0.0   65536.0   6554.0   175104.0     0.0     4480.0 785.7  384.0   75.9       0    0.000   0      0.000    0.000 10752.0 10752.0  0.0    0.0   65536.0   6554.0   175104.0     0.0     4480.0 785.7  384.0   75.9       0    0.000   0      0.000    0.000 10752.0 10752.0  0.0    0.0   65536.0   6554.0   175104.0     0.0     4480.0 785.7  384.0   75.9       0    0.000   0      0.000    0.000 复制代码

输出信息的列释义:

  • S0C、S1C、S0U、S1U:Survivor 0/1区容量(Capacity)和使用量(Used)

  • EC、EU:Eden区容量和使用量

  • OC、OU:年老代容量和使用量

  • PC、PU:永久代容量和使用量

  • YGC、YGT:年轻代 GC 次数和 GC 耗时

  • FGC、FGCT:Full GC 次数和 Full GC耗时

  • GCT:GC 总耗时

jmap(Memory Map)


jmap

用来查看堆内存使用状况,一般结合

jhat

使用。其使用语法如下:

jmap [option] <pid> jmap [option] <executable <core> jmap [option] [server_id@]<remote server IP or hostname> 复制代码


Options

参数说明如下:

选项 作用
打印与

Solaris pmap

相同的信息
-heap 打印

java

堆摘要
-histo[:live] 打印 java 对象堆的直方图;如果指定了“live”子选项,则只计算live对象
-clstats 打印 classloader 统计信息
-finalizerinfo 打印 等待终结 对象的信息
–dump: : 以 hprof 二进制格式dump java heap
-F 使用 -dump:  or -histo 强制执行
-J 将  直接传递给运行时系统

dump-options 又包括以下几个选项:

  • live : 只 dump 活动对象;如果未指定,堆中的所有对象将被dump。

  • format=b : 二进制格式

  • file= : dump 到指定文件


jmap -heap

通过指定

pid

,可以将当前进程的

heap

信息打印在

console

上,包括使用的

GC

算法、堆配置参数和各代中堆内存使用情况,如下:

$ jmap -heap 3493 Attaching to process ID 3493, please wait... Debugger attached successfully. Server compiler detected. JVM version is 25.172-b245 using parallel threads in the new generation.(eden 区使用的是并发线程) using thread-local object allocation.(使用线程本地对象分配) Concurrent Mark-Sweep GC (使用 CMS 垃圾收集器) # 堆配置信息 Heap Configuration:    MinHeapFreeRatio         = 40    MaxHeapFreeRatio         = 70    MaxHeapSize              = 2147483648 (2048.0MB)    NewSize                  = 805306368 (768.0MB)    MaxNewSize               = 805306368 (768.0MB)    OldSize                  = 1342177280 (1280.0MB)    NewRatio                 = 2    SurvivorRatio            = 8    MetaspaceSize            = 21807104 (20.796875MB)    CompressedClassSpaceSize = 1073741824 (1024.0MB)    MaxMetaspaceSize         = 17592186044415 MB    G1HeapRegionSize         = 0 (0.0MB) # 堆使用情况 Heap Usage: New Generation (Eden + 1 Survivor Space):    capacity = 724828160 (691.25MB)    used     = 35156456 (33.527809143066406MB)    free     = 689671704 (657.7221908569336MB)    4.850315970063856% used Eden Space:    capacity = 644349952 (614.5MB)    used     = 19878008 (18.95714569091797MB)    free     = 624471944 (595.542854309082MB)    3.084970820328392% used From Space:    capacity = 80478208 (76.75MB)    used     = 15278448 (14.570663452148438MB)    free     = 65199760 (62.17933654785156MB)    18.984577787815553% used To Space:    capacity = 80478208 (76.75MB)    used     = 0 (0.0MB)    free     = 80478208 (76.75MB)    0.0% used concurrent mark-sweep generation:    capacity = 1342177280 (1280.0MB)    used     = 166885296 (159.1542205810547MB)    free     = 1175291984 (1120.8457794189453MB)    12.433923482894897% used 55843 interned Strings occupying 6689024 bytes. 复制代码

jmap -clstats

通过指定 pid ,可以将当前进程的 classloader 统计信息打印在 console 上,包括类加载器名称、对象是否存活、对象地址、父类加载器、已加载的类大小等信息,如下:

$ jmap -clstats  3493 Attaching to process ID 3493, please wait... Debugger attached successfully. Server compiler detected. JVM version is 25.172-b245 finding class loader instances ..done. computing per loader stat ..done. please wait.. computing liveness.......................liveness analysis may be inaccurate ... class_loader classes bytes parent_loader alive? type <bootstrap> 3211 5818395   null   live <internal> 0x00000000b150ed50 1 1491 0x00000000b0020830 dead sun/reflect/DelegatingClassLoader@0x000000010000a040 0x00000000b8715670 1 900     0x00000000b0020830 dead sun/reflect/DelegatingClassLoader@0x000000010000a040 0x00000000cb417140 1 1503 0x00000000b0020830 dead sun/reflect/DelegatingClassLoader@0x000000010000a040 0x00000000b98b4388 1 1491   null   dead sun/reflect/DelegatingClassLoader@0x000000010000a040 0x00000000b5a419a0 1 900     0x00000000b0020830 dead sun/reflect/DelegatingClassLoader@0x000000010000a040 0x00000000b358df50 1 1493 0x00000000b0020830 dead sun/reflect/DelegatingClassLoader@0x000000010000a040 0x00000000b7b277b8 1 1503 0x00000000b0020830 dead sun/reflect/DelegatingClassLoader@0x000000010000a040 0x00000000c2527c58 1 1505 0x00000000b0020830 dead sun/reflect/DelegatingClassLoader@0x000000010000a040 0x00000000b98b4580 1 1491 0x00000000b0026260 dead sun/reflect/DelegatingClassLoader@0x000000010000a040 0x00000000b9b307b8 1 1493 0x00000000b0020830 dead sun/reflect/DelegatingClassLoader@0x000000010000a040 0x00000000e236b038 1 900     0x00000000b0020830 dead sun/reflect/DelegatingClassLoader@0x000000010000a040 0x00000000b0108400 1 1493 0x00000000b0020830 dead sun/reflect/DelegatingClassLoader@0x000000010000a040 0x00000000b010bc00 3 7946 0x00000000b0022f60 live org/jacoco/compass/agent/rt/internal/fastjson/util/ASMClassLoader@0x00000001000eb830 0x00000000b358e148 1 1493 0x00000000b0020830 dead sun/reflect/DelegatingClassLoader@0x000000010000a040 复制代码

jmap -histo

使用 jmap -histo pid 可以查看堆内存中的对象数目、大小统计直方图,如下:

# jmap -histo:live 1493  带上 live 则只统计存活对象 $ jmap -histo 1493   num     #instances         #bytes  class name ----------------------------------------------    1:       1314509      144436976  [C    2:       1572864       37748736  org.apache.logging.log4j.core.async.AsyncLoggerConfigDisruptor$Log4jEventWrapper    3:         77458       32776608  [B    4:       1061561       25477464  java.lang.String    5:        731623       23411936  java.util.HashMap$Node    6:         32930       22826616  [I    7:        150340       15546784  [Ljava.util.HashMap$Node;    8:        144895       14968208  [Ljava.lang.Object;    9:        377379       12076128  java.util.concurrent.ConcurrentHashMap$Node   10:        230943       11085264  java.util.HashMap   11:         81124        3893952  java.nio.HeapByteBuffer   12:          3396        3869944  [Ljava.util.concurrent.ConcurrentHashMap$Node;   13:         78418        3764064  java.nio.HeapCharBuffer   14:         75784        3031360  java.util.TreeMap$Entry   15:         72865        2914600  java.util.LinkedHashMap$Entry   16:        166213        2659408  java.util.HashSet   17:         18355        2643120  com.mysql.jdbc.Field   18:         18394        2044336  java.lang.Class   19:         19966        1757008  java.lang.reflect.Method 复制代码

PS: 上图中的 [C [B 指的是 class 的对象类型,下面是常见类型的参考

  • B  byte

  • C  char

  • D  double

  • F  float

  • I  int

  • J  long

  • Z  boolean

  • [  数组,如 [I 表示 int[]

  • [L+类名 其他对象,如 [Ljava.lang.Object

jmap -dump

绝大多数情况下,我们不会直接在 console 来打印分析,更常规的做法是 dump 到指定的文件,然后通过一些可视化工具来辅助分析;那执行 dump 到文件一般使用如下指令:

jmap -dump:format=b,file=dumpFileName pid   # 语法 $ jmap -dump:format=b,file=test-dump.bin 85716  # 举例 Dumping heap to /Users/guolei.sgl/test-dump.bin ... Heap dump file created 复制代码

对于 dump 下来的文件,可以通过 jprofile 等图形化工具来分析,如下

也可以通过 jhat 查看,操作方式如下:


1、起 http 服务

jhat -port 9300 test-dump.bin Reading from test-dump.bin... Dump file created Wed Oct 28 17:54:24 CST 2020 Snapshot read, resolving... Resolving 1151952 objects... Chasing references, expect 230 dots...................................................................................................................................................................................................................................... Eliminating duplicate references...................................................................................................................................................................................................................................... Snapshot resolved. Started HTTP server on port 9300 Server is ready. 复制代码


2、dump 类概要信息

访问 localhost:9300 查看 dump 概要信息

http://img.mukewang.com/5faddabd00018a8a13100627.jpg


3、class 详情

点击某个类查看详细信息

http://img.mukewang.com/5faddabd0001d52714051056.jpg

小结

本文介绍了一些 JDK 自带的一些性能调优监控工具,通过对这些工具的掌握,可以使的我们在实际的开发或者运维中能够快速的去定位和解决一些问题,常见的有 OOM、内存泄漏、线程死锁、CPU 负载高等等;目前社区也有很多好用的工具,例如 Arthas,perfma 等。


作者:glmapper