Arthas线上监控诊断工具

发布时间 2023-10-31 16:11:38作者: 蔡金榜

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

背景

通常,本地开发环境无法访问生产环境。如果在生产环境中遇到问题,则无法使用 IDE 远程调试。更糟糕的是,在生产环境中调试是不可接受的,因为它会暂停所有线程,导致服务暂停。
开发人员可以尝试在测试环境或者预发环境中复现生产环境中的问题。但是,某些问题无法在不同的环境中轻松复现,甚至在重新启动后就消失了。
如果您正在考虑在代码中添加一些日志以帮助解决问题,您将必须经历以下阶段:测试、预发,然后生产。这种方法效率低下,更糟糕的是,该问题可能无法解决,因为一旦 JVM 重新启动,它可能无法复现,如上文所述。
Arthas 旨在解决这些问题。开发人员可以在线解决生产问题。无需 JVM 重启,无需代码更改。 Arthas 作为观察者永远不会暂停正在运行的线程。

Arthas作用

Arthas 是 Alibaba 开源的 Java 诊断工具,深受开发者喜爱。
当你遇到以下类似问题而束手无策时,Arthas可以帮助你解决:

  1. 这个类从哪个 jar 包加载的?为什么会报各种类相关的 Exception?
  2. 我改的代码为什么没有执行到?难道是我没 commit?分支搞错了?
  3. 遇到问题无法在线上 debug,难道只能通过加日志再重新发布吗?
  4. 线上遇到某个用户的数据处理有问题,但线上同样无法 debug,线下无法重现!
  5. 是否有一个全局视角来查看系统的运行状况?
  6. 有什么办法可以监控到 JVM 的实时运行状态?
  7. 怎么快速定位应用的热点,生成火焰图?
  8. 怎样直接从 JVM 内查找某个类的实例?

Arthas安装与启动

下载全包地址:https://arthas.aliyun.com/download/latest_version?mirror=aliyun解压即可。

  • 通过help可查看所有的命令
  • 通过 命令 -h 可以查看命令所需要的参数
  • 通过 -Dfile.encoding=UTF-8可以解决部分查询结果中文乱码问题
$ java -Dfile.encoding=UTF-8 -jar arthas-boot.jar
[INFO] arthas-boot version: 3.7.0
[INFO] Process 39361 already using port 3658
[INFO] Process 39361 already using port 8563
[INFO] Found existing java process, please choose one and input the serial number of the process, eg : 1. Then hit ENTER.
# 启动后会显示目前所运行的java应用,通过下标进入对应的应用里
* [1]: 39361 com.galaxy.eureka.server.EurekaServerApplication
  [2]: 45651 com.alibaba.otter.canal.deployer.CanalLauncher
1
[INFO] arthas home: /Users/caijinbang/.arthas/lib/3.7.0/arthas
[INFO] The target process already listen port 3658, skip attach.
[INFO] arthas-client connect 127.0.0.1 3658
  ,---.  ,------. ,--------.,--.  ,--.  ,---.   ,---.
 /  O  \ |  .--. ''--.  .--'|  '--'  | /  O  \ '   .-'
|  .-.  ||  '--'.'   |  |   |  .--.  ||  .-.  |`.  `-.
|  | |  ||  |\  \    |  |   |  |  |  ||  | |  |.-'    |
`--' `--'`--' '--'   `--'   `--'  `--'`--' `--'`-----'

wiki       https://arthas.aliyun.com/doc
tutorials  https://arthas.aliyun.com/doc/arthas-tutorials.html
version    3.7.0
main_class com.galaxy.eureka.server.EurekaServerApplication
pid        39361
time       2023-08-03 16:33:55

[arthas@39361]$

Arthas命令

dashboard

查看当前系统的实时面板

格式

dashboard [-i ] [-n ]

参数说明

参数名称 参数说明 举例
[i:] 刷新实时数据的时间间隔 (ms),默认 5000ms dashboard -i 10000
[n:] 刷新实时数据的次数(观测的次数) dashboard -n 10

结果

线程信息

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

内存使用和GC情况

分为堆和非堆

Memory                     used     total    max      usage    GC

heap

  • ps_eden_space : 堆内存中新生代的Eden区
  • ps_survivor_space:堆内存中的survivor区
  • ps_old_gen :堆内存的老年代区

nonheap

  • code_cache:JVM在运行时会频繁的调用方法的字节码编译为机器码,
  • metaspace:元数据区
  • compressed_class_space:类文件信息区
  • direct :直接内存
  • mapped :内存映射缓冲区(一般来说频繁读写文件可能导致此区域偏高)

