JVM第八周 常用命令jstat/jmap/jhat

402 阅读11分钟

jstat

平时我们对运行中的系统,如果要检查他的JVM的整体运行情况,比较实用的工具之一,就是jstat他可以轻易的让你看到当前运行中的系统,他的JVM内的Eden、Survivor、老年代的内存使用情况,还有Young GC和Full gC的执行次数以及耗时。

通过这些指标,我们可以轻松的分析出当前系统的运行情况,判断当前系统的内存使用压力以及GC压力,还有就是内存分配是否合理。下面我们就一点点来看看这个jstat工具的使用。

jstat -gc PID

可以看到Java进程的内存和GC情况。

S0C: From Survivor区的大小

S1C: To Survivor区的大小

S0U: From Survivor区 当前使用内存的大小

S1U: To Survivor区 当前使用内存的大小

EC: Eden区的大小

EU: Eden区当前使用内存的大小

OC: 老年代的大小

OU: 老年代当前使用内存的大小

MC: 方法区(永久代、元数据区)的大小

MU: 方法区(永久代、元数据区)当前使用内存的大小

YGC:系统运行迄今为止的Young GC次数

YGCT: Young GC 耗时

FGC:系统运行迄今为止的Full GC次数

FGCT: Full GC耗时

GCT: 所有GC的总耗时

怎么使用jstat

我们分析线上的JVM进程,最想要知道的信息有哪些?

包括如下:新生代对象增长的速率,Young GC的触发频率,Young GC的耗时,每次Young GC后有多少对象是存活下来的,每次Young GC过后有多少对象进入了老年代,老年代对象增长的速率,Full GC的触发频率,Full GC的耗时。

只要知道了这些信息,其实我们就可以合理分配内存空间,尽可能让对象留在年轻代不进入老年代,避免发生频繁的Full GC。这就是对JVM最好的性能优化了!

新生代对象增长的速率

jstat -gc PID 1000 10

每隔1秒钟(1000ms)打印一次最新的jstat统计信息,一共执行10次统计

观察Eden区对象占用空间变化,EU信息。

这样就可以得出结论,这个Java系统每隔1秒钟产生多少MB的对象

一般系统都有高峰和日常两种状态,比如系统高峰期用的人很多,此时你就应该在系统高峰期去用上述命令看看高峰期的对象增长速率。然后你再得在非高峰的日常时间段内看看对象的增长速率。

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

其实多久触发一次Young GC就很容易推测出来了,因为系统高峰和日常时候的对象增长速率你都知道了,那么非常简单就可以推测出来高峰期多久发生一次Young GC,日常期多久发生一次Young GC。

比如你Eden区有800MB内存,那么发现高峰期每秒新增5MB对象,大概高峰期就是3分钟会触发一次Young GC。日常期每秒新增0.5MB对象,那么日常期大概需要半个小时才会触发一次Young GC。

每次Young GC的平均耗时,根据下面两个信息做除法计算

YGC:系统运行迄今为止的Young GC次数

YGCT: Young GC 耗时

每次Young GC后有多少对象进入老年代

假设之前我们已经推算出来高峰期的时候多久发生一次Young GC,比如3分钟会有一次Young GC

那么此时我们可以执行下述jstat命令:jstat-gc PID 180000 10。这就相当于是让他每隔三分钟执行一次统计,连续执行10次。

此时大家可以观察一下,每隔三分钟之后发生了一次Young GC,此时Eden、Survivor、老年代的对象变化

正常来说,Eden区肯定会在几乎放满之后重新变得里面对象很少,比如800MB的空间就使用了几十MB。Survivor区肯定会放入一些存活对象,老年代可能会增长一些对象占用。所以这里的关键,就是观察老年代的对象增长速率

从一个正常的角度来看,老年代的对象是不太可能不停的快速增长的,因为普通的系统其实没那么多长期存活的对象。如果你发现比如每次Young GC过后,老年代对象都要增长几十MB,那很有可能就是你一次Young GC过后存活对象太多了

存活对象太多,可能导致放入Survivor区域之后触发了动态年龄判定规则进入老年代,也可能是Survivor区域放不下了,所以大部分存活对象进入老年代。

