深入JVM十一:JVM常见调优工具

  • Post author:
  • Post category:其他




jmap的使用

jmap主要用来观察运行的JVM进程的内存情况及内存快照生成,这里只要说明其中的几个参数:

  1. histo 主要是展示指定JVM进程内存中包含的对象类型、个数及占用空间大小。
  2. heap 主要是展示当前节点堆中各个空间的使用情况。
  3. 堆内存dump文件的生成。

以上参数均是指定jmap名称节点的堆内存中情况。



histo参数的使用

该参数主要用于查看JVM进程中类的实例个数及占用空间。这里以一个简单的实例代码作为运行的进程,如下:

/**
 * @Description: jmap工具的使用
 * @Author: binga
 * @Date: 2020/9/14 16:37
 * @Blog: https://blog.csdn.net/pang5356
 */
public class JMapTest {

    public static void main(String[] args) throws InterruptedException {
        List<User> list = new ArrayList<>();
        for (int i = 0; i < 100; i++) {
            list.add(new User());
        }

        Thread.sleep(Integer.MAX_VALUE);
    }

    static class User {
    }
}

然后通过jps工具查看当前运行测JVM进程ID,如下:

C:\Users\Administrator>jps
17200 JMapTest
6864
23800 KotlinCompileDaemon
25192 Jps
15596 RemoteMavenServer
25148 Launcher

其进程ID为17200,通过histo参数查看JVM类的实例个数及占用空间。

jmap -histo 17200

结果如下:

