banner
田野放空

田野放空

认真扮演一个擅长白日做梦的普通人

Arthas使用分享

介绍#

Arthas 是一款线上监控诊断产品,通过全局视角实时查看应用 内存、gc、线程的状态信息,并能在不修改应用代码的情况下,对业务问题进行诊断,包括查看方法调用的出入参、异常,监测方法执行耗时,类加载信息等,大大提升线上问题排查效率。

解决问题:

  1. 本地开发环境无法访问生产环境,出现问题难以调试
  2. 某些问题无法在不同的环境中轻松复现。
  3. 添加一些日志以帮助解决问题,涉及到发布。

基础命令#

下载和安装:#

机器安装:
curl -O https://arthas.aliyun.com/arthas-boot.jar

命令列表:#

1. jvm 相关:#

image

  • dashboard - 当前系统的实时数据面板,默认 5s 刷新一次
ID: Java 级别的线程 ID,注意这个 ID 不能跟 jstack 中的 nativeID 一一对应。
NAME: 线程名
GROUP: 线程组名
PRIORITY: 线程优先级, 1~10 之间的数字,越大表示优先级越高。setPriority(1-10)
STATE: 线程的状态
CPU%: 线程的 cpu 使用率。比如采样间隔 1000ms,某个线程的增量 cpu 时间为 100ms,则 cpu 使用率=100/1000=10%
DELTA_TIME: 上次采样之后线程运行增量 CPU 时间,数据格式为秒
TIME: 线程运行总 CPU 时间,数据格式为分:秒
INTERRUPTED: 线程当前的中断位状态
DAEMON: 是否是 daemon 线程

C1 C2 CompilerThread:
垃圾回收次数gc.ps_scavenge.count、垃圾回收消耗时间gc.ps_scavenge.time、标记-清除算法的次数gc.ps_marksweep.count、标记-清除算法的消耗时间
  • heapdump - dump java heap, 类似 jmap 命令的 heap dump 功能

    heapdump xx-output/dump.hprof
    生成文件在 arthas-output 目录,可以通过浏览器打开: http://localhost:8563/xx-output/

  • jvm - 查看当前 JVM 的信息

    Thread:
    COUNT: JVM 当前活跃的线程数
    DAEMON-COUNT: JVM 当前活跃的守护线程数
    PEAK-COUNT: 从 JVM 启动开始曾经活着的最大线程数
    STARTED-COUNT: 从 JVM 启动开始总共启动过的线程次数
    DEADLOCK-COUNT: JVM 当前死锁的线程数
    文件描述符:
    MAX-FILE-DESCRIPTOR-COUNT:JVM 进程最大可以打开的文件描述符数
    OPEN-FILE-DESCRIPTOR-COUNT:JVM 当前打开的文件描述符数

  • logger - 查看和修改 logger

    更新 logger level
    logger --name ROOT --level debug

  • memory - 查看 JVM 的内存信息

  • thread - 查看当前 JVM 的线程堆栈信息

    thread: 默认按照 CPU 增量时间降序排列
    thread -n 3 : 展示当前最忙的前 3 个线程并打印堆栈
    thread id : 显示指定线程的运行堆栈
    thread -b : 找出当前阻塞其他线程的线程:目前只支持找出 synchronized 关键字阻塞住的线程
    thread -i : 指定采样时间间隔
    thread --state : 查看指定状态的线程

  • vmoption - 查看和修改 JVM 里诊断相关的 option

    更新指定的 option
    vmoption PrintGC true

  • vmtool - 从 jvm 里查询对象,执行 forceGc

    vmtool --action forceGc