最常见的就是这种情况。如果你的老年代每次在Young GC过后就新增几百KB,或者几MB的对象,这个还算情有可缘,但是如果老年代对象快速增长,那一定是不正常的。

所以通过上述观察策略,你就可以知道每次Young GC过后多少对象是存活的,实际上Survivor区域里的和进入老年代的对象,都是存活的。

你也可以知道老年代对象的增长速率,比如每隔3分钟一次Young GC,每次会有50MB对象进入老年代,这就是年代对象的增长速率,每隔3分钟增长50MB。

Full GC的触发时机和耗时

知道了老年代对象的增长速率,就很好估算 Full GC的触发频率了

比如老年代总共有800MB的内存,老年代每隔3分钟新增50MB对象,那么大概每小时就会触发一次Full GC。

然后可以看到stat打印出来的系统运行起劲为止的Full GC次数以及总耗时,比如一共执行了10次Full GC,共耗时305,每次Full GC大概就是需要耗费3s左右。

jmap和jhat

有的时候可能我们会发现JVM新增对象的速度很快,然后就想要去看看,到底什么对象占据了那么多的内存

如果发现有的对象在代码中可以优化一下创建的时机,避免那种对象对内存占用过大,那么也许甚至可以去反过来优化一下代码。

当然,其实如果不是出现OOM那种极端情况,也并没有那么大的必要去着急优化代码。

jmap -heap PID

Attaching to process ID 31597, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.261-b12

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

Heap Configuration:
   MinHeapFreeRatio         = 0
   MaxHeapFreeRatio         = 100
   MaxHeapSize              = 4181721088 (3988.0MB)
   NewSize                  = 87031808 (83.0MB)
   MaxNewSize               = 1393557504 (1329.0MB)
   OldSize                  = 175112192 (167.0MB)
   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 = 881328128 (840.5MB)
   used     = 648596808 (618.5501174926758MB)
   free     = 232731320 (221.94988250732422MB)
   73.59311332453014% used
From Space:
   capacity = 23592960 (22.5MB)
   used     = 23346592 (22.265045166015625MB)
   free     = 246368 (0.234954833984375MB)
   98.95575629340277% used
To Space:
   capacity = 85458944 (81.5MB)
   used     = 0 (0.0MB)
   free     = 85458944 (81.5MB)
   0.0% used
PS Old Generation
   capacity = 820510720 (782.5MB)
   used     = 495043352 (472.1101303100586MB)
   free     = 325467368 (310.3898696899414MB)
   60.33356297892123% used

使用jmap了解系统运行时的对象分布

jmap -histo PID

按照各种对象内存占用大小降序排列,内存占用最多的对象排在最上面

使用jmap生成堆内存转储快照

jmap -dump: live, format=b, file=dump. hprof PID

这个命令会在当前目录下生成一个dump.hrpof文件,这里是二进制的格式,你不能直接打开看的,他把这一时刻JVM堆内存里所有对象的快照放到文件里去了,供你后续去分析。

使用jhap在浏览器中分析堆内存转储快照

接着就可以使用jhat去分析堆快照了,jhat内置了web服务器,他会支持你通过浏览器来以图形化的方式分析堆转储快照。

使用如下命令即可启动jhat服务器,还可以指定自己想要的http端口号,默认是7000端口号: jhat -port 7000 dump.hprof

接着你就在浏览器上访问当前这台机器的7000端口号,就可以通过图形化的方式去分析堆内存里的对象分布情况了。

[root@i-0F626122 ~]# jhat -port 7000 dump.hprof 
Reading from dump.hprof...
Dump file created Wed Sep 08 15:48:17 CST 2021
Snapshot read, resolving...
Resolving 6850015 objects...
Chasing references, expect 1370 dots..........................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................
Eliminating duplicate references..........................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................
Snapshot resolved.
Started HTTP server on port 7000
Server is ready.

在服务器上执行命令: curl http://127.0.0.1:7000

实践

JVM参数配置

-XX:NewSize=104857600
-XX:MaxNewSize=104857600
-XX:InitialHeapSize=209715200
-XX:MaxHeapSize=209715200
-XX:PretenureSizeThreshold=20971520
-XX:SurvivorRatio=8
-XX:MaxTenuringThreshold=15
-XX:+UseParNewGC
-XX:+UseConcMarkSweepGC
-XX:+PrintGCDetails
-XX:+PrintGCTimeStamps
-Xloggc:gc.log

Eden 80M S0 SI: 10M 老年代 100MB ,大对象 阈值 20MB

java代码

public class Demo6 {

    // -XX:NewSize=104857600
    // -XX:MaxNewSize=104857600     100MB
    // -XX:InitialHeapSize=209715200   200MB
    // -XX:MaxHeapSize=209715200
    // -XX:PretenureSizeThreshold=20971520  20MB
    // -XX:SurvivorRatio=8    10MB
    // -XX:MaxTenuringThreshold=15
    // -XX:PretenureSizeThreshold=3145728
    // -XX:+UseParNewGC
    // -XX:+UseConcMarkSweepGC
    // -XX:+PrintGCDetails
    // -XX:+PrintGCTimeStamps
    // -Xloggc:gc.log
    public static void main(String[] args) throws Exception {
        Thread.sleep(40000);
        while (true) {
            loadData();
        }
    }

    private static void loadData() throws Exception {
        byte[] data = null;
        for (int i = 0; i < 4; i++) {
            // 10MB
            data = new byte[10 * 1024 * 1024];
        }
        data = null;

        byte[] data1 = new byte[10 * 1024 * 1024];
        byte[] data2 = new byte[10 * 1024 * 1024];

        byte[] data3 = new byte[10 * 1024 * 1024];
        data3 = new byte[10 * 1024 * 1024];

        Thread.sleep(1000);
    }
}

jstat执行结果

每秒会发生一次Young GC,都会导致20MB~30MB左右的对象进入老年代

因为每次Young GC都会存活下来这么多对象,但是Survivor区域是放不下的,所以都会直接进入老年代。

老年代的对象占用从30MB一路到60MB左右,此时突然在60MB之后下一秒,明显发生了一次Full GC,对老年代进行了垃圾回收,因为此时老年代重新变成30MB了。

很简单,老年代总共就100MB左右,已经占用了60MB了,此时如果发生一次Young GC,有30MB存活对象要放入老年代的话,你还要放30MB对象,明显老年代就要不够了,此时必须会进行Full GC,回收掉之前那60MB对象,然后再放入进去新的30MB对象。

按照我们的这段代码,几乎是每秒新增80MB左右,触发每秒1次Young GC,每次Young GC后存活下来20MB30MB的对象,**老年代每秒新增20MB30MB的对象,触发老年代几乎三秒一次Full GC**

问题:Young GC太频繁,而且每次GC后存活对象太多,频繁进入老年代,频繁触发老年代的GC。

GC耗时

左边Young GC 右边 Full GC

Young GC平均耗时比Full GC平均耗时还多

原因:每次Full GC都是由Young GC触发的,因为Young GC过后存活对象太多要放入老年代,老年代内存不够了触发Full GC,所以必须得等Full GC执行完毕了,Young GC才能把存活对象放入老年代,才算结束。这就导致Young GC也是速度非常慢。

JVM性能优化

我们只需要调大年轻代的内存空间,增加Survivor的内存即可,看如下JVM参数:

-XX:NewSize=209715200 -XX:MaxNewSize=209715200 -XX:InitialHeapSize=314572800 -XX:MaxHeapSize=314572800 -XX:SurvivorRatio=2  -XX:MaxTenuringThreshold=15 -XX:PretenureSizeThreshold=20971520 -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -Xloggc:gc.log

堆大小调大为了300MB,年轻代给了200MB,同时“-XX:SurvivorRatio=2”表明,Eden:Survivor:Survivor的比例为2:1:1,所以Eden区是100MB,每个Survivor区是50MB,老年代也是100MB。

每秒的Young GC过后,都会有20MB左右的存活对象进入Survivor,但是每个Survivor区都是50MB的大小,因此可以轻松容纳,而且一般不会过50%的动态年龄判定的阈值

每秒触发Yuong GC过后,几乎就没有对象会进入老年代,最终就600KB的对象进入了老年代里,其他就没有对象进入老年代了。

只有Young GC,没有Full GC

仅仅是调整了内存分配比例,立马就大幅度提升了JVM的性能,几乎把Full GC给消灭掉了。