系统信息区域

  • os.name:操作系统名称
  • os.version:操作系统版本
  • java.version:JAVA版本
  • java.home:JDK路径
  • systemload.average:平均负载(这个参数的意义暂时未知)
  • processors:处理器个数
  • timestamp/uptime:当前时间戳/当前系统启动时间-现在

jvm

该命令主要是查看当前JVM的整体情况,主要有以下几个指标

  • RUNTIME: java运行的环境,版本,classPath,lib等信息
  • CLASS-LOADING:加载的类的数量
  • COMPILATION:编译时长
  • GARBAGE-COLLECTORS:垃圾回收的次数和时间
  • MEMORY-MANAGERS: 内存区域
  • MEMORY:内存的使用情况,堆和非堆
  • OPERATING-SYSTEM:操作系统信息
  • THREAD:线程统计,死锁,守护,运行
  • FILE-DESCRIPTOR:文件描述符相关信息

memory

查看内存各个区的使用情况

[arthas@60687]$ memory
Memory                     used        total         max        usage
# 堆内存
heap                       48M         100M          1820M      2.66%
	ps_eden_space            31M         32M           672M       4.63%
	ps_survivor_space        888K        5120K         5120K      17.35%
	ps_old_gen               16M         62M           1365M      1.21%
# 非堆内促
nonheap                    31M         32M           -1         96.98%
	code_cache               6M          7M            240M       2.90%
	metaspace                21M         22M           -1         96.95%
	compressed_class_space   2M          2M            1024M      0.25%
	direct                   0K          0K            -          0.00%
	mapped                   0K          0K            -          0.00%

vmoption

查看,更新VM诊断相关的参数

查看所用VM参数

[arthas@60687]$ vmoption
KEY                                       VALUE       ORIGIN       WRITEABLE
------------------------------------------------------------------------------
# 发生Full gc前生成heapdump文件
                       false       DEFAULT      true
# 发生Full gc后生成heapdump文件
HeapDumpAfterFullGC                       false       DEFAULT      true
# 发生内存溢出时生成heapdump文件
HeapDumpOnOutOfMemoryError                false       DEFAULT      true
# 指定heapdump输出路径
HeapDumpPath                                          DEFAULT      true
# CMS垃圾回收主动退出等待的时间
CMSAbortablePrecleanWaitMillis            100         DEFAULT      true
# 用于设置CMS垃圾回收器在等待后台线程完成并发标记工作的最长时间。默认值为200ms。
CMSWaitDuration                           2000        DEFAULT      true
# CMS触发间隔时间
CMSTriggerInterval                        -1          DEFAULT      true
# 输出简要GC日志
PrintGC                                   false       DEFAULT      true
# 输出详细GC日志
PrintGCDetails                            false       DEFAULT      true
# 输出GC的时间戳(以日期的形式,如 2013-05-04T21:53:59.234+0800)
PrintGCDateStamps                         false       DEFAULT      true
# 输出GC的时间戳(以JVM启动到当期的总时长的时间戳形式)
PrintGCTimeStamps                         false       DEFAULT      true
# 输出GCID
PrintGCID                                 false       DEFAULT      true
# full gc前打印类直方图
PrintClassHistogramBeforeFullGC           false       DEFAULT      true
# full gc后打印类直方图
PrintClassHistogramAfterFullGC            false       DEFAULT      true
# 打印类的信息
PrintClassHistogram                       false       DEFAULT      true
# JVM最小空闲比率 
MinHeapFreeRatio                          0           DEFAULT      true
# JVM最大空闲比率 
MaxHeapFreeRatio                          100         DEFAULT      true
# 输出各个线程的获得的concurrent lock信息。
PrintConcurrentLocks                      false       DEFAULT      true

查看指定VM参数

[arthas@60687]$ vmoption PrintGC
 KEY            VALUE            ORIGIN               WRITEABLE
------------------------------------------------------------------
 PrintGC        false            DEFAULT              true

更新指定的 option

[arthas@60687]$ vmoption PrintGC true
Successfully updated the vm option.
 NAME     BEFORE-VALUE  AFTER-VALUE
------------------------------------
 PrintGC  false         true
[arthas@60687]$ vmoption PrintGC
 KEY            VALUE            ORIGIN               WRITEABLE
------------------------------------------------------------------
 PrintGC        true            DEFAULT              true

heapdump

生成dump文件

[arthas@60687]$ heapdump arthas-output/dump.hprof
Dumping heap to arthas-output/dump.hprof ...
Heap dump file created

classloader

查看 classloader 的继承树,urls,类加载信息

格式

