当前位置：首页 > news >正文

【JVM】JVisualVM的介绍、使用和GC过程

news 文章来源：https://blog.csdn.net/Alex_81D/article/details/138606561 2024/11/1 3:24:19

VisualVM介绍

VisualVM 是Netbeans的profile子项目，已在JDK6.0 update 7 中自带，能够监控线程，内存情况，查看方法的CPU时间和内存中的对象，已被GC的对象，反向查看分配的堆栈(如100个String对象分别由哪几个对象分配出来的)。在JDK_HOME/bin(默认是C:\Program Files\Java\jdk1.6.0_13\bin)目录下面，有一个jvisualvm.exe文件，双击打开，从UI上来看，这个软件是基于NetBeans开发的了。

VisualVM 提供了一个可视界面，用于查看 Java 虚拟机 (Java Virtual Machine, JVM) 上运行的基于 Java 技术的应用程序的详细信息。VisualVM 对 Java Development Kit (JDK) 工具所检索的 JVM 软件相关数据进行组织，并通过一种使您可以快速查看有关多个 Java 应用程序的数据的方式提供该信息。您可以查看本地应用程序或远程主机上运行的应用程序的相关数据。此外，还可以捕获有关 JVM 软件实例的数据，并将该数据保存到本地系统，以供后期查看或与其他用户共享。

在cmd中执行 jvisualvm

Visual GC插件

本来使用这个是看GC的，结果发现没有Visual GC选项插件，接下来说一下怎么安装

安装 Visual GC插件

流程：
点击上方【工具】–【插件】–【可用插件】

选中需要的插件，然后点击安装，安装完成后，重启jvisualvm即可。

但是肯定有的小伙伴可用插件是空的，下面就是解决【可用插件】中为空的情况。
步骤1：

找到新的插件地址
打开这个地址: VisualVM: Home
选中上方的Plugins

步骤2：
更换插件地址
将步骤1中复制出来的地址放进去。

如果更换了还是在【可用插件】中刷不出来，那么可以尝试多添加几个地址。

最后多刷新，多尝试几遍。就可以在【可用插件】中找到了，然后勾选，安装，重启即可。

测试

工具测试如下图

测试代码

import java.util.ArrayList;public class JVMTest {//100KBbyte[] b = new byte[1024*100];public static void main(String[] args) throws InterruptedException {ArrayList<JVMTest> heapTests = new ArrayList<>();while(true){heapTests.add(new JVMTest());Thread.sleep(50);//System.out.println("执行中....");}}
}

整个区域划分为三个部分，分别为 spaces、graphs、histogram

spaces 区域

代表虚拟机内存分布情况，从图中可以看出，虚拟机被分为 Perm、Old、Eden、S0、S1

Perm

英文名叫做 Permanent Generation，我们称之为永久代，Java 8 之后称为元空间

通过 VM Args:-XX:PermSize=128m -XX:MaxPermSize=256m 设置初始值与最大值

Heap

Java 堆（Java Heap）。它包括老年代（对应图中的 Old 区域）和新生代（对应图中的 Eden、S0、S1 三个统称为新生代，分为 Eden 区和两个 Survivor 区域），它们默认是 8:1:1 分配内存

通过 VM Args:-xms512m -Xmx512m -XX:+HeapDumpOnOutofMemoryError -XX:SurvivorRatio=8 设置初始堆内存、最大内存、内存异常打印 dump、新生代内存、新生代内存分配比例（8:1:1），因为 Heap 分为新生代和老年代，所以 512M - 100M = 412M，老年代就是 412M（初始内存跟最大内存最好相等，防止内存不够时扩充内存或者 Full GC，导致性能下降）

Graphs 区域

Compile Time（编译时间）

图中 996 compiles 表示编译总数，1.413 s 表示编译累计时间。一个脉冲表示一次 JIT 编译，窄脉冲表示持续时间短，宽脉冲表示持续时间长

Class Loader Time（类加载时间）

图中 1675 loaded 表示加载类数量，42 unloaded 表示卸载的数量，905.329ms 表示类加载花费的时间

GC Time

图中 5 collections 表示垃圾收集的总次数，468.449 ms 表示垃圾收集花费的时间，last cause 表示最近垃圾收集的原因

Eden Space（Eden 区）

图中括号内的 315.500 M 表示最大容量，15.000M 表示当前容量，后面的 9.873 M 表示当前使用情况， 1 collections 表示垃圾收集次数，4.732 ms 表示垃圾收集花费时间

Survivor 0 / Survivor 1（S0 和 S1 区）

图中括号内的 105.500 M 表示最大容量，2.500 M 表示当前容量，之后的 0 值是当前使用情况

Old Gen（老年代）

图中括号内的 633.500 M 表示最大容量，633.500 M 表示当前容量，后面的 632.474 M 表示当前使用情况，4 collections 表示垃圾收集次数，463.717 ms 表示垃圾收集花费时间

Metaspace（元空间）

图中括号内的 1.008 G 表示最大容量，9.750 M 表示当前容量，8.973 M 表示当前使用情况

配置jvm参数如下：

         -Xms512m-Xmx512m-XX:-UseGCOverheadLimit-XX:MaxPermSize=50m

Jvisualvm查看GC流程

老年代

这些位于老年代的经典对象有：数据库连接池、静态变量有很多，只要程序一直运行，一直有指针指向他，他就是属于老不死的对象

测试查看GC过程

这个字节数组占用的内存是100KB，也就是这个对象一旦new出来，至少占内存空间是大于100KB的
下面代码不断创建对象，放到list中，这个程序一直执行，会产生大量新的对象，同时是被list指向的，是有用的，是不会被minorGC回收掉的，程序不断执行，最终将会导致内存溢出

使用jvisualvm（jdk自带的命令）监控，cmd窗口直接执行jvisualvm命令，将启动该程序，Jvisualvm会自动寻找本机的所有java进程

启动刚才的程序heapTest

新new出来的对象位于eden区域，所以eden区域一直在增长，一开始是0的，随着程序的运行，慢慢的增长，然后降到最低然后又增长

增长到峰值的时候，伊甸园区满了，就会马上做一次GC，就会在GC时间图上打印一条峰值标识，然后就会马上把伊甸园区的内存释放掉，这时候伊甸园区又回到初始位置

同时把一部分有用的对象挪移到survivor0区域，当survivor0区域满了以后，又会进行一次GC，清理无效对象，剩余有效对象一次全部挪移到survivor1区域，然后反复，可以看到是交叉的

可以看到old区是一会平稳然后突然内存占用上一个台阶，继续平稳，
这部分平稳的区域正好是survivor区经历了15次minor GC，他才可能突然把一堆对象加到old区

元空间即方法区的内存在程序运行的时候是不动的，但是在程序刚开始运行，加载程序的时候，他的内存是一下增长到最高点的，因为在加载类

Old区放满以后会出现什么事情？
答案：程序已经奔溃了，oom：heap space
原因：当old区满以后，底层会触发Full GC，将会对老年代的垃圾进行收集，但是当他收集的时候发现，老年代里面的对象都是有用的，那么GC不会释放任何东西，这样，再往老年代放东西，就会出现空间不够用的情况，即OOM

虚拟机调优初步

一般用的垃圾收集器是G1收集器，每秒几十万并发的系统会频繁发生Full GC

Java虚拟机调优的目的是什么？

Full gc是一个非常慢的过程，java虚拟机在执行full GC的时候，很多情况下会出现
Stop the world，即停掉我们应用程序（应用线程）的执行，即会让我们应用程序卡住，影响我们程序的执行

因此，java虚拟机调优的目的是为了减少Full GC的次数，出现的越少越好
同时，减少一次Full GC的时间，因为full GC的时间越长，stop the world的时间就越长，应用程序卡死的时间就越长

怎么调优？
通过观察他的调优日志

如果为idea，通过如下方式配置打印GC日志

-XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -Xloggc:./gc.log

Java HotSpot(TM) 64-Bit Server VM (25.171-b11) for windows-amd64 JRE (1.8.0_171-b11), built on Mar 28 2018 16:06:12 by "java_re" with MS VC++ 10.0 (VS2010)
Memory: 4k page, physical 8263504k(2346828k free), swap 16652112k(6491288k free)
CommandLine flags: -XX:InitialHeapSize=132216064 -XX:MaxHeapSize=2115457024 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:-UseLargePagesIndividualAllocation -XX:+UseParallelGC 
2019-10-15T10:27:29.145+0800: 14.641: [GC (Allocation Failure) [PSYoungGen: 33211K->5116K(38400K)] 33211K->28718K(125952K), 0.0187916 secs] [Times: user=0.02 sys=0.05, real=0.02 secs] 
2019-10-15T10:27:45.962+0800: 31.456: [GC (Allocation Failure) [PSYoungGen: 38339K->5084K(38400K)] 61941K->61199K(125952K), 0.0184338 secs] [Times: user=0.00 sys=0.02, real=0.02 secs] 
2019-10-15T10:27:45.979+0800: 31.475: [Full GC (Ergonomics) [PSYoungGen: 5084K->0K(38400K)] [ParOldGen: 56115K->60903K(129024K)] 61199K->60903K(167424K), [Metaspace: 3964K->3964K(1056768K)], 0.0167096 secs] [Times: user=0.03 sys=0.00, real=0.02 secs] 
2019-10-15T10:28:02.924+0800: 48.419: [GC (Allocation Failure) [PSYoungGen: 33189K->5028K(38400K)] 94093K->93836K(167424K), 0.0237348 secs] [Times: user=0.02 sys=0.11, real=0.02 secs] 
2019-10-15T10:28:20.109+0800: 65.604: [GC (Allocation Failure) [PSYoungGen: 38283K->5096K(38400K)] 127091K->127017K(167424K), 0.0119623 secs] [Times: user=0.03 sys=0.02, real=0.01 secs] 
2019-10-15T10:28:20.121+0800: 65.616: [Full GC (Ergonomics) [PSYoungGen: 5096K->0K(38400K)] [ParOldGen: 121920K->126915K(196096K)] 127017K->126915K(234496K), [Metaspace: 3964K->3964K(1056768K)], 0.0333172 secs] [Times: user=0.06 sys=0.00, real=0.03 secs] 
2019-10-15T10:28:37.102+0800: 82.597: [GC (Allocation Failure) [PSYoungGen: 33260K->5028K(37888K)] 160175K->160248K(233984K), 0.0248040 secs] [Times: user=0.03 sys=0.03, real=0.03 secs] 
2019-10-15T10:28:53.840+0800: 99.335: [GC (Allocation Failure) [PSYoungGen: 37777K->37733K(72192K)] 192997K->192953K(268288K), 0.0377579 secs] [Times: user=0.01 sys=0.01, real=0.04 secs] 
2019-10-15T10:29:06.706+0800: 112.201: [GC (Allocation Failure) [PSYoungGen: 63333K->53736K(78848K)] 218553K->218157K(274944K), 0.0216211 secs] [Times: user=0.08 sys=0.05, real=0.02 secs] 
2019-10-15T10:29:06.727+0800: 112.223: [Full GC (Ergonomics) [PSYoungGen: 53736K->22503K(78848K)] [ParOldGen: 164421K->195543K(261120K)] 218157K->218047K(339968K), [Metaspace: 3964K->3964K(1056768K)], 0.0354184 secs] [Times: user=0.05 sys=0.02, real=0.04 secs] 
2019-10-15T10:29:19.435+0800: 124.930: [GC (Allocation Failure) [PSYoungGen: 47505K->47535K(86016K)] 243049K->243079K(347136K), 0.0192741 secs] [Times: user=0.05 sys=0.00, real=0.02 secs] 
2019-10-15T10:29:29.547+0800: 135.041: [GC (Allocation Failure) [PSYoungGen: 67433K->50535K(91136K)] 262976K->262882K(352256K), 0.0232305 secs] [Times: user=0.05 sys=0.03, real=0.02 secs] 
2019-10-15T10:29:39.623+0800: 145.118: [GC (Allocation Failure) [PSYoungGen: 70435K->39750K(93696K)] 282781K->282733K(354816K), 0.0192353 secs] [Times: user=0.05 sys=0.00, real=0.02 secs] 
2019-10-15T10:29:39.642+0800: 145.137: [Full GC (Ergonomics) [PSYoungGen: 39750K->21803K(93696K)] [ParOldGen: 242983K->260769K(325632K)] 282733K->282572K(419328K), [Metaspace: 3964K->3964K(1056768K)], 0.0280720 secs] [Times: user=0.06 sys=0.00, real=0.03 secs] 
2019-10-15T10:29:49.799+0800: 155.294: [GC (Allocation Failure) [PSYoungGen: 41703K->19867K(39936K)] 302472K->302440K(365568K), 0.0166059 secs] [Times: user=0.03 sys=0.02, real=0.02 secs] 
2019-10-15T10:30:00.007+0800: 165.502: [GC (Allocation Failure) [PSYoungGen: 39765K->19867K(87040K)] 322337K->322267K(412672K), 0.0201685 secs] [Times: user=0.00 sys=0.03, real=0.02 secs] 
2019-10-15T10:30:00.027+0800: 165.522: [Full GC (Ergonomics) [PSYoungGen: 19867K->0K(87040K)] [ParOldGen: 302400K->322185K(385024K)] 322267K->322185K(472064K), [Metaspace: 3964K->3964K(1056768K)], 0.0175613 secs] [Times: user=0.03 sys=0.03, real=0.02 secs] 
HeapPSYoungGen      total 87040K, used 6995K [0x00000000d5f80000, 0x00000000dfb00000, 0x0000000100000000)eden space 19968K, 35% used [0x00000000d5f80000,0x00000000d6654c80,0x00000000d7300000)from space 67072K, 0% used [0x00000000db980000,0x00000000db980000,0x00000000dfb00000)to   space 69632K, 0% used [0x00000000d7300000,0x00000000d7300000,0x00000000db700000)ParOldGen       total 385024K, used 322185K [0x0000000081e00000, 0x0000000099600000, 0x00000000d5f80000)object space 385024K, 83% used [0x0000000081e00000,0x00000000958a2570,0x0000000099600000)Metaspace       used 3970K, capacity 4628K, committed 4864K, reserved 1056768Kclass space    used 435K, capacity 464K, committed 512K, reserved 1048576K

底层没有做GC的时候，任何日志是没有的，只有当底层做了GC才会有这个日志，通过这个日志就可以知道我们的应用程序执行GC的频率以及为什么会去做GC？

可以看到我们的heaptest测试的时候频繁发生FullGC，因为list添加的对象都是有用的对象，old区满就会出现Full GC
一般不用管minor GC，因为速度很快，主要侧重点在于Full GC

https://www.jianshu.com/p/73563cae3bde

https://blog.csdn.net/Woo_home/article/details/107247525

https://blog.csdn.net/Renren151/article/details/126454097