num     #instances         #bytes  class name
----------------------------------------------
   1:           660         478376  [B
   2:          3533         400904  [C
   3:           281         146968  [I
   4:          3233          77592  java.lang.String
   5:           610          65080  java.lang.Class
   6:           627          37144  [Ljava.lang.Object;
   7:           785          31400  java.util.TreeMap$Entry
   8:           230          11352  [Ljava.lang.String;
   9:           127           9144  java.lang.reflect.Field
  10:           252           8064  java.util.HashMap$Node
  11:            87           5568  java.net.URL
  12:            50           4400  java.lang.reflect.Method
  13:           256           4096  java.lang.Integer
  14:           115           3680  java.util.Hashtable$Entry
  15:           108           3456  java.util.concurrent.ConcurrentHashMap$Node
  16:            18           2784  [Ljava.util.HashMap$Node;
  17:             7           2632  java.lang.Thread
  18:            54           2160  java.lang.ref.Finalizer
  19:            39           1872  sun.misc.URLClassPath$JarLoader
  20:            38           1824  sun.util.locale.LocaleObjectCache$CacheEntry
  21:            22           1760  java.lang.reflect.Constructor
  22:            83           1744  [Ljava.lang.Class;
  23:            43           1720  java.util.LinkedHashMap$Entry
  24:             1           1712  [[B
  25:           100           1600  com.binga.jvm.jvmtools.JMapTest$User
  26:            11           1520  [Ljava.util.concurrent.ConcurrentHashMap$Node;
  27:            18           1440  [Ljava.util.WeakHashMap$Entry;
  28:            88           1408  java.lang.Object
  ... 
Total         12499        1352056

通过上面的输出结果可以直观的展示当前JVM进程中存在的都有哪些类的对象以及对象个数。其展示的字段含义如下:


  • num

    序号。

  • #instance

    实例数量

  • #bytes

    占用空间大小

  • class name

    实例所属类型(类名称) [C is a char[],[S is a short[],[I is a int[],[B is a byte[],[[I is a int[][]。



heap参数的使用

heap参数用于查看堆的初始信息和当前节点各个区域使用情况。还是以上述的示例代码为例,通过jps获取其进程ID为17200,然后通过jmap命令查看其堆内存配置及使用情况。

jmap -heap 17200

结果如下:

Attaching to process ID 17200, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.11-b03

using thread-local object allocation.
Parallel GC with 4 thread(s)

## 堆内存相关配置
Heap Configuration:
   MinHeapFreeRatio         = 40
   MaxHeapFreeRatio         = 70
   MaxHeapSize              = 2069889024 (1974.0MB)
   NewSize                  = 1572864 (1.5MB)
   MaxNewSize               = 689963008 (658.0MB)
   OldSize                  = 128450560 (122.5MB)
   NewRatio                 = 2
   SurvivorRatio            = 8
   MetaspaceSize            = 21807104 (20.796875MB)
   CompressedClassSpaceSize = 1073741824 (1024.0MB)
   MaxMetaspaceSize         = 17592186044415 MB
   G1HeapRegionSize         = 0 (0.0MB)

##堆内存使用情况
Heap Usage:
PS Young Generation
Eden Space:
   capacity = 524288 (0.5MB)
   used     = 491864 (0.46907806396484375MB)
   free     = 32424 (0.03092193603515625MB)
   93.81561279296875% used
From Space:
   capacity = 524288 (0.5MB)
   used     = 507936 (0.484405517578125MB)
   free     = 16352 (0.015594482421875MB)
   96.881103515625% used
To Space:
   capacity = 524288 (0.5MB)
   used     = 0 (0.0MB)
   free     = 524288 (0.5MB)
   0.0% used
PS Old Generation
   capacity = 128450560 (122.5MB)
   used     = 352256 (0.3359375MB)
   free     = 128098304 (122.1640625MB)
   0.274234693877551% used

1843 interned Strings occupying 161336 bytes.



堆内存dump

通过一下命令:

jmap -dump:format=b,file=path.hprof pid

从而可以将指定的JVM进程的内存dump文件输出到指定的文件。

C:\Users\Administrator>jmap -dump:format=b,file=F:\test\test.hprof 17200
Dumping heap to F:\test\test.hprof ...
Heap dump file created

生成的dump文件可以通过java visualVM加载查看,步骤如下:

在这里插入图片描述

在点击加载快照后,然后选择生成的快照文件:

在这里插入图片描述

加载完成后可以查看生成快照是堆内存的实例个数信息、线程堆栈信息等JVM运行时的内容信息:

在这里插入图片描述

当然JVM提供了以下参数用于在内存溢出时生成dump文件,参数如下:

  • -XX:+HeapDumpOnOutOfMemoryError
  • -XX:HeapDumpPath=path

查看一下示例:

/**
 * @Description: oom时生成dump文件测试
 *               -Xms10m -Xmx10m -XX:+PrintGCDetails -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=jvm.dump
 * @Author: binga
 * @Date: 2020/9/14 18:13
 * @Blog: https://blog.csdn.net/pang5356
 */
public class OOMDumpTest {

    public static void main(String[] args) {
        List<User> list = new ArrayList<User>();
        while(true) {
            list.add(new User());
        }
    }

    static class User {

    }
}

生成的dump文件也可通过java visualVM查看,如下:

在这里插入图片描述



jinfo的使用

通过该命令工具可以查看当前运行的JVM的相关系统参数配置。其中有如下几个参数:

  • flags 通过该参数可以查看指定的JVM进程的启动参数等信息。
  • sysprops 通过该参数可以查看指定的JVM进程的系统属性。

接下来还是以jmap介绍时的代码为例来使用jinfo。



flags 参数的使用

使用命令jps查询出该JVM进程ID,然后使用jinfo命令查看如下:

C:\Users\Administrator>jinfo -flags 2320
Attaching to process ID 2320, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.11-b03
Non-default VM flags: -XX:InitialHeapSize=130023424 -XX:MaxHeapSize=2069889024 -XX:MaxNewSize=689963008 -XX:MinHeapDeltaBytes=524288 -XX:NewSize=1572864 -XX:OldSize=128450560 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:-UseLargePagesIndividualAllocation -XX:+UseParallelGC
Command line:  -javaagent:D:\ideal\IntelliJ IDEA 2019.3\lib\idea_rt.jar=53768:D:\ideal\IntelliJ IDEA 2019.3\bin -Dfile.encoding=UTF-8

当然还有一个flag参数用于查看和设置指定的JVM参数,如通过jinfo查看InitialHeapSize设置的大小如下:

C:\Users\Administrator>jinfo -flag InitialHeapSize 2320
-XX:InitialHeapSize=130023424



sysprops参数的使用

查看JVM的系统属性相关的参数,如下:

C:\Users\Administrator>jinfo -sysprops 2320
Attaching to process ID 2320, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.11-b03
java.runtime.name = Java(TM) SE Runtime Environment
java.vm.version = 25.11-b03
sun.boot.library.path = C:\Program Files\Java\jdk1.8.0_11\jre\bin
java.vendor.url = http://java.oracle.com/
java.vm.vendor = Oracle Corporation
path.separator = ;
file.encoding.pkg = sun.io
java.vm.name = Java HotSpot(TM) 64-Bit Server VM
sun.os.patch.level =
sun.java.launcher = SUN_STANDARD
user.script =
user.country = CN
user.dir = E:\t4\learn
java.vm.specification.name = Java Virtual Machine Specification
java.runtime.version = 1.8.0_11-b12
java.awt.graphicsenv = sun.awt.Win32GraphicsEnvironment
os.arch = amd64
java.endorsed.dirs = C:\Program Files\Java\jdk1.8.0_11\jre\lib\endorsed
line.separator =


java.io.tmpdir = C:\Users\Administrator\AppData\Local\Temp\
java.vm.specification.vendor = Oracle Corporation
user.variant =
os.name = Windows 8.1
sun.jnu.encoding = GBK
java.library.path = C:\Program Files\Java\jdk1.8.0_11\bin;C:\Windows\Sun\Java\bin;C:\Windows\system32;C:\Windows;D:\mysoft\xftp\;D:\mysoft\xshell\;C:\Program Files (x86)\Common Files\NetSarang;D:\oracle\product\10.2.0\client_1\bin;C:\Program Files\Java\jdk1.8.0_11\bin;C:\Program Files\Java\jdk1.8.0_11\jre\bin;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\System32\WindowsPowerShell\v1.0\;C:\Program Files\TortoiseSVN\bin;D:\maven\apache-maven-3.5.4\bin;D:\mysoft\mysql\bin;D:\gradle\gradle-4.4.1\bin;D:\maven\apache-maven-3.5.4\bin;D:\elasticsearch\nodejs\;C:\Users\Administrator\AppData\Local\Microsoft\WindowsApps;C:\Users\Administrator\AppData\Roaming\npm;C:\Users\Administrator\AppData\Local\BypassRuntm;%IntelliJ IDEA%;C:\Program Files\Java\jdk1.8.0_11\bin;C:\Program Files\Java\jdk1.8.0_11\jre\bin;D:\mysoft\tomcat8\bin;D:\mysoft\tomcat8\lib;.
java.specification.name = Java Platform API Specification
java.class.version = 52.0
sun.management.compiler = HotSpot 64-Bit Tiered Compilers
os.version = 6.3
user.home = C:\Users\Administrator
user.timezone = Asia/Shanghai
java.awt.printerjob = sun.awt.windows.WPrinterJob
file.encoding = UTF-8
java.specification.version = 1.8
user.name = Administrator
java.class.path = C:\Program Files\Java\jdk1.8.0_11\jre\lib\charsets.jar;C:\Program Files\Java\jdk1.8.0_11\jre\lib\deploy.jar;C:\Program Files\Java\jdk1.8.0_11\jre\lib\ext\access-bridge-64.jar;C:\Program Files\Java\jdk1.8.0_11\jre\lib\ext\cldrdata.jar;C:\Program Files\Java\jdk1.8.0_11\jre\lib\ext\dnsns.jar;C:\Program Files\Java\jdk1.8.0_11\jre\lib\ext\jaccess.jar;C:\Program Files\Java\jdk1.8.0_11\jre\lib\ext\jfxrt.jar;C:\Program Files\Java\jdk1.8.0_11\jre\lib\ext\localedata.jar;C:\Program Files\Java\jdk1.8.0_11\jre\lib\ext\nashorn.jar;C:\Program Files\Java\jdk1.8.0_11\jre\lib\ext\sunec.jar;C:\Program Files\Java\jdk1.8.0_11\jre\lib\ext\sunjce_provider.jar;C:\Program Files\Java\jdk1.8.0_11\jre\lib\ext\sunmscapi.jar;C:\Program Files\Java\jdk1.8.0_11\jre\lib\ext\sunpkcs11.jar;C:\Program Files\Java\jdk1.8.0_11\jre\lib\ext\zipfs.jar;C:\Program Files\Java\jdk1.8.0_11\jre\lib\javaws.jar;C:\Program Files\Java\jdk1.8.0_11\jre\lib\jce.jar;C:\Program Files\Java\jdk1.8.0_11\jre\lib\jfr.jar;C:\Program Files\Java\jdk1.8.0_11\jre\lib\jfxswt.jar;C:\Program Files\Java\jdk1.8.0_11\jre\lib\jsse.jar;C:\Program Files\Java\jdk1.8.0_11\jre\lib\management-agent.jar;C:\Program Files\Java\jdk1.8.0_11\jre\lib\plugin.jar;C:\Program Files\Java\jdk1.8.0_11\jre\lib\resources.jar;C:\Program Files\Java\jdk1.8.0_11\jre\lib\rt.jar;E:\t4\learn\jvm\target\classes;D:\maven\springrepository\Repository\cglib\cglib\3.1\cglib-3.1.jar;D:\maven\springrepository\Repository\org\ow2\asm\asm\4.2\asm-4.2.jar;D:\maven\springrepository\Repository\org\openjdk\jol\jol-core\0.9\jol-core-0.9.jar;D:\ideal\IntelliJ IDEA 2019.3\lib\idea_rt.jar
java.vm.specification.version = 1.8
sun.arch.data.model = 64
sun.java.command = com.binga.jvm.jvmtools.JMapTest
java.home = C:\Program Files\Java\jdk1.8.0_11\jre
user.language = zh
java.specification.vendor = Oracle Corporation
awt.toolkit = sun.awt.windows.WToolkit
java.vm.info = mixed mode
java.version = 1.8.0_11
java.ext.dirs = C:\Program Files\Java\jdk1.8.0_11\jre\lib\ext;C:\Windows\Sun\Java\lib\ext
sun.boot.class.path = C:\Program Files\Java\jdk1.8.0_11\jre\lib\resources.jar;C:\Program Files\Java\jdk1.8.0_11\jre\lib\rt.jar;C:\Program Files\Java\jdk1.8.0_11\jre\lib\sunrsasign.jar;C:\Program Files\Java\jdk1.8.0_11\jre\lib\jsse.jar;C:\Program Files\Java\jdk1.8.0_11\jre\lib\jce.jar;C:\Program Files\Java\jdk1.8.0_11\jre\lib\charsets.jar;C:\Program Files\Java\jdk1.8.0_11\jre\lib\jfr.jar;C:\Program Files\Java\jdk1.8.0_11\jre\classes
java.vendor = Oracle Corporation
file.separator = \
java.vendor.url.bug = http://bugreport.sun.com/bugreport/
sun.io.unicode.encoding = UnicodeLittle
sun.cpu.endian = little
sun.desktop = windows
sun.cpu.isalist = amd64

通过上面的结果可以其主要就是打印出系统配置的属性。



jstat的使用

jstat命令可以查看堆内存各部分的使用量,以及加载类的数量。命令的格式如下:

jstat [-命令选项] [vmid] [间隔时间(毫秒)] [查询次数]

注意:使用的jdk版本是jdk8。



垃圾回收统计

jstat -gc pid

最常用,可以评估程序内存使用及GC压力整体情况。接下来以一段示例代码来演示:

/**
 * @Description: Jstat工具的使用测试
 *              -Xms1024m -Xmx1024m -Xmn512m
 * @Author: binga
 * @Date: 2020/9/15 10:29
 * @Blog: https://blog.csdn.net/pang5356
 */
public class JstatToolsTest {

    public static void main(String[] args) {
        List<User> users = new ArrayList<>();
        int index = 0;
        while (true) {
            if (index % 10000 == 0) {
                users.add(new User());
            } else {
                new User();
            }
        }
    }

    static class User {

    }
}

通过-gc参数结果如下:

C:\Users\Administrator>jstat -gc 10872
 S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT
65536.0 65536.0  0.0    0.0   393216.0 393216.0  524288.0   490492.7  4864.0 3339.1 512.0  361.8       2    1.209   5     27.810   29.019

当然也可以通过指定输出的次数和频率如:

jstat -gc 10872 1000 5

代表的是每1秒输出一次,总共输出5次,如下:

C:\Users\Administrator>jstat -gc 10872 1000 5
 S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT
65536.0 65536.0  0.0    0.0   393216.0 393216.0  524288.0   490517.7  4864.0 3339.1 512.0  361.8       2    1.209  30    150.260  151.469
65536.0 65536.0  0.0    0.0   393216.0 393216.0  524288.0   490518.7  4864.0 3339.1 512.0  361.8       2    1.209  31    154.907  156.115
65536.0 65536.0  0.0    0.0   393216.0 393216.0  524288.0   490518.7  4864.0 3339.1 512.0  361.8       2    1.209  31    154.907  156.115
65536.0 65536.0  0.0    0.0   393216.0 393216.0  524288.0   490518.7  4864.0 3339.1 512.0  361.8       2    1.209  31    154.907  156.115
65536.0 65536.0  0.0    0.0   393216.0 393216.0  524288.0   490518.7  4864.0 3339.1 512.0  361.8       2    1.209  31    154.907  156.115

那么接下来来说明一下每个字段的含义:

  • S0C:第一个幸存区的大小
  • S1C:第二个幸存区的大小
  • S0U:第一个幸存区的使用大小
  • S1U:第二个幸存区的使用大小
  • EC:伊甸园区的大小
  • EU:伊甸园区的使用大小
  • OC:老年代大小
  • OU:老年代使用大小
  • MC:方法区大小(元空间)
  • MU:方法区使用大小
  • CCSC:压缩类空间大小
  • CCSU:压缩类空间使用大小
  • YGC:年轻代垃圾回收次数
  • YGCT:年轻代垃圾回收消耗时间,单位s(指从JVM启动每次的YGC时间总和)
  • FGC:老年代垃圾回收次数
  • FGCT:老年代垃圾回收消耗时间,单位s (指从JVM启动每次的FGC时间总和)
  • GCT:垃圾回收消耗总时间,单位s



堆内存统计

jstat -gccapacity pid

统计运行时JVM的堆空间各个区域的大小。还是以上面的例子示例:如下:

C:\Users\Administrator>jstat -gccapacity 5416
 NGCMN    NGCMX     NGC     S0C   S1C       EC      OGCMN      OGCMX       OGC         OC       MCMN     MCMX      MC     CCSMN    CCSMX     CCSC    YGC    FGC
524288.0 524288.0 524288.0 65536.0 65536.0 393216.0   524288.0   524288.0   524288.0   524288.0      0.0 1056768.0   4864.0      0.0 1048576.0    512.0      2    10

当然也可以通过指定输出的频率和次数:

jstat -gccapacity 5416 1000 5

其含义是每1秒输出一次,输出5次。如下:

C:\Users\Administrator>jstat -gccapacity 5416 1000 5
 NGCMN    NGCMX     NGC     S0C   S1C       EC      OGCMN      OGCMX       OGC         OC       MCMN     MCMX      MC     CCSMN    CCSMX     CCSC    YGC    FGC
524288.0 524288.0 524288.0 65536.0 65536.0 393216.0   524288.0   524288.0   524288.0   524288.0      0.0 1056768.0   4864.0      0.0 1048576.0    512.0      2    30
524288.0 524288.0 524288.0 65536.0 65536.0 393216.0   524288.0   524288.0   524288.0   524288.0      0.0 1056768.0   4864.0      0.0 1048576.0    512.0      2    31
524288.0 524288.0 524288.0 65536.0 65536.0 393216.0   524288.0   524288.0   524288.0   524288.0      0.0 1056768.0   4864.0      0.0 1048576.0    512.0      2    31
524288.0 524288.0 524288.0 65536.0 65536.0 393216.0   524288.0   524288.0   524288.0   524288.0      0.0 1056768.0   4864.0      0.0 1048576.0    512.0      2    31
524288.0 524288.0 524288.0 65536.0 65536.0 393216.0   524288.0   524288.0   524288.0   524288.0      0.0 1056768.0   4864.0      0.0 1048576.0    512.0      2    31

那么各个字段的含义如下:

  • NGCMN:新生代最小容量
  • NGCMX:新生代最大容量
  • NGC:当前新生代容量
  • S0C:第一个幸存区大小
  • S1C:第二个幸存区的大小
  • EC:伊甸园区的大小
  • OGCMN:老年代最小容量
  • OGCMX:老年代最大容量
  • OGC:当前老年代大小
  • OC:当前老年代大小
  • MCMN:最小元数据容量
  • MCMX:最大元数据容量
  • MC:当前元数据空间大小
  • CCSMN:最小压缩类空间大小
  • CCSMX:最大压缩类空间大小
  • CCSC:当前压缩类空间大小
  • YGC:年轻代gc次数
  • FGC:老年代GC次数



年轻代垃圾回收统计

jstat -gcnew pid

用于统计新生代垃圾回收。还是上面的例子示例,如下:

C:\Users\Administrator>jstat -gcnew 1416
 S0C    S1C    S0U    S1U   TT MTT  DSS      EC       EU     YGC     YGCT
65536.0 65536.0    0.0    0.0  7  15 65536.0 393216.0 393216.0      2    1.263

当然也可以指定输出的频率和次数,如下:

C:\Users\Administrator>jstat -gcnew 1416 1000 5
 S0C    S1C    S0U    S1U   TT MTT  DSS      EC       EU     YGC     YGCT
65536.0 65536.0    0.0    0.0  7  15 65536.0 393216.0 393216.0      2    1.263
65536.0 65536.0    0.0    0.0  7  15 65536.0 393216.0 393216.0      2    1.263
65536.0 65536.0    0.0    0.0  7  15 65536.0 393216.0 393216.0      2    1.263
65536.0 65536.0    0.0    0.0  7  15 65536.0 393216.0 393216.0      2    1.263
65536.0 65536.0    0.0    0.0  7  15 65536.0 393216.0 393216.0      2    1.263

各个字段含义如下:

  • S0C:第一个幸存区的大小
  • S1C:第二个幸存区的大小
  • S0U:第一个幸存区的使用大小
  • S1U:第二个幸存区的使用大小
  • TT:对象在新生代存活的次数
  • MTT:对象在新生代存活的最大次数
  • DSS:期望的幸存区大小
  • EC:伊甸园区的大小
  • EU:伊甸园区的使用大小
  • YGC:年轻代垃圾回收次数
  • YGCT:年轻代垃圾回收消耗时间



新生代内存统计

jstat -gcnewcapaticy pid

统计新生代的内存状况,如下:

C:\Users\Administrator>jstat -gcnewcapacity 1416
  NGCMN      NGCMX       NGC      S0CMX     S0C     S1CMX     S1C       ECMX        EC      YGC   FGC
  524288.0   524288.0   524288.0 174592.0  65536.0 174592.0  65536.0   523264.0   393216.0     2    56


C:\Users\Administrator>jstat -gcnewcapacity 1416 1000 5
  NGCMN      NGCMX       NGC      S0CMX     S0C     S1CMX     S1C       ECMX        EC      YGC   FGC
  524288.0   524288.0   524288.0 174592.0  65536.0 174592.0  65536.0   523264.0   393216.0     2    57
  524288.0   524288.0   524288.0 174592.0  65536.0 174592.0  65536.0   523264.0   393216.0     2    57
  524288.0   524288.0   524288.0 174592.0  65536.0 174592.0  65536.0   523264.0   393216.0     2    57
  524288.0   524288.0   524288.0 174592.0  65536.0 174592.0  65536.0   523264.0   393216.0     2    58
  524288.0   524288.0   524288.0 174592.0  65536.0 174592.0  65536.0   523264.0   393216.0     2    58

上述同时展示了指定频率和输出次数,那么各个字段的含义如下:

  • NGCMN:新生代最小容量
  • NGCMX:新生代最大容量
  • NGC:当前新生代容量
  • S0CMX:最大幸存1区大小
  • S0C:当前幸存1区大小
  • S1CMX:最大幸存2区大小
  • S1C:当前幸存2区大小
  • ECMX:最大伊甸园区大小
  • EC:当前伊甸园区大小
  • YGC:年轻代垃圾回收次数FGC:老年代回收次数



老年代垃圾回收统计

jstat -gcold pid

主要是统计老年代内存的使用情况等信息,如下:

C:\Users\Administrator>jstat -gcold 1416
   MC       MU      CCSC     CCSU       OC          OU       YGC    FGC    FGCT     GCT
  4864.0   3337.0    512.0    361.8    524288.0    490556.3      2    98  475.959  477.222


C:\Users\Administrator>jstat -gcold 1416  1000 5
   MC       MU      CCSC     CCSU       OC          OU       YGC    FGC    FGCT     GCT
  4864.0   3337.0    512.0    361.8    524288.0    490558.3      2   100  485.218  486.481
  4864.0   3337.0    512.0    361.8    524288.0    490558.3      2   100  485.218  486.481
  4864.0   3337.0    512.0    361.8    524288.0    490558.3      2   100  485.218  486.481
  4864.0   3337.0    512.0    361.8    524288.0    490558.3      2   100  485.218  486.481
  4864.0   3337.0    512.0    361.8    524288.0    490558.3      2   100  485.218  486.481

那么输的的各个字段含义如下:

  • MC:方法区大小
  • MU:方法区使用大小
  • CCSC:压缩类空间大小
  • CCSU:压缩类空间使用大小
  • OC:老年代大小
  • OU:老年代使用大小
  • YGC:年轻代垃圾回收次数
  • FGC:老年代垃圾回收次数
  • FGCT:老年代垃圾回收消耗时间
  • GCT:垃圾回收消耗总时间



老年代内存统计

jstat -gcoldcapacity pid

老年代内存大小等信息的统计。

C:\Users\Administrator>jstat -gcoldcapacity 1416
   OGCMN       OGCMX        OGC         OC       YGC   FGC    FGCT     GCT
   524288.0    524288.0    524288.0    524288.0     2   147  711.373  712.636


C:\Users\Administrator>jstat -gcoldcapacity 1416  1000 5
   OGCMN       OGCMX        OGC         OC       YGC   FGC    FGCT     GCT
   524288.0    524288.0    524288.0    524288.0     2   148  715.932  717.195
   524288.0    524288.0    524288.0    524288.0     2   148  715.932  717.195
   524288.0    524288.0    524288.0    524288.0     2   149  720.566  721.829
   524288.0    524288.0    524288.0    524288.0     2   149  720.566  721.829
   524288.0    524288.0    524288.0    524288.0     2   149  720.566  721.829

各个字段含义如下:

  • OGCMN:老年代最小容量
  • OGCMX:老年代最大容量
  • OGC:当前老年代大小
  • OC:老年代大小
  • YGC:年轻代垃圾回收次数
  • FGC:老年代垃圾回收次数
  • FGCT:老年代垃圾回收消耗时间
  • GCT:垃圾回收消耗总时间



元空间内存统计

jstat -gcmetacapacity pid

元空间大小及垃圾回收统计。

C:\Users\Administrator>jstat -gcmetacapacity 1416
   MCMN       MCMX        MC       CCSMN      CCSMX       CCSC     YGC   FGC    FGCT     GCT
       0.0  1056768.0     4864.0        0.0  1048576.0      512.0     2   193  931.247  932.511


C:\Users\Administrator>jstat -gcmetacapacity 1416 1000 5
   MCMN       MCMX        MC       CCSMN      CCSMX       CCSC     YGC   FGC    FGCT     GCT
       0.0  1056768.0     4864.0        0.0  1048576.0      512.0     2   196  945.792  947.055
       0.0  1056768.0     4864.0        0.0  1048576.0      512.0     2   196  945.792  947.055
       0.0  1056768.0     4864.0        0.0  1048576.0      512.0     2   196  945.792  947.055
       0.0  1056768.0     4864.0        0.0  1048576.0      512.0     2   196  945.792  947.055
       0.0  1056768.0     4864.0        0.0  1048576.0      512.0     2   196  945.792  947.055

各个列字段说明如下:

  • MCMN:最小元数据容量
  • MCMX:最大元数据容量
  • MC:当前元数据空间大小
  • CCSMN:最小压缩类空间大小
  • CCSMX:最大压缩类空间大小
  • CCSC:当前压缩类空间大小
  • YGC:年轻代垃圾回收次数
  • FGC:老年代垃圾回收次数
  • FGCT:老年代垃圾回收消耗时间
  • GCT:垃圾回收消耗总时间

当然还有一个各个区域空间使用比例的统计参数:

jstat -gcutil pid

C:\Users\Administrator>jstat -gcutil 1416
  S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT
  0.00   0.00 100.00  93.60  68.61  70.66      2    1.263   274 1310.417 1311.680

各个字段说明如下:

  • S0:幸存1区当前使用比例
  • S1:幸存2区当前使用比例
  • E:伊甸园区使用比例
  • O:老年代使用比例
  • M:元数据区使用比例
  • CCS:压缩使用比例
  • YGC:年轻代垃圾回收次数
  • FGC:老年代垃圾回收次数
  • FGCT:老年代垃圾回收消耗时间
  • GCT:垃圾回收消耗总时间



jstack的使用

jstack主要用于打印执行JVM进程的线程堆栈信息。如可以通过jstack定位代码中的死锁问题、定位查找线程是什么原因阻塞或者等待以及定位当占用CPU的线程等。



jstack定位死锁问题

通过jstack可以查看出在程序中出现的死锁等问题,看下面一段代码,如下:

/**
 * @Description: 死锁测试
 * @Author: binga
 * @Date: 2020/9/15 14:55
 * @Blog: https://blog.csdn.net/pang5356
 */
public class DeadLockTest {

    public static final Object LOCK1 = new Object();
    public static final Object LOCK2 = new Object();

    public static void main(String[] args) throws InterruptedException {
        Thread t1 = new Thread(new Task1(), "t1");
        Thread t2 = new Thread(new Task2(), "t2");

        t1.start();
        t2.start();

        Thread.sleep(Integer.MAX_VALUE);
    }

    static class Task1 implements Runnable {

        @Override
        public void run() {
            synchronized (LOCK1) {
                try {
                    Thread.sleep(1000);
                } catch (InterruptedException e) {
                    e.printStackTrace();
                }

                synchronized (LOCK2) {
                    System.out.println("get it");
                }
            }
        }
    }

    static class Task2 implements Runnable {

        @Override
        public void run() {
            synchronized (LOCK2) {
                try {
                    Thread.sleep(1000);
                } catch (InterruptedException e) {
                    e.printStackTrace();
                }

                synchronized (LOCK1) {
                    System.out.println("get it");
                }
            }
        }
    }
}

通过jps查询其进程ID,然后通过jstack命令查询线程的栈信息如下:

C:\Users\Administrator>jstack 12720
2020-09-15 15:23:05
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.11-b03 mixed mode):


"t2" #12 prio=5 os_prio=0 tid=0x0000000018d72800 nid=0x31f8 waiting for monitor entry [0x00000000199df000]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at com.binga.jvm.jvmtools.DeadLockTest$Task2.run(DeadLockTest.java:54)
        - waiting to lock <0x00000000d6e5d3f0> (a java.lang.Object)
        - locked <0x00000000d6e5d400> (a java.lang.Object)
        at java.lang.Thread.run(Thread.java:745)


"t1" #11 prio=5 os_prio=0 tid=0x0000000018d71000 nid=0x31e8 waiting for monitor entry [0x00000000198df000]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at com.binga.jvm.jvmtools.DeadLockTest$Task1.run(DeadLockTest.java:36)
        - waiting to lock <0x00000000d6e5d400> (a java.lang.Object)
        - locked <0x00000000d6e5d3f0> (a java.lang.Object)
        at java.lang.Thread.run(Thread.java:745)


"Service Thread" #10 daemon prio=9 os_prio=0 tid=0x0000000018ca7800 nid=0x315c runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE


"C1 CompilerThread2" #9 daemon prio=9 os_prio=2 tid=0x0000000018ca3800 nid=0x3160 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE


"C2 CompilerThread1" #8 daemon prio=9 os_prio=2 tid=0x0000000018c43000 nid=0x2f8c waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE


"C2 CompilerThread0" #7 daemon prio=9 os_prio=2 tid=0x0000000018c42000 nid=0x31e0 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE


"Monitor Ctrl-Break" #6 daemon prio=5 os_prio=0 tid=0x0000000018c41000 nid=0x319c runnable [0x00000000192de000]
   java.lang.Thread.State: RUNNABLE
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.read(SocketInputStream.java:150)
        at java.net.SocketInputStream.read(SocketInputStream.java:121)
        at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:284)
        at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:326)
        at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:178)
        - locked <0x00000000d6e6fc90> (a java.io.InputStreamReader)
        at java.io.InputStreamReader.read(InputStreamReader.java:184)
        at java.io.BufferedReader.fill(BufferedReader.java:161)
        at java.io.BufferedReader.readLine(BufferedReader.java:324)
        - locked <0x00000000d6e6fc90> (a java.io.InputStreamReader)
        at java.io.BufferedReader.readLine(BufferedReader.java:389)
        at com.intellij.rt.execution.application.AppMainV2$1.run(AppMainV2.java:64)


"Attach Listener" #5 daemon prio=5 os_prio=2 tid=0x0000000018c22800 nid=0x3178 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE


"Signal Dispatcher" #4 daemon prio=9 os_prio=2 tid=0x0000000017885000 nid=0x3198 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE


"Finalizer" #3 daemon prio=8 os_prio=1 tid=0x0000000000c30000 nid=0x31d4 in Object.wait() [0x0000000018bde000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x00000000d6e80ba8> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:142)
        - locked <0x00000000d6e80ba8> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:158)
        at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)


"Reference Handler" #2 daemon prio=10 os_prio=2 tid=0x0000000017837800 nid=0x31d0 in Object.wait() [0x0000000018ade000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x00000000d6e80d60> (a java.lang.ref.Reference$Lock)
        at java.lang.Object.wait(Object.java:502)
        at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:157)
        - locked <0x00000000d6e80d60> (a java.lang.ref.Reference$Lock)


"main" #1 prio=5 os_prio=0 tid=0x0000000000b42800 nid=0x2db4 waiting on condition [0x0000000002e6f000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
        at java.lang.Thread.sleep(Native Method)
        at com.binga.jvm.jvmtools.DeadLockTest.main(DeadLockTest.java:21)


"VM Thread" os_prio=2 tid=0x0000000017836800 nid=0x3188 runnable


"GC task thread#0 (ParallelGC)" os_prio=0 tid=0x0000000000b58000 nid=0x31c8 runnable


"GC task thread#1 (ParallelGC)" os_prio=0 tid=0x0000000000b59800 nid=0x2dbc runnable


"GC task thread#2 (ParallelGC)" os_prio=0 tid=0x0000000000b5b000 nid=0x31cc runnable


"GC task thread#3 (ParallelGC)" os_prio=0 tid=0x0000000000b5c800 nid=0x3180 runnable


"VM Periodic Task Thread" os_prio=2 tid=0x0000000018ca9800 nid=0xd54 waiting on condition


JNI global references: 34




Found one Java-level deadlock:
=============================
"t2":
  waiting to lock monitor 0x0000000000c39738 (object 0x00000000d6e5d3f0, a java.lang.Object),
  which is held by "t1"
"t1":
  waiting to lock monitor 0x0000000000c39688 (object 0x00000000d6e5d400, a java.lang.Object),
  which is held by "t2"


Java stack information for the threads listed above:
===================================================
"t2":
        at com.binga.jvm.jvmtools.DeadLockTest$Task2.run(DeadLockTest.java:54)
        - waiting to lock <0x00000000d6e5d3f0> (a java.lang.Object)
        - locked <0x00000000d6e5d400> (a java.lang.Object)
        at java.lang.Thread.run(Thread.java:745)
"t1":
        at com.binga.jvm.jvmtools.DeadLockTest$Task1.run(DeadLockTest.java:36)
        - waiting to lock <0x00000000d6e5d400> (a java.lang.Object)
        - locked <0x00000000d6e5d3f0> (a java.lang.Object)
        at java.lang.Thread.run(Thread.java:745)


Found 1 deadlock.

可以看到在打印的栈信息最后面,显示了一个死锁信息:

Found one Java-level deadlock:
=============================
"t2":
  waiting to lock monitor 0x0000000000c39738 (object 0x00000000d6e5d3f0, a java.lang.Object),
  which is held by "t1"
"t1":
  waiting to lock monitor 0x0000000000c39688 (object 0x00000000d6e5d400, a java.lang.Object),
  which is held by "t2"

该信息分别显示了t1和t2分别等待的锁,而t1和t2等待的锁分别又被对方所持有,所以形成了死锁。同时在下方罗列出了对象代码的位置:

Java stack information for the threads listed above:
===================================================
"t2":
        at com.binga.jvm.jvmtools.DeadLockTest$Task2.run(DeadLockTest.java:54)
        - waiting to lock <0x00000000d6e5d3f0> (a java.lang.Object)
        - locked <0x00000000d6e5d400> (a java.lang.Object)
        at java.lang.Thread.run(Thread.java:745)
"t1":
        at com.binga.jvm.jvmtools.DeadLockTest$Task1.run(DeadLockTest.java:36)
        - waiting to lock <0x00000000d6e5d400> (a java.lang.Object)
        - locked <0x00000000d6e5d3f0> (a java.lang.Object)
        at java.lang.Thread.run(Thread.java:745)

Found 1 deadlock.



使用jstack找出占用cpu最高的线程

使用Linux服务器时:

  1. 使用命令top -p ,显示你的java进程的内存情况,pid是你的java 进程号,比如4977 。
  2. 按H,获取每个线程的内存情况。
  3. 找到内存和cpu占用最高的线程tid,比如4977。
  4. 转为十六进制得到 0x1371 ,此为线程id的十六进制表示。
  5. 执行 jstack 4977|grep -A 10 1371,得到线程堆栈信息中1371这个线程所在行的后面10行查看对应的堆栈信息找出可能存在问题的代码位置。



jstack展示的线程状态

线程的堆栈dump中线程有以下几种状态:

  • RUNNABLE,线程处于执行中
  • BLOCKED,线程被阻塞
  • WAITING,线程正在等待
  • TIMED_WAITING 等待指定时间

示例1:多线程竞争sychronized锁,如下:

/**
 * @Description: jstack 线程状态测试
 * @Author: binga
 * @Date: 2020/9/15 14:44
 * @Blog: https://blog.csdn.net/pang5356
 */
public class JstackToolTest1 {

    public static final Object LOCK = new Object();

    public static void main(String[] args) throws InterruptedException {
        Thread t1 = new Thread(new Task(), "t1");
        Thread t2 = new Thread(new Task(), "t2");

        t1.start();
        t2.start();

        Thread.sleep(Integer.MAX_VALUE);
    }

    static class Task implements Runnable {

        @Override
        public void run() {
            synchronized (LOCK) {
                calculate();
            }
        }

        public void calculate() {
            int count = 0;
            while(true) {
                count++;
            }
        }
    }
}

这里只展示线程t1和t2的线程堆栈信息:

"t2" #12 prio=5 os_prio=0 tid=0x00000000192c1800 nid=0x5b8 runnable [0x0000000019f2f000]
   java.lang.Thread.State: RUNNABLE
        at com.binga.jvm.jvmtools.JstackToolTest1$Task.calculate(JstackToolTest1.java:35)
        at com.binga.jvm.jvmtools.JstackToolTest1$Task.run(JstackToolTest1.java:28)
        - locked <0x00000000d6e72930> (a java.lang.Object)
        at java.lang.Thread.run(Thread.java:745)


"t1" #11 prio=5 os_prio=0 tid=0x00000000192c0800 nid=0x31e4 waiting for monitor entry [0x0000000019e2f000]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at com.binga.jvm.jvmtools.JstackToolTest1$Task.run(JstackToolTest1.java:28)
        - waiting to lock <0x00000000d6e72930> (a java.lang.Object)
        at java.lang.Thread.run(Thread.java:745)

从上面的打印信息可以知道线程t2是- locked <0x00000000d6e72930> (a java.lang.Object),所以t1是在对象0x00000000d6e72930加锁,而t1则是在等待0x00000000d6e72930的锁,- waiting to lock <0x00000000d6e72930> (a java.lang.Object),此时t2的状态为RUNNABLE,而t1的状态则为BLOCKED。

示例2:通过wait挂起线程,再来看通过wait方法将线程挂起是什么状态,代码如下:

/**
 * @Description: jstack线程状态测试
 * @Author: binga
 * @Date: 2020/9/15 16:51
 * @Blog: https://blog.csdn.net/pang5356
 */
public class JstackToolTest2 {

    public static final Object LOCK = new Object();

    public static void main(String[] args) throws InterruptedException {
        Thread t1 = new Thread(new Task(), "t1");
        Thread t2 = new Thread(new Task(), "t2");

        t1.start();
        t2.start();

        Thread.sleep(Integer.MAX_VALUE);

    }

    static class Task implements Runnable {

        @Override
        public void run() {
            synchronized (LOCK) {
                try {
                    LOCK.wait();
                } catch (InterruptedException e) {
                    e.printStackTrace();
                }
            }
        }
    }
}

输出的线程堆栈信息如下,这里只展示线程t1和t2的堆栈信息:

"t2" #12 prio=5 os_prio=0 tid=0x0000000019630000 nid=0x1310 in Object.wait() [0x000000001a2bf000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x00000000d6e56678> (a java.lang.Object)
        at java.lang.Object.wait(Object.java:502)
        at com.binga.jvm.jvmtools.JstackToolTest2$Task.run(JstackToolTest2.java:30)
        - locked <0x00000000d6e56678> (a java.lang.Object)
        at java.lang.Thread.run(Thread.java:745)


"t1" #11 prio=5 os_prio=0 tid=0x000000001962f800 nid=0x31b8 in Object.wait() [0x000000001a1bf000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x00000000d6e56678> (a java.lang.Object)
        at java.lang.Object.wait(Object.java:502)
        at com.binga.jvm.jvmtools.JstackToolTest2$Task.run(JstackToolTest2.java:30)
        - locked <0x00000000d6e56678> (a java.lang.Object)
        at java.lang.Thread.run(Thread.java:745)

通过打印信息可以看到两个线程的状态均为WAITING,并且均在等待对象0x00000000d6e56678上的锁,如下:

- waiting on <0x00000000d6e56678> (a java.lang.Object)

当然对于TIMED_WAITING的状态则是在使用sleep方法时可以查看其状态,如main线程在最终调用了sleep方法,其状态为:

"main" #1 prio=5 os_prio=0 tid=0x0000000003702800 nid=0x19b4 waiting on condition [0x00000000036ff000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
        at java.lang.Thread.sleep(Native Method)
        at com.binga.jvm.jvmtools.JstackToolTest2.main(JstackToolTest2.java:20)



JVM运行情况评估

用 jstat -gc pid 命令可以计算出垃圾收集频率的关键数据,有了这些数据就可以通过以下手段进行优化:

先给自己的系统设置一些初始性的JVM参数,比如堆内存大小,年轻代大小,Eden和Survivor的比例,老年代的大小,大对象的阈值,大龄对象进入老年代的阈值等。


年轻代对象增长的速率


可以执行命令 jstat -gc 1000 10 (每隔1秒执行1次命令,共执行10次),通过观察EU(eden区的使用)来估算每秒eden大概新增多少对象,如果系统负载不高,可以把频率1秒换成1分钟,甚至10分钟来观察整体情况。注意,一般系统可能有高峰期和日常期,所以需要在不同的时间分别估算不同情况下对象增长速率。


Young GC的触发频率和每次耗时


知道年轻代对象增长速率我们就能推根据Eden区的大小推算出Young GC大概多久触发一次,Young GC的平均耗时可以通过 YGCT/YGC公式算出,根据结果我们大概就能知道系统大概多久会因为Young GC的执行而卡顿多久。

每次Young GC后有多少对象存活和进入老年代这个因为之前已经大概知道Young GC的频率,假设是每5分钟一次,那么可以执行命令 jstat -gc 300000 10 ,观察每次结果Eden,Survivor和老年代使用的变化情况,在每次GC后Eden区使用一般会大幅减少,Survivor和老年代都有可能增长,这些增长的对象就是每次 Young GC后存活的对象,同时还可以看出每次Young GC后进去老年代大概多少对象,从而可以推算出老年代对象增长速率。


Full GC的触发频率和每次耗时


知道了老年代对象的增长速率就可以推算出Full GC的触发频率了,Full GC的每次耗时可以用公式 FGCT/FGC 计算得出。

优化思路其实简单来说就是尽量让每次Young GC后的存活对象小于Survivor区域的50%,都留存在年轻代里。尽量别让对象进入老年 代。尽量减少Full GC的频率,避免频繁Full GC对JVM性能的影响。



版权声明:本文为pang5356原创文章,遵循 CC 4.0 BY-SA 版权协议,转载请附上原文出处链接和本声明。