classloader [-a] [-c ] [--classLoaderClass ] [-i] [-l] [--load ] [-r ] [-t] [-u]

参数说明

参数名称 参数说明 示例
[l] 按类加载实例进行统计
[t] 打印所有 ClassLoader 的继承树
[a] 列出所有 ClassLoader 加载的类,请谨慎使用
[c:] ClassLoader 的 hashcode
[classLoaderClass:] 指定执行表达式的 ClassLoader 的 class name
[c: r:] 用 ClassLoader 去查找 resource
[c: load:] 用 ClassLoader 去加载指定的类

结果

按类加载类型

[arthas@64185]$ classloader
# 类加载器名称																实例树							加载类的数量
name                                       numberOfInstances  loadedCountTotal
com.taobao.arthas.agent.ArthasClassloader  2                  3839
BootstrapClassLoader                       1                  2363
sun.misc.Launcher$ExtClassLoader           1                  45
sun.reflect.DelegatingClassLoader          27                 27
sun.misc.Launcher$AppClassLoader           1                  4
Affect(row-cnt:5) cost in 5 ms.

按类加载实例

[arthas@64185]$ classloader -l
# 类加载器名称											  加载类的数量  hash值   父类 
 name                               loadedCount  hash    parent
 BootstrapClassLoader                   2363     null    null
 com.t.a.a.ArthasClassloader@7e543fad   1365   7e543fad  ExtClassLoader@6d6f6e28
 com.t.a.a.ArthasClassloader@317129dd   2474   317129dd  ExtClassLoader@6d6f6e28
 sun.m.Launcher$AppClassLoader@42a57993  4     42a57993  ExtClassLoader@6d6f6e28
 sun.m.Launcher$ExtClassLoader@6d6f6e28  45    6d6f6e28  null
Affect(row-cnt:5) cost in 17 ms.

jad

反编译指定已加载类的源码,反编译出来的 java 代码可能会存在语法错误,但不影响你进行阅读理解

格式

jad [--classLoaderClass ] [-c ] [--hideUnicode] [--lineNumber ]
[-E] [--source-only] class-pattern [method-name]

参数说明

参数名称 参数说明
class-pattern 类名表达式匹配
[c:] 类所属 ClassLoader 的 hashcode
[classLoaderClass:] 指定执行表达式的 ClassLoader 的 class name
[E] 开启正则表达式匹配,默认为通配符匹配
[--source-only] 只打印源码
[method-name] 方法名称
[--lineNumber ] 显示行号

jad无参数

[arthas@64185]$ jad demo.MathGame
// 默认情况下,反编译结果里会带有ClassLoader信息
ClassLoader:
    +-sun.misc.Launcher$AppClassLoader@42a57993
    +-sun.misc.Launcher$ExtClassLoader@6d6f6e28
// 反编译类所在jar包路径
Location:
    /arthas-packaging-3.7.0-bin/math-game.jar

/*
* 反编译结果
*/
package demo;
import java.util.ArrayList;
import java.util.List;
import java.util.Random;
import java.util.concurrent.TimeUnit;

public class MathGame {
    private static Random random = new Random();
    private int illegalArgumentCount = 0;

    public List<Integer> primeFactors(int number) {
/*44*/ if (number < 2) {
/*45*/      ++this.illegalArgumentCount;
            throw new IllegalArgumentException(
                "number is: " + number + ", need >= 2"
            );
        }
        ArrayList<Integer> result = new ArrayList<Integer>();
/*50*/  int i = 2;
/*51*/  while (i <= number) {
/*52*/     if (number % i == 0) {
/*53*/          result.add(i);
/*54*/          number /= i;
/*55*/          i = 2;
                continue;
            }
/*57*/  	++i;
        }
/*61*/  return result;
    }

    public static void main(String[] args) throws InterruptedException {
        MathGame game = new MathGame();
        while (true) {
/*16*/      game.run();
/*17*/      TimeUnit.SECONDS.sleep(1L);
        }
    }

    public void run() throws InterruptedException {
        try {
/*23*/      int number = random.nextInt() / 10000;
/*24*/      List<Integer> primeFactors = this.primeFactors(number);
/*25*/      MathGame.print(number, primeFactors);
        }
        catch (Exception e) {
/*28*/      System.out.println(String.format("illegalArgumentCount:%3d, ",
                        this.illegalArgumentCount) + e.getMessage()
            );
        }
    }

    public static void print(int number, List<Integer> primeFactors) {
        StringBuffer sb = new StringBuffer(number + "=");
/*34*/  for (int factor : primeFactors) {
/*35*/       b.append(factor).append('*');
        }
/*37*/  if (sb.charAt(sb.length() - 1) == '*') {
/*38*/       sb.deleteCharAt(sb.length() - 1);
        }
/*40*/   System.out.println(sb);
    }
}
Affect(row-cnt:1) cost in 154 ms.

jad 方法

[arthas@64185]$ jad demo.MathGame
// 默认情况下,反编译结果里会带有ClassLoader信息
ClassLoader:
    +-sun.misc.Launcher$AppClassLoader@42a57993
    +-sun.misc.Launcher$ExtClassLoader@6d6f6e28
// 反编译类所在jar包路径
Location:
    /arthas-packaging-3.7.0-bin/math-game.jar

    public List<Integer> primeFactors(int number) {
/*44*/ if (number < 2) {
/*45*/      ++this.illegalArgumentCount;
            throw new IllegalArgumentException(
                "number is: " + number + ", need >= 2"
            );
        }
        ArrayList<Integer> result = new ArrayList<Integer>();
/*50*/  int i = 2;
/*51*/  while (i <= number) {
/*52*/     if (number % i == 0) {
/*53*/          result.add(i);
/*54*/          number /= i;
/*55*/          i = 2;
                continue;
            }
/*57*/  	++i;
        }
/*61*/  return result;
    }
Affect(row-cnt:1) cost in 154 ms.

jad只显示源码

默认情况下,反编译结果里会带有ClassLoader信息,通过--source-only选项,可以只打印源代码。方便和mc/retransform命令结合使用。

[arthas@64185]$ jad demo.MathGame  --source-only 

jad不显示行号

编译时如果不想显示行号,可以通过--lineNumber参数设置,默认值为 true,显示指定为 false 则不打印行号。

[arthas@64185]$ jad demo.MathGame  --source-only --lineNumber false

jad多个类加载器加载的类

当有多个 ClassLoader 都加载了这个类时,jad 命令会输出对应 ClassLoader 实例的 hashcode,然后你只需要重新执行 jad 命令,并使用参数 -c 就可以反编译指定 ClassLoader 加载的那个类了;
对于只有唯一实例的 ClassLoader 还可以通过--classLoaderClass指定 class name,使用起来更加方便:
--classLoaderClass 的值是 ClassLoader 的类名,只有匹配到唯一的 ClassLoader 实例时才能工作,目的是方便输入通用命令,而-c 是动态变化的。

$ jad org.apache.log4j.Logger
Found more than one class for: org.apache.log4j.Logger, 
Please use jad -c hashcode org.apache.log4j.Logger
HASHCODE  CLASSLOADER
    69dcaba4  +-monitor's ModuleClassLoader
    6e51ad67  +-java.net.URLClassLoader@6e51ad67
    		  +-sun.misc.Launcher$AppClassLoader@6951a712
              +-sun.misc.Launcher$ExtClassLoader@6fafc4c2
    2bdd9114  +-pandora-qos-service's ModuleClassLoader
    4c0df5f8  +-pandora-framework's ModuleClassLoader
Affect(row-cnt:0) cost in 38 ms.
                    
$ jad org.apache.log4j.Logger -c 69dcaba4
ClassLoader:
	+-monitor's ModuleClassLoader

Location:
	/Users/admin/app/log4j-1.2.14.jar

package org.apache.log4j;

import org.apache.log4j.spi.*;

public class Logger extends Category
{
    private static final String FQCN;

    protected Logger(String name) {
        super(name);
    }

    ...
Affect(row-cnt:1) cost in 190 ms.

mc

Memory Compiler/内存编译器,编译.java文件生成.class。

格式

mc [-c ] [--classLoaderClass ] [-d ] [--encoding ] sourcefiles...

参数说明

参数名称 参数说明
[-c ] classloader的hash值
[--classLoaderClass ] 指定执行表达式的 ClassLoader 的 class name
[-d ] 编译后的路径
[--encoding ] 编码
sourcefiles... 支持多个文件同时编译

直接编译

[arthas@64185]$ mc /tmp/Test.java

指定类加载器

$ mc -c  327a647b  /tmp/Test.java
$ mc --classLoaderClass org.s.b.l.LaunchedURLClassLoader /tmp/Test.java 

输出目录

$ mc -d /tmp/output /tmp/ClassA.java /tmp/ClassB.java

retransform

加载外部的.class文件,retransform jvm 已加载的类。

retransform 指定的 .class 文件

加载指定的 .class 文件,然后解析出 class name,再 retransform jvm 中已加载的对应的类。每加载一个 .class 文件,则会记录一个 retransform entry。如果多次执行 retransform 加载同一个 class 文件,则会有多条 retransform entry.

$ retransform /tmp/MathGame.class
retransform success, size: 1, classes:
demo.MathGame

查看retransform entry

$ retransform -l
Id              ClassName       TransformCount  LoaderHash      LoaderClassName
1               demo.MathGame   1               null            null

删除 retransform entry

# 指定id
retransform -d 1
# 删除所有
retransform --deleteAll

结合 jad/mc/retransform 命令使用

# 源码反编译
jad --source-only demo.MathGame > /tmp/MathGame.java
# 内存编译
mc /tmp/MathGame.java -d /tmp
# 加载新的字节码
retransform /tmp/demo/MathGame.class

流程

  • jad 命令反编译,然后可以用其它编译器,比如 vim 来修改源码
  • mc 命令来内存编译修改过的代码
  • 用 retransform 命令加载新的字节码

上传 .class 文件到服务器的技巧

使用mc命令来编译jad的反编译的代码有可能失败。可以在本地修改代码,编译好后再上传到服务器上。有的服务器不允许直接上传文件,可以使用base64命令来绕过。
在本地先转换.class文件为 base64,再保存为 result.txt

base64 < Test.class > result.txt
  1. 到服务器上,新建并编辑result.txt,复制本地的内容,粘贴再保存
  2. 把服务器上的 result.txt还原为.class
base64 -d < result.txt > Test.class
  1. 用 md5 命令计算哈希值,校验是否一致

retransform 的限制

  • 不允许新增加 field/method
  • 正在跑的函数,没有退出不能生效

thread

格式

thread [--all] [-b] [-i ] [--state ] [-n ] [id]

参数说明

参数名称 参数说明 举例
id 线程id thread 1022
[n:] 指定最忙的前 N 个线程并打印堆栈 thread -n 5
[b] 找出当前阻塞其他线程的线程,目前有2种类型
--lockedMonitors : synchronize导致的死锁
--lockedSynchronizers:Reentrylock类型导致 thread -b
thread -b --lockedMonitors
thread -b --ockedSynchronizers
[i ] 指定 cpu 使用率统计的采样间隔,单位为毫秒,默认值为 200 thread -i 5000
[--all] 显示所有匹配的线程 thread
[--state ] 根据状态筛选 thread --state BLOCK

结果

thread

# 统计总的线程情况及各个状态的个数
Threads Total: 66, NEW: 0, RUNNABLE: 35, BLOCKED: 0, WAITING: 17, TIMED_WAITING:
4, TERMINATED: 0, Internal threads: 10
# 各个线程具体的信息
ID NAME      GROUP     PRIORI STATE  %CPU  DELTA_ TIME   INTER DAEMON
  • ID :线程id
  • NAME:线程名称
  • GROUP:线程组
  • PRIORI :线程的优先级
  • STATE :线程状态
  • %CPU :CPU的占比
  • DELTA_TIME:采样间隔时间内线程的增量CPU时间
  • INTERRUPTED:是否被中断
  • DAEMON:是否是守护线程

thread id

[arthas@39361]$ thread 77
# 指明线程名称,线程id 运行状态,具体运行的行号
"http-nio-8080-ClientPoller" Id=77 RUNNABLE (in native)
    at sun.nio.ch.KQueueArrayWrapper.kevent0(Native Method)
    at sun.nio.ch.KQueueArrayWrapper.poll(KQueueArrayWrapper.java:198)
    at sun.nio.ch.KQueueSelectorImpl.doSelect(KQueueSelectorImpl.java:117)
    at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
    at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
    at org.apache.tomcat.util.net.NioEndpoint$Poller.run(NioEndpoint.java:816)
    at java.lang.Thread.run(Thread.java:748)

thread -n

[arthas@39361]$ thread -n 3
# Compiler threads:这些线程负责在运行时将字节码编译为本地代码;
"C1 CompilerThread2" [Internal] cpuUsage=2.53% deltaTime=5ms time=2649ms
# 用户应用线程
"arthas-command-execute" Id=100 cpuUsage=0.36% deltaTime=0ms time=234ms RUNNABLE
    at sun.management.ThreadImpl.dumpThreads0(Native Method)
    at sun.management.ThreadImpl.getThreadInfo(ThreadImpl.java:448)
    at com.taobao.arthas.core.command.monitor200........ThreadCommand.java:206)
    at com.taobao.arthas.core.command.monitor200.....(ThreadCommand.java:122)
    at com.taobao.arthas.core.shell.command.impl...(AnnotatedCommandImpl.java:82)
    at com.taobao.arthas.core.shell.command....$100(AnnotatedCommandImpl.java:18)
    at com.taobao.arthas.core.shell.command..$ProcessHandler.handle(.....java:111)
    at com.taobao.arthas.core.shell.command....ProcessHandler.handle(...java:108)
    at com.taobao.arthas.core.shell.s..CommandProcessTask.run(...java:385)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run$$$capture(FutureTask.java:266)
    at java.util.concurrent.FutureTask.run(FutureTask.java)
    at java.util.concurrent.ScheduledThreadPoolExecutor..cutor.java:180)
    at java.util.concurrent.ScheduledThreadPoolExecutor$(...java:293)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(...java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(...java:617)
    at java.lang.Thread.run(Thread.java:748)

# 这个线程负责响应定时触发的事件(例如:中断),用来执行一些定时操作
"VM Periodic Task Thread" [Internal] cpuUsage=0.06% deltaTime=0ms time=41483ms


# 引用对象垃圾回收线程
"Reference Handler" Id=2 cpuUsage=0.0% deltaTime=0ms time=10ms WAITING on java.lang.ref.Reference$Lock@1d6c398
    at java.lang.Object.wait(Native Method)
    -  waiting on java.lang.ref.Reference$Lock@1d6c398
    at java.lang.Object.wait(Object.java:502)
    at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
    at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)

# GC线程
"Finalizer" Id=3 cpuUsage=0.0% deltaTime=0ms time=12ms WAITING on java.lang.ref.ReferenceQueue$Lock@6bc16e23
    at java.lang.Object.wait(Native Method)
    -  waiting on java.lang.ref.ReferenceQueue$Lock@6bc16e23
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164)
    at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)

# 这些线程负责响应外部发给当前JVM进程的信号,并通过调用JVM内的其他线程。
"Signal Dispatcher" Id=4 cpuUsage=0.0% deltaTime=0ms time=0ms RUNNABLE

thread -b

$ thread -b
"http-bio-8080-exec-4" Id=27 TIMED_WAITING
    at java.lang.Thread.sleep(Native Method)
    at test.arthas.TestThreadBlocking.doGet(TestThreadBlocking.java:22)
    # 指出了具体导致死锁的代码行号
    -  locked java.lang.Object@725be470 <---- but blocks 4 other threads!
    .......

    Number of locked synchronizers = 1
    - java.util.concurrent.ThreadPoolExecutor$Worker@31a6493e

watch

格式

watch [-b] [-e] [--exclude-class-pattern ] [-x ] [-f] [-h] [-n ] [--listenerId ] [-m ] [-E] [-M ] [-s] [-v] class-pattern m
ethod-pattern [express] [condition-express]

参数说明

参数名称 参数说明 举例
class-pattern 类名表达式匹配 watch demo.MathGame
primeFactors
method-pattern 函数名表达式匹配
express 观察表达式,
默认值:
condition-express 条件表达式
[b] 函数调用之前观察
[e] 函数异常之后观察
[s] 函数返回之后观察
[f] 函数结束之后(正常返回和异常返回)观察
[E] 开启正则表达式匹配,默认为通配符匹配
[x:] 指定输出结果的属性遍历深度,
默认为 1,最大值是 4
[m ] 指定 Class 最大匹配数量,默认值为 50。
长格式为[maxMatch ]。

结果

ognl表达式,它支持一些内置对象:clazz 、method、target、params、returnObj、throwExp

监听方法

[arthas@60687]$ watch demo.MathGame primeFactors
Press Q or Ctrl+C to abort.
# 影响的类、行 耗时时间
Affect(class count: 1 , method count: 1) cost in 34 ms, listenerId: 3
# location为AtExceptionExit是异常退出,AtExit为正常退出
method=demo.MathGame.primeFactors location=AtExceptionExit
# ts为调用时间  cost为耗时 
ts=2023-08-04 11:01:15; [cost=0.155181ms] result=@ArrayList[
  	# 参数
    @Object[][isEmpty=false;size=1],
    # 对象
    @MathGame[demo.MathGame@2e0fa5d3],
  	#结果
    null,
]
method=demo.MathGame.primeFactors location=AtExit
ts=2023-08-04 11:01:18; [cost=3.874243ms] result=@ArrayList[
    @Object[][isEmpty=false;size=1],
    @MathGame[demo.MathGame@2e0fa5d3],
    @ArrayList[isEmpty=false;size=1],
]

观察方法出参和返回值

# 
[arthas@60687]$ watch demo.MathGame primeFactors "{params,returnObj}" -x 2
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 33 ms, listenerId: 13
method=demo.MathGame.primeFactors location=AtExceptionExit
ts=2023-08-04 13:31:54; [cost=0.241083ms] result=@ArrayList[
    @Object[][
        @Integer[-34709],
    ],
    null,
]

method=demo.MathGame.primeFactors location=AtExit
ts=2023-08-04 13:31:56; [cost=0.02882ms] result=@ArrayList[
    @Object[][
        @Integer[1],
    ],
    @ArrayList[
        @Integer[7],
        @Integer[23],
        @Integer[139],
    ],
]

特别说明

  • watch 命令定义了4个观察事件点,即 -b 方法调用前,-e 方法异常后,-s 方法返回后,-f 方法结束后
  • 4个观察事件点 -b、-e、-s 默认关闭,-f 默认打开,当指定观察点被打开后,在相应事件点会对观察表达式进行求值并输出
  • 这里要注意方法入参和方法出参的区别,有可能在中间被修改导致前后不一致,除了 -b 事件点 params 代表方法入参外,其余事件都代表方法出参
  • 当使用 -b 时,由于观察事件点是在方法调用前,此时返回值或异常均不存在
  • 具体可参考:https://www.cnblogs.com/doit8791/p/12040642.html

monitor

方法执行监控,monitor命令是一个非实时返回命令,不断的等待目标 Java 进程返回信息,直到用户输入 Ctrl+C为止。

格式

monitor [-b] [-c ] [--exclude-class-pattern ] [-n ]
[--listenerId ] [-m ] [-E] [-v]
class-pattern method-pattern [condition-express]

参数说明

参数名称 参数说明
class-pattern 类名表达式匹配
method-pattern 方法名表达式匹配
condition-express 条件表达式
[E] 开启正则表达式匹配,默认为通配符匹配
[c:] 统计周期,默认值为 120 秒
[b] 方法调用之前计算 condition-express
[m ] 指定 Class 最大匹配数量,默认值为 50。长格式为[maxMatch ]。

监控指标

监控项 说明
timestamp 时间戳
class Java 类
method 方法(构造方法、普通方法)
total 调用次数
success 成功次数
fail 失败次数
rt 平均 RT
fail-rate 失败率

监控命令

# 每5s监控一次MathGame类的primeFactors方法, 监控次数不限制
$ monitor -c 5 demo.MathGame primeFactors
# 每1s监控一次MathGame类的primeFactors方法,其监控次数为10次
$ monitor demo.MathGame primeFactors -c 1 -n 10

trace

渲染和统计整个调用链路上的所有性能开销和追踪调用链路。
渲染和统计整个调用链路上的所有性能开销和追踪调用链路。

格式

trace [--exclude-class-pattern ] [-n ] [--listenerId ]
[-m ] [-p ] [-E] [--skipJDKMethod ]
[-v] class-pattern method-pattern [condition-express]

参数说明

参数名称 参数说明
class-pattern 类名表达式匹配
method-pattern 方法名表达式匹配
condition-express 条件表达式
[E] 开启正则表达式匹配,默认为通配符匹配
[n:] 命令执行次数
#cost 方法执行耗时
[m ] 指定 Class 最大匹配数量,默认值为 50。长格式为[maxMatch ]。

追踪方法

命令:trace demo.MathGame run

[arthas@64185]$ trace demo.MathGame run
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 60 ms, listenerId: 15
# 主要信息有:执行时间、线程名、线程id,是否是守护线程,优先级,类加载器
---ts=2023-08-05 15:49:35;thread_name=main;id=1;is_daemon=false;priority=5;
	TCCL=sun.misc.Launcher$AppClassLoader@42a57993
	# 监测的方法
  ---[0.679662ms] demo.MathGame:run() 
  	# primeFactors #24  方法的行号,
    +---[20.00% 0.135965ms ] demo.MathGame:primeFactors() #24
    ---[32.78% 0.222792ms ] demo.MathGame:print() #25

---ts=2023-08-05 15:49:36;thread_name=main;id=1;is_daemon=false;priority=5;
	TCCL=sun.misc.Launcher$AppClassLoader@42a57993
  ---[0.414585ms] demo.MathGame:run()
     ---[49.39% 0.204767ms ] demo.MathGame:primeFactors() #24 [throws Exception]

常用命令

# 追踪run方法 5次
$ trace demo.MathGame run -n 5
# 追踪run方法,可根据 --skipJDKMethod 的设置是否跳过JDK的方法,默认跳过
$ trace --skipJDKMethod false demo.MathGame run
# 追踪run方法,只追踪 #cost(耗时) > 10ms的
$ trace demo.MathGame run '#cost > 10'

tt

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

格式

tt [-d] [--delete-all] [--exclude-class-pattern ] [-x ]
[-i ] [-n ] [-l] [--listenerId ] [-m ] [-p] [-E]
[--replay-interval ] [--replay-times ] [-s ] [-M ] [-t] [-v]
[-w ] [class-pattern] [method-pattern] [condition-express]

记录调用

tt -t监控某个方法执行了几次

[arthas@64185]$ tt -t demo.MathGame primeFactors
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 59 ms, listenerId: 28
 INDEX  TIMESTAMP  COST(ms)   IS-RET  IS-EXP   OBJECT    CLASS   METHOD

表格字段解释

表格字段 字段解释
INDEX 时间片段记录编号,每一个编号代表着一次调用,
后续 tt 还有很多命令都是基于此编号指定记录操作,非常重要。
TIMESTAMP 方法执行的本机时间,记录了这个时间片段所发生的本机时间
COST(ms) 方法执行的耗时
IS-RET 方法是否以正常返回的形式结束
IS-EXP 方法是否以抛异常的形式结束
OBJECT 执行对象的hashCode(),注意,曾经有人误认为是对象在 JVM 中的内存地址,
但很遗憾他不是。但他能帮助你简单的标记当前执行方法的类实体
CLASS 执行的类名
METHOD 执行的方法名

部分参数解释

# 获取记录列表
$ tt -l 
# 获取某个执行的详细信息
$ tt demo.MathGame primeFactors  -i 1037
# 记录 10 次
$ tt demo.MathGame primeFactors  -n 10 -t
# 记录方法或者类可以用通配符去匹配
$ tt demo.MathGame pri*  -n 3 -t
# 筛选出已记录的方法名
$ tt -s 'method.name=="primeFactors"'


重做一次调用

   当你稍稍做了一些调整之后,你可能需要前端系统重新触发一次你的调用,此时得求爷爷告奶奶的需要前端配合联调的同学再次发起一次调用。而有些场景下,这个调用不是这么好触发的。

tt 命令由于保存了当时调用的所有现场信息,所以我们可以自己主动对一个 INDEX 编号的时间片自主发起一次调用,从而解放你的沟通成本。此时你需要 -p 参数。通过 --replay-times 指定 调用次数,通过 --replay-interval 指定多次调用间隔(单位 ms, 默认 1000ms)

logger

查看 logger 信息

[arthas@21068]$ logger
 name                  ROOT
 class                 ch.qos.logback.classic.Logger
 classLoader           sun.misc.Launcher$AppClassLoader@18b4aac2
 classLoaderHash       18b4aac2
 level                 INFO
 effectiveLevel        INFO
 additivity            true
 codeSource            file:/D:/soft/install/.../logback-classic-1.2.3.jar
 appenders      name            CONSOLE
                class           ch.qos.logback.core.ConsoleAppender
                classLoader     sun.misc.Launcher$AppClassLoader@18b4aac2
                classLoaderHash 18b4aac2
                target          System.out

 name           com.quanqiuwa.website.micro.service.common.orm.logger.CustomLoggerImpl
 class              ch.qos.logback.classic.Logger
 classLoader        sun.misc.Launcher$AppClassLoader@18b4aac2
 classLoaderHash    18b4aac2
 level              DEBUG
 effectiveLevel     DEBUG
 additivity         false
 codeSource         file:/D:/soft/install/apache-maven-3.6.3-bin/apache-maven-3.6.3/lib/ch/qos/logback/logback-classic/1.2.3/logback-classic-1.2.3.jar
 appenders           name            CONSOLE
                     class           ch.qos.logback.core.ConsoleAppender
                     classLoader     sun.misc.Launcher$AppClassLoader@18b4aac2
                     classLoaderHash 18b4aac2
                     target          System.out

更新 logger level

# 更新指定日志级别修改日志级别
[arthas@2062]$ logger --name ROOT --level debug
# 指定方法修改日志级别
[arthas@2062]$ logger -n com.quanqiuwa....ReportOrderListener --level info
update logger level success.

辅助命令

# arthas版本
[arthas@60687]$ version
# 停止监听,如果已经监听了一个java进程,无退出,之后重新连接其他线程会连接不上,必须连接上之前的
# 监听,然后使用stop命令停止,然后再重新连接
[arthas@60687]$ stop
# 等同于exit、logout、q三个指令
[arthas@60687]$ quit
# 返回当前工作目录,等同于linux命令
[arthas@60687]$ pwd
# 查看历史命令 有2个参数  [n]:查看最近n条命令  -c 清除历史
[arthas@60687]$ history
# 清除命令
[arthas@60687]$ cls