2. class/classloader 相关#

  • classloader - 查看 classloader 的继承树,urls,类加载信息,使用 classloader 去 getResource

    按类加载类型查看统计信息
    按类加载实例查看统计信息 -l
    查看 ClassLoader 的继承树 -t

  • dump - dump 已加载类的 byte code 到特定目录

    dump com.xx.xx.controller.ArthasController 生成 ArthasController.class 文件

  • jad - 反编译指定已加载类的源码

    默认情况下,反编译结果里会带有 ClassLoader 信息,通过 --source-only 选项,可以只打印源代码
    jad --source-only com.xx.xx.controller.ArthasController
    jad --source-only com.xx.xx.controller.ArthasController deadLock

  • redefine - 加载外部的.class 文件,redefine 到 JVM 里

    redefine 命令和 jad/watch/trace/monitor/tt 等命令会冲突。执行完 redefine 之后,如果再执行上面提到的命令,则会把 redefine 的字节码重置。

  • retransform - 加载外部的.class 文件,retransform 到 JVM 里

    1. 加载外部.class 文件
      retransform /Users/xx/IdeaProjects/ArthasController.class
    2. 查看 retransform entry
      retransform -l
    3. 删除 retransform entity:
      retransform -d 1
      retransform --deleteAll
      备注:
    4. 如果不清除掉所有的 retransform entry,并重新触发 retransform ,则 arthas stop 时,retransform 过的类仍然生效。
    5. 若没有清除 retransform 而停止了 Arthas,则可以再次启动,重新 jad-mc-retransform,jad 反编译得到的还是修改前的代码。
    6. retransform 不允许新增加字段或方法。
  • sc - 查看 JVM 已加载的类信息

    sc -d com.xx.xx.controller.*
    sc -d com.xx.xx.controller.ArthasController

  • sm - 查看已加载类的方法信息

    sm com.xx.xx.controller.ArthasController *

3. monitor/watch/trace 相关#

请注意,这些命令,都通过字节码增强技术来实现的,会在指定类的方法中插入一些切面来实现数据统计和观测,因此在线上、预发使用时,请尽量明确需要观测的类、方法以及条件,诊断结束要执行 stop 或将增强过的类执行 reset 命令。
一定要带 -n 执行命令,否则在遇到调用量非常大的方法,瞬间就能将你的 JVM 内存撑爆。

  • monitor - 方法执行监控

    监控 ArthasController 中的 flag 方法,每 5s 打印一次,打印 10 次
    monitor com.xx.xx.controller.ArthasController flag -n 10 --cycle 5
    统计接口参数 param [0] <=2 的请求
    monitor -c 5 demo.MathGame primeFactors "params[0] <= 2"

  • stack - 输出当前方法被调用的调用路径
    很多时候我们都知道一个方法被执行,但这个方法被执行的路径非常多,或者你根本就不知道这个方法是从那里被执行。

stack com.xx.xx.service.impl.WjVideoServiceImpl preprocessingVideo -n 5

  • trace - 方法内部调用路径,并输出方法路径上的每个节点上耗时

    • trace 能方便的帮助你定位和发现因 RT 高而导致的性能问题缺陷,但其每次只能跟踪一级方法的调用链路。
    • 很多时候我们只想看到某个方法的 rt 大于某个时间之后的 trace 结果。可以用 '#cost>100' 表示当执行时间超过 100ms 的时候,才会输出 trace 的结果。
    • 目前不支持 trace java.lang.Thread getName

    --exclude-class-pattern 排除掉指定的类
    --skipJDKMethod true trace jdk 里的函数
    '#cost > 10' 执行时间超过 10ms 的时候,才会输出 trace 的结果。
    跟踪多级方法实现链路调用追踪
    trace -E com.xx.xx.service.impl.VideoServiceImpl|com.xx.xx.controller.AutoCutController|com.xx.xx.service.impl.WjVideoServiceImpl preprocessing|preprocessingVideo -n 5 '#cost>10'

  • tt (TimeTunnel) - 方法执行数据的时空隧道,记录下指定方法每次调用的入参和返回信息,并能对这些不同的时间下调用进行观测

    tt -t com.kscs.capcut.service.impl.WjVideoServiceImpl preprocessingVideo -n 5
    tt -l 检索调用记录 tt -s 'method.name=="preprocessingVideo"'
    tt -i 1000 查看调用信息
    tt -i 1004 -p 重做一次调用

  • watch - 观察到指定函数的调用情况。能观察到的范围为:返回值、抛出异常、入参。

    • -f 在函数返回之后观察
    • -x 输出结果的属性遍历深度

    watch com.xx.xx.service.impl.WjVideoServiceImpl preprocessingVideo '{params,returnObj,throwExp}' -n 5 -x 3

解决问题:#

1. 利用 Arthas 精准定位 Java 应用 CPU 负载过高问题#

查看CPU占比最高线程  
1. thread / thread -n 3
2. thread id

1. 方法被循环调用
2. 内部有死循环

我们使用tt命令监听一下这个方法的调用情况
tt -t com.xx.xx.controller.ArthasController deadAdd -n 5 
在线上执行这个命令的时候,一定要记得加上 -n 参数,否则线上巨大的流量可能会瞬间撑爆你的JVM内存

反编译方法,看看
jad --source-only com.xx.xx.controller.ArthasController deadAdd


top --> top -Hp pid --> jstack pid  16 进制

2. 利用 Arthas 分析内存问题#

dashboard 查看GC数据
 gc.ps_scavenge.count      gc.ps_marksweep.count  

使用 vmoption 命令动态打开 GC 日志
vmoption PrintGC true
vmoption PrintGCDetails true

使用 vmtool 强制 GC
vmtool --action forceGc
https://www.v2ex.com/t/792635

3. 动态修改日志打印级别#

logger
默认情况下,logger 命令会在 SystemClassloader 下执行,如果应用是传统的war应用,或者 spring boot fat jar 启动的应用,那么需要指定 classloader。
 logger -c 685f4c2e  --name ROOT --level debug

4. 反编译源码,查看 jvm 加载的是否为预期的文件内容。#

jad --source-only com.xx.xx.controller.AutoCutController preprocessing

5. 方法内调用路径及各方法调用耗时。#

    monitor :此命令用于监控方法的执行情况,包括方法的调用次数、成功次数、失败次数、最大耗时、最小耗时和平均耗时。它通常用于定位性能问题。
[arthas@19702]$ monitor com.xx.xx.service.impl.WjVideoServiceImpl preprocessingVideo  -n 10  --cycle 10
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 49 ms, listenerId: 3
 timestamp         class                     method                    total    success  fail    avg-rt(  fail-ra
                                                                                                 ms)      te
------------------------------------------------------------------------------------------------------------------
 2023-07-17 16:21  com.xx.xx.service.  preprocessingVideo        1        1        0       3755.98  0.00%
 :14               impl.WjVideoServiceImpl

 
 
    trace :此命令用于跟踪方法的调用路径和耗时。它会记录下方法的入参和返回结果,以及方法内部调用的其他方法和它们的执行时间。
 [arthas@19702]$  trace -E com.xx.xx.service.impl.VideoServiceImpl|com.xx.xx.controller.AutoCutController|com.xx.xx.service.impl.WjVideoServiceImpl preprocessing|preprocessingVideo -n 5  --skipJDKMethod false '1==1'
Press Q or Ctrl+C to abort.
Affect(class count: 4 , method count: 4) cost in 157 ms, listenerId: 2
`---ts=2023-07-17 16:20:42;thread_name=http-nio-8183-exec-8;id=2b;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@3576ddc2
    `---[1.069325ms] com.xx.xx.controller.AutoCutController$$EnhancerBySpringCGLIB$$333516af:preprocessing()
        `---[83.17% 0.889312ms ] org.springframework.cglib.proxy.MethodInterceptor:intercept()
            `---[43.36% 0.385619ms ] com.xx.xx.controller.AutoCutController:preprocessing()
                +---[6.45% 0.024868ms ] org.slf4j.MDC:get() #31
                +---[1.90% 0.007333ms ] com.xx.xx.common.vo.ProcessingVO:setTaskId() #31
                +---[70.24% 0.270861ms ] com.xx.xx.service.VideoService:preprocessingVideo() #32
                `---[2.93% 0.011295ms ] com.xx.xx.base.model.Result:success() #33


    tt   :此命令用于记录方法的历史调用情况,包括方法的入参、返回结果和异常信息。它不仅可以查看方法的当前调用情况,还可以查看方法的历史调用情况,还可以重试历史调用。
[arthas@19702]$ tt -t com.kscs.capcut.controller.AutoCutController preprocessing -n 5
Press Q or Ctrl+C to abort.
Affect(class count: 2 , method count: 2) cost in 39 ms, listenerId: 4
 INDEX  TIMESTAMP         COST(ms  IS-RE  IS-EX  OBJECT       CLASS                     METHOD
                          )        T      P
------------------------------------------------------------------------------------------------------------------
 1000   2023-07-17 16:23  0.20207  true   false  0x5ec8b24c   AutoCutController         preprocessing
        :17               4
 1001   2023-07-17 16:23  1.94166  true   false  0xe637be2a   AutoCutController$$Enhan  preprocessing
        :17               4                                   cerBySpringCGLIB$$333516
                                                              af

6. 代码热更新#

1. 反编译已加载类的源码
jad --source-only com.kscs.capcut.controller.ArthasController 

2. 修改本地代码并编译、测试。通过后找到target目录下编译好的.class文件
3. 热更新
retransform /Users/edy/IdeaProjects/ArthasController.class
2. 查看 retransform entry
    retransform -l 
3. 删除retransform entity:
    retransform -d 1
    retransform --deleteAll

对服务性能的影响#

Arthas在执行trace/watch/tt/monitor 等命令时,本质上是在method的前后插入代码,会导致原来JVM里JIT编译生成的代码无效,需要退回原来的代码,再重新JIT编译。所以对于并发高的函数调用会调起抖动。
所以要避免一次性trace/watch大量的类。
建议在线上环境时,集群里选一台负载低的机器来执行分析,如果是只有一台机器,则要小心使用。

用到的 demo#

public class ArthasController {
    public static boolean flag = true;
    private List<ProcessingVO> stringList = new ArrayList<>();

    @RequestMapping(method = RequestMethod.POST, value = "flag")
    public Result<Map<String, String>> flag(Integer param1, Integer param2) {
        flag = !flag;
        return Result.success();
    }

    @RequestMapping(method = RequestMethod.POST, value = "oom")
    public Result<List<ProcessingVO>> oom() {
        stringList.clear();
        for (int i = 0; i < 1000000; i++) {
            if (stringList.size() > 500000) {
                continue;
            }
            ProcessingVO vo = new ProcessingVO();
            vo.setVideoName("videoName" + i);
            vo.setTaskId("taskId" + i);
            stringList.add(vo);
        }
        return Result.success();
    }

    @RequestMapping(method = RequestMethod.POST, value = "deadLock")
    public Result<Map<String, String>> deadLock() {
        Thread thread1 = new Thread(() -> {
            synchronized (String.class) {
                log.info("thread1 get String lock");
                try {
                    Thread.sleep(10000);
                } catch (Exception e) {
                    e.printStackTrace();
                }
                synchronized (Integer.class) {
                    log.info("thread1 get Integer lock");
                }
            }
        });
        Thread thread2 = new Thread(() -> {
            synchronized (Integer.class) {
                log.info("thread2 get Integer lock");
                try {
                    Thread.sleep(100);
                } catch (Exception e) {
                    e.printStackTrace();
                }
                synchronized (String.class) {
                    log.info("thread2 get String lock");
                }
            }
        });
        thread1.setName("deadlock-thread1");
        thread2.setName("deadlock-thread2");
        thread1.start();
        thread2.start();
        return Result.success();
    }

    @RequestMapping(method = RequestMethod.POST, value = "highCPU")
    public Result<Map<String, String>> highCPU() {
        Thread highCpuThread = new Thread(this::deadAdd);
        highCpuThread.setName("HighCpu");
        highCpuThread.start();
        return Result.success();
    }
    //0<-1<-2<-0
    private void deadAdd() {
        ListNode node2 = new ListNode(2, null); //创建节点(数据+引用
        ListNode node1 = new ListNode(1, node2);
        ListNode node = new ListNode(0, node1);
        node2.next = node;
        while (node != null) {
            if (flag) {
                node = node.next;
            } else {
                break;
            }
        }
        System.out.println("stop deadAdd");

    }

    class ListNode {        //类名 :Java类就是一种自定义的数据结构
        int val;            //数据 :节点数据
        ListNode next;      //对象 :引用下一个节点对象。在Java中没有指针的概念,Java中的引用和C语言的指针类似

        ListNode(int val, ListNode next) {  //构造方法 :构造方法和类名相同
            this.val = val;   //把接收的参数赋值给当前类的val变量
            this.next = next;
        }
    }


}
加载中...
此文章数据所有权由区块链加密技术和智能合约保障仅归创作者所有。