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