Threads
在 Threads 页面可以提供详细的线程信息,点击右上角的“Thread Dump”按钮,可以导出当前所有线程的堆栈信息(相当于 jstack)。
如果 VisualVM 在当前程序中找到死锁,则会在该页面很显眼地做出提示,如下图所示:
Sampler
在 “Sampler”页面下,有两个采样器,分别代表 CPU 和内存这两个性能采样器,用于实时监控程序信息。CPU 采样器可以将 CPU 占用时间定位到方法,内存采样器可以查看当前程序的堆信息。
这里我们以上面用到的死锁代码作为测试案例。
public class SyncDeadLock { private static Object objectA = new Object(); private static Object objectB = new Object(); public static void main(String[] args) { new SyncDeadLock().deadLock(); } private void deadLock() { Thread thread1 = new Thread(new Runnable() { @Override public void run() { synchronized (objectA) { try { System.out.println(Thread.currentThread().getName() + " get objectA ing!"); Thread.sleep(500); } catch (Exception e) { e.printStackTrace(); } System.out.println(Thread.currentThread().getName() + " need objectB! Just waiting!"); synchronized (objectB) { System.out.println(Thread.currentThread().getName() + " get objectB ing!"); } } } }, "thread1"); Thread thread2 = new Thread(() -> { synchronized (objectB) { try { System.out.println(Thread.currentThread().getName() + " get objectB ing!"); Thread.sleep(500); } catch (Exception e) { e.printStackTrace(); } System.out.println(Thread.currentThread().getName() + " need objectA! Just waiting!"); synchronized (objectA) { System.out.println(Thread.currentThread().getName() + " get objectA ing!"); } } }, "thread2"); thread1.start(); thread2.start(); } } 复制代码
启动程序,然后进入“Sampler”页面,点击”CPU“按钮,得到如下内容:
上面出现的 Monitor Ctrl-Break,大家可能不明白是个什么东西。这里简单提一下,这个线程是在 IDEA 中才有的,而且还是用 run 启动方式才会出现,如果是 debug 启动方式,则不会出现。
比如在上面 main 方法中增加如下代码:
ThreadGroup currentGroup = Thread.currentThread().getThreadGroup(); int noThreads = currentGroup.activeCount(); Thread[] lstThreads = new Thread[noThreads]; currentGroup.enumerate(lstThreads); for (int i = 0; i < noThreads; i++) { System.out.println("线程号:" + i + " = " + lstThreads[i].getName()); } 复制代码
控制台会输出如下内容:
线程号:0 = main 线程号:1 = Monitor Ctrl-Break 线程号:2 = thread1 线程号:3 = thread2 复制代码
我们接着对上图内容进行分析,可以发现 SyncDeadLock.run() 方法占用了大量的 CPU 时间,那么就可以定位到对应的代码,并加以改进。
接着来使用内存采样器,可以实时查看系统中实例的分布情况。
Profiler
在 Profiler 页签中,VisualVM 提供了程序运行期间方法级的处理器执行时间分析以及内存分析。做 Profiling 分析肯定会对程序运行性能有比较大的影响,所以一般不在生产环境使用这项功能,或者改用 JMC 来完成,JMC 的 Profiling 能力更强,对应用的影响非常轻微。
这里有四个选择:CPU、Memory、JDBC、Locks,不过在实际测试过程中,点击发现没有什么反应,本地控制台报错“Profiler Agent Warning: JVMTI classLoadHook: class name is null.“,也没找到解决方案。
市面上还有一款叫做 JProfiler 的分析工具,比 VirtualVM 要更详细,更专业,基本上覆盖了 VirtualVM 的功能点,还有一些更细致的功能,精确到代码某一行,不过是个收费软件,以后有机会用得到再研究一下。
Visual GC
JVisualVM 工具的 “VisualGC” 插件提供了基本的 JMX客户端功能, 还实时显示出 GC事件以及各个内存空间的使用情况。
Visual GC 插件常用来监控本机运行的Java程序, 比如开发者和性能调优专家经常会使用此插件, 以快速获取程序运行时的GC信息。
关于 Visual GC 插件的使用推荐阅读:Visual GC 插件使用 ,文章还介绍了 Spaces、Graphs 和 Histogram 这三块区域的含义。
首先我们看一下程序结束后在 Visual GC 的展示图:
根据上图可知:
- 我们设置的堆空间大小为 60M,Eden 和老年代的内存大小按照 1:2 的比例进行分配;
- Compile Time:编译情况
748 compoles - 853.953ms
表示编译总数为 748,编译总耗时为 853.953ms。 一个脉冲表示一次 JIT 编译,脉冲越宽表示编译时间越长。
- Class Loader Time:类加载情况
1621 loaded,51 unloaded - 225.812ms
表示已加载的数量为 1621,卸载的数量为 51,耗时为 225.812ms。 - GC Time:总的(包含新生代和老年代)gc情况记录
52 collections,1.916s Last Cause:Allocation Failure
表示一共经历了 52 次 GC(包含Minor GC和Full GC),总共耗时 1.916s。
- Eden Space:新生代 Eden 区内存使用情况
(19.000M,15.000M): 530.28K,4 collections,27.792ms
表示 Eden 区的最大容量为 19M,当前容量为 15M,当前已使用15M,从开始监控到现在在该内存区域一共发生了 4 次 gc(Minor GC),gc 总耗时为 27.792ms。
- Survivor 0和Survivor 1:新生代的两个Survivor区内存使用情况
(6.500M,2.500M):0M
表示该Survivor区的最大容量为 6.5M,当前已用 0M。
- Old Gen:老年代内存使用情况
(40.000M,40.000M):1.829M,48 collections,1.889s
表示老年区的最大容量为 40M,当前容量为 40 M,当前已用 1.829M,从开始监控到现在在该内存区域一共发生了 48 次gc(Full GC),gc 总耗时为 1.889s,换算下可以看出单次 Full GC 要比 Minor GC 耗时长很多。
- Metaspace:方法区内存使用情况
(1.008G,9.125M):8.473M
表示方法区最大容量为1.008G,当前容量为 9.125M,当前使用量为 8.473M。
下面我们展示一下程序运行过程的动图展示:
GCeasy
GCeasy 是一款在线的 GC日志分析器,可以通过GC日志分析进行内存泄漏检测、GC暂停原因分析、JVM 配置建议优化等功能,而且是可以免费使用的(有一些服务是收费的)。
将我们得到 gc log 文件上传上去,然后点击分析按钮,稍等片刻就会出结果。这里展示部分截图:
下述图片中,可以点击左侧按钮,显示不同的内容,比如说点击 Old Gen,
下面这张图就更加详细了,与 GCViewer 相比展示更加直观。
总结
本文介绍了三种工具来分析 GC 日志,以及通过日志关注哪些信息。当然文中的案例比较简单,实际应用肯定复杂的多,后续我会再找机会出一篇生产过程中 GC 日志分析的文章。