Arthas&GC日志&GCeasy详解

Arthas详解

Arthas是阿里巴巴在2018年9月开源的Java诊断工具,支持JDK6+,采用命令行交互模式,可以方便定位和诊断线上程序运行问题.Arthas官方文档十分详细.详见:官方文档

Arthas使用场景

Arthas使用

# github下载arthas
wget https://alibaba.github.io/arthas/arthas-boot.jar
# 或者 Gitee 下载
wget https://arthas.gitee.io/arthas-boot.jar

运行以下代码

package com.fanqiechaodan;

import java.util.HashSet;

/**
 * @author fanqiechaodan
 * @Classname ArthasDemo
 * @Description
 */
public class ArthasDemo {

    private static HashSet<String> HASH_SET = new HashSet<>();

    public static void main(String[] args) {
        // 模拟CPU过高
        cpuHigh();
        // 模拟线程死锁
        deadThread();
        // 不断的向HashSet增加数据
        addHashSetThread();
    }

    private static void addHashSetThread() {
        new Thread(()->{
            int count = 0;
            while (true){
                try {
                    HASH_SET.add("count:"+count);
                    Thread.sleep(1000);
                    count++;
                } catch (InterruptedException e) {
                    e.printStackTrace();
                }
            }
        }).start();
    }

    private static void deadThread() {
        Object lock1 = new Object();
        Object lock2 = new Object();
        new Thread(()->{
            synchronized (lock1){
                try {
                    System.out.println("thread1 start");
                    Thread.sleep(5000);
                } catch (InterruptedException e) {
                    e.printStackTrace();
                }
                synchronized (lock2){
                    System.out.println("thread1 end");
                }
            }
        }).start();

        new Thread(()->{
            synchronized (lock2){
                try {
                    System.out.println("thread2 start");
                    Thread.sleep(5000);
                } catch (InterruptedException e) {
                    e.printStackTrace();
                }
                synchronized (lock1){
                    System.out.println("thread2 end");
                }
            }
        }).start();
    }

    private static void cpuHigh() {
        new Thread(()->{
            while (true){

            }
        }).start();
    }
}

运行Arthas

java -jar arthas-boot.jar

选择进程序号1,进入进程信息操作

输入dashboard可以查看整个进程的运行情况,线程,内存,GC,运行环境等信息:

输入thread可以查看线程详细情况

输入thread加上线程ID可以查看线程堆栈

输入thread -b可以查看线程死锁

输入jad加类的全名,可以反编译,这样可以方便我们查看线上代码是否是正确的版本

输入ognl查看静态字段的值

ongl还可以修改静态变量

更多命令可以用help命令查看,或者查看文档

GC日志详解

对于Java应用我们可以通过一些配置把程序运行过程中的GC日志全部打印出来,然后分析GC日志得到关键性指标,分析GC原因,调优JVM参数.

ParallelGC

打印GC日志方法,在JVM参数里增加参数,%t代表时间

-Xloggc:./GC-%t.log -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCTimeStamps -XX:+PrintGCCause -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=100M -XX:+UseParallelGC -Xmx2048m -Xms2048m

Tomcat则直接加在JAVA_OPTS变量里.

CommandLine flags是项目的配置参数,这里不仅配置了打印GC日志,还有相关的JVM参数.

2024-05-06T20:17:01.133+0800: 9.079: [Full GC (Metadata GC Threshold) [PSYoungGen: 17029K->0K(611840K)] [ParOldGen: 96K->16294K(1398272K)] 17125K->16294K(2010112K), [Metaspace: 20743K->20743K(1067008K)], 0.0536606 secs] [Times: user=0.20 sys=0.01, real=0.05 secs] 

是在这个GC时间点发生GC之后相关GC情况

• 9.079:这是从JVM启动开始计算到这次GC经过的时间,前面还有具体的发生时间日期
• Full GC (Metadata GC Threshold): 指这是一次Full GC,括号里是GC的原因,PSYoungGen是年轻代的GC,ParOldGen是老年代的GC,Metaspace是元空间的GC
• 17029K->0K(611840K): 这三个数字分别对应GC之前占用年轻代的大小,GC之后年轻代占用,以及整个年轻代的大小
• 96K->16294K(1398272K): 这三个数字分别对应GC之前占用老年代的大小,GC之后老年代占用,以及整个老年代的大小
• 20743K->20743K(1067008K): 这三个数字分别对应GC之前占用元空间内存的大小,GC之后元空间内存占用,以及整个元空间内存大小
• 0.0536606 secs:是该时间点GC总耗费时间

从日志可以发现几次Full GC都是由于元空间不够导致的,所以我们可以将元空间调大点

-Xloggc:./GC-%t.log -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCTimeStamps -XX:+PrintGCCause -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=100M -XX:+UseParallelGC -Xmx2048m -Xms2048m -XX:MetaspaceSize=256M -XX:MaxMetaspaceSize=256M

调整完我们再看下GC日志已经没有因为元空间不够导致的Full GC了

对于CMS和G1收集器的日志可能会有点不一样,也可以尝试打印对应的GC日志分析下.

package com.fanqiechaodan;

import java.util.ArrayList;
import java.util.List;

/**
 * @author fanqiechaodan
 * @Classname G1CMSDemo
 * @Description
 */
public class HeapDemo {

    /**
     * 100KB
     */
    byte[] BYTE = new byte[1024*100];

    public static void main(String[] args) throws InterruptedException {
        List<HeapDemo> heapDemoList = new ArrayList<>();
        while (true){
            heapDemoList.add(new HeapDemo());
            Thread.sleep(10);
        }
    }
}

CMS

-Xloggc:./GC-CMS-%t.log -Xms50M -Xmx50M -XX:MetaspaceSize=256M -XX:MaxMetaspaceSize=256M -XX:+PrintGCDetails -XX:+PrintGCDateStamps    -XX:+PrintGCTimeStamps -XX:+PrintGCCause  -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=100M -XX:+UseParNewGC -XX:+UseConcMarkSweepGC

这里的日志记录的就更为详细,每个CMS的阶段(初始标记,并发标记,重新标记,并发重置)都有涉及.

G1

-Xloggc:./G1-GC-%t.log -Xms50M -Xmx50M -XX:MetaspaceSize=256M -XX:MaxMetaspaceSize=256M -XX:+PrintGCDetails -XX:+PrintGCDateStamps    -XX:+PrintGCTimeStamps -XX:+PrintGCCause  -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=100M -XX:+UseG1GC  

GCeasy详解

以上的参数,能够帮我们查看分析GC的垃圾收集情况,但是如果GC日志很多很多,成千上万行.就算一目十行,看完了脑子也还是一片空白.所以我们可以借助一些东西来帮助我们分析.这里推荐GCeasy.可以上传GC文件,然后会利用可视化界面来展示GC情况.具体下图所示.

上图我们可以看到年轻代,老年代以及永久代的内存分配和最大使用情况

上图我们可以看到堆内存在GC之前和之后的变化.以及其他的信息

这个工具还提供基于机器学习的JVM只能优化建议.