线上问题排查神器入门——Arthas

恒生LIGHT云社区
990 阅读6分钟

作者：threedayman

来源：恒生LIGHT云社区

Arthas 是什么

Arthas是一款阿里巴巴开源的 Java 线上诊断工具。Arthas支持JDK 6+，支持Linux/Mac/Windows，采用命令行交互模式，同时提供丰富的 Tab 自动补全功能，进一步方便进行问题的定位和诊断。

官网地址**：**arthas.aliyun.com/doc/

github地址**：**github.com/alibaba/art…

Arthas能干什么

大家有没有在生产 或者测试环境中遇到下列问题。

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

在官网上说Arthas能帮忙处理以上问题，并没有写明怎么处理，下面我们通过介绍几个命令来介绍下，以上问题通过Arthas怎么去定位处理。

Arthas快速入门

下载Arthas

curl -O https://arthas.aliyun.com/arthas-boot.jar

运行Arthas

java -jar arthas-boot.jar

运行该命令后 会显示java 进程，选择需要排查的进程。

我们运行以下测试代码来看看arthas的使用

package com.example.arthas;

public class ArthasTest {

    public static void main(String[] args) throws InterruptedException {
        while(true){
            put("test");
        }
    }

    private static String put(String name) throws InterruptedException {
        Thread.sleep(1000L);
        System.out.println(name);
        return "hello "+name;
    }
}

选择我们测试代码运行的进程[3]22756

[INFO] Found existing java process, please choose one and input the serial number of the process, eg : 1. Then hit ENTER.
* [1]: 1200 org.jetbrains.jps.cmdline.Launcher
  [2]: 9120
  [3]: 22756 com.example.arthas.ArthasTest

这个类从哪个 jar 包加载的？为什么会报各种类相关的 Exception？

通过sc命令查找类是哪个jar包加载的

[arthas@22756]$ sc -d com.example.arthas.ArthasTest
 class-info        com.example.arthas.ArthasTest
 code-source       /D:/ideaproject/jsoupservice/target/classes/
 name              com.example.arthas.ArthasTest
 isInterface       false
 isAnnotation      false
 isEnum            false
 isAnonymousClass  false
 isArray           false
 isLocalClass      false
 isMemberClass     false
 isPrimitive       false
 isSynthetic       false
 simple-name       ArthasTest
 modifier          public
 annotation
 interfaces
 super-class       +-java.lang.Object
 class-loader      +-sun.misc.Launcher$AppClassLoader@18b4aac2
                     +-sun.misc.Launcher$ExtClassLoader@593cfc78
 classLoaderHash   18b4aac2

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

其中code-source 信息表明类加载路径，如果是jar包中加载出来的 会显示jar包信息，如下

code-source  file:/home/trade/u3/u3-mnager/u-mnager-1.jar!/BOOT-INF/lib/uc-do-1.0-SNAPSHOT.jar!/

对于依赖冲突这类问题，我们可以通过该命令来进行排查。

我改的代码为什么没有执行到？难道是我没 commit？分支搞错了？

我们通过jad命令来反编译查看源码信息

[arthas@22756]$ jad com.example.arthas.ArthasTest

ClassLoader:
+-sun.misc.Launcher$AppClassLoader@18b4aac2
  +-sun.misc.Launcher$ExtClassLoader@593cfc78

Location:
/D:/ideaproject/jsoupservice/target/classes/

       /*
        * Decompiled with CFR.
        */
       package com.example.arthas;

       public class ArthasTest {
           public static void main(String[] args) throws InterruptedException {
               while (true) {
/* 7*/             ArthasTest.put("test");
               }
           }

           private static String put(String name) throws InterruptedException {
/*12*/         Thread.sleep(1000L);
/*13*/         System.out.println(name);
               return "hello " + name;
           }
       }

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

通过查看反编译代码确认是否运行的是提交后的代码。

遇到问题无法在线上 debug，难道只能通过加日志再重新发布吗？

watch 观察方法执行的入参和返回值

[arthas@22756]$ watch com.example.arthas.ArthasTest put '{params,returnObj}' -x 2 -n2
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 12 ms, listenerId: 3
method=com.example.arthas.ArthasTest.put location=AtExit
ts=2021-08-04 17:07:19; [cost=3.10595639883E7ms] result=@ArrayList[
    @Object[][
        @String[test],
    ],
    @String[hello test],
]
method=com.example.arthas.ArthasTest.put location=AtExit
ts=2021-08-04 17:07:20; [cost=1009.9733ms] result=@ArrayList[
    @Object[][
        @String[test],
    ],
    @String[hello test],
]

-x 输出结果属性遍历深度

-n 执行次数

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

结合jad、mc命令，通过jad反编译，通过编辑器修改源码,加入相关日志。mc命令来内存编译修改过的代码。

用retransform命令加载新的字节码。通过热加载将日志语句添加进去。

jad --source-only com.example.arthas.ArthasTest > D:/ArthasTest.java
mc d:/ArthasTest.java -d d:
retransform d:/com/example/arthas/ArthasTest.class

线上遇到某个用户的数据处理有问题，但线上同样无法 debug，线下无法重现！

此问题也可通过上面 watch 方法去观测线上 相关调用出入参。可以根据已知的调查结果给watch 方法加上对应的条件参数，以过滤掉不需要观测的请求。watch命令文档。

是否有一个全局视角来查看系统的运行状况？

dashboard实时数据面板命令,可以查看到线程、内存、系统参数等信息，具体的参数解释可以参考 dashboard文档

[arthas@17396]$ dashboard -n 1
ID   NAME                          GROUP          PRIORITY  STATE    %CPU      DELTA_TIM TIME      INTERRUPT DAEMON
-1   C1 CompilerThread3            -              -1        -        0.0       0.000     0:0.437   false     true
-1   C2 CompilerThread2            -              -1        -        0.0       0.000     0:0.375   false     true
1    main                          main           5         TIMED_WA 0.0       0.000     0:0.328   false     false
-1   C2 CompilerThread0            -              -1        -        0.0       0.000     0:0.312   false     true
-1   C2 CompilerThread1            -              -1        -        0.0       0.000     0:0.281   false     true
23   arthas-NettyHttpTelnetBootstr system         5         RUNNABLE 0.0       0.000     0:0.234   false     true
5    Attach Listener               system         5         RUNNABLE 0.0       0.000     0:0.031   false     true
-1   GC task thread#7 (ParallelGC) -              -1        -        0.0       0.000     0:0.031   false     true
-1   GC task thread#6 (ParallelGC) -              -1        -        0.0       0.000     0:0.031   false     true
-1   GC task thread#0 (ParallelGC) -              -1        -        0.0       0.000     0:0.031   false     true
-1   GC task thread#1 (ParallelGC) -              -1        -        0.0       0.000     0:0.031   false     true
-1   VM Thread                     -              -1        -        0.0       0.000     0:0.031   false     true
-1   GC task thread#2 (ParallelGC) -              -1        -        0.0       0.000     0:0.031   false     true
-1   GC task thread#3 (ParallelGC) -              -1        -        0.0       0.000     0:0.031   false     true
-1   GC task thread#5 (ParallelGC) -              -1        -        0.0       0.000     0:0.031   false     true
-1   GC task thread#4 (ParallelGC) -              -1        -        0.0       0.000     0:0.031   false     true
16   arthas-NettyHttpTelnetBootstr system         5         RUNNABLE 0.0       0.000     0:0.015   false     true
6    Monitor Ctrl-Break            main           5         RUNNABLE 0.0       0.000     0:0.015   false     true
2    Reference Handler             system         10        WAITING  0.0       0.000     0:0.000   false     true
3    Finalizer                     system         8         WAITING  0.0       0.000     0:0.000   false     true
4    Signal Dispatcher             system         9         RUNNABLE 0.0       0.000     0:0.000   false     true
13   arthas-timer                  system         5         WAITING  0.0       0.000     0:0.000   false     true
17   arthas-NettyWebsocketTtyBoots system         5         RUNNABLE 0.0       0.000     0:0.000   false     true
18   arthas-NettyWebsocketTtyBoots system         5         RUNNABLE 0.0       0.000     0:0.000   false     true
Memory                    used    total    max     usage    GC
heap                      26M     165M     3591M   0.75%    gc.ps_scavenge.count          2
ps_eden_space             8M      63M      1325M   0.67%    gc.ps_scavenge.time(ms)       16
ps_survivor_space         0K      10752K   10752K  0.00%    gc.ps_marksweep.count         1
ps_old_gen                17M     91M      2693M   0.67%    gc.ps_marksweep.time(ms)      41
nonheap                   29M     30M      -1      97.08%
code_cache                6M      6M       240M    2.57%
metaspace                 20M     21M      -1      97.06%
compressed_class_space    2M      2M       1024M   0.25%
direct                    0K      0K       -       0.00%
mapped                    0K      0K       -       0.00%
Runtime
os.name                                                     Windows 10
os.version                                                  10.0
java.version                                                1.8.0_291
java.home                                                   C:\Program Files\Java\jdk1.8.0_291\jre
systemload.average                                          -1.00
processors                                                  8
timestamp/uptime                                            Fri Aug 06 09:43:41 GMT+08:00 2021/326s

classloader 查看类加载器和其加载类数量.

[arthas@17396]$ classloader
 name                                       numberOfInstances  loadedCountTotal
 BootstrapClassLoader                       1                  2782
 com.taobao.arthas.agent.ArthasClassloader  1                  1373
 sun.misc.Launcher$ExtClassLoader           1                  60
 sun.reflect.DelegatingClassLoader          15                 15
 sun.misc.Launcher$AppClassLoader           1                  7
Affect(row-cnt:5) cost in 3 ms.

有什么办法可以监控到JVM的实时运行状态？

通过jvm 命令可以查看到jvm的实时运行状态。其中包含了机器信息、编译器信息、垃圾回收器、类加载信息、内存管理、线程相关信息、文件描述符相关信息。jvm命令文档

[arthas@17396]$ jvm
 RUNTIME
-----------------------------------------------------------------------------------------------------------------------
 MACHINE-NAME                      17396@WINDOWS-D2B420I
 JVM-START-TIME                    2021-08-06 09:38:14
 MANAGEMENT-SPEC-VERSION           1.2
 SPEC-NAME                         Java Virtual Machine Specification
 SPEC-VENDOR                       Oracle Corporation
 SPEC-VERSION                      1.8
 VM-NAME                           Java HotSpot(TM) 64-Bit Server VM
 VM-VENDOR                         Oracle Corporation
 VM-VERSION                        25.291-b10
 INPUT-ARGUMENTS                   -javaagent:D:\JetBrains\IntelliJ IDEA 2021.1\lib\idea_rt.jar=61057:D:\JetBrains\Int
                                   elliJ IDEA 2021.1\bin
                                   -Dfile.encoding=UTF-8

 CLASS-PATH                        C:\Program Files\Java\jdk1.8.0_291\jre\lib\charsets.jar;C:\Program Files\Java\jdk1.
                                   8.0_291\jre\lib\deploy.jar;C:\Program 
                                   ea_rt.jar
 BOOT-CLASS-PATH                   C:\Program Files\Java\jdk1.8.0_291\jre\lib\resources.jar;C:\Program Files\Java\jdk1
                                   .8.0_291\jre\lib\rt.jar;C:\Program 

-----------------------------------------------------------------------------------------------------------------------
 CLASS-LOADING
-----------------------------------------------------------------------------------------------------------------------
 LOADED-CLASS-COUNT                3914
 TOTAL-LOADED-CLASS-COUNT          3914
 UNLOADED-CLASS-COUNT              0
 IS-VERBOSE                        false

-----------------------------------------------------------------------------------------------------------------------
 COMPILATION
-----------------------------------------------------------------------------------------------------------------------
 NAME                              HotSpot 64-Bit Tiered Compilers
 TOTAL-COMPILE-TIME                1317
 [time (ms)]

-----------------------------------------------------------------------------------------------------------------------
 GARBAGE-COLLECTORS
-----------------------------------------------------------------------------------------------------------------------
 PS Scavenge                       name : PS Scavenge
 [count/time (ms)]                 collectionCount : 2
                                   collectionTime : 16

 PS MarkSweep                      name : PS MarkSweep
 [count/time (ms)]                 collectionCount : 1
                                   collectionTime : 41


-----------------------------------------------------------------------------------------------------------------------
 MEMORY-MANAGERS
-----------------------------------------------------------------------------------------------------------------------
 CodeCacheManager                  Code Cache

 Metaspace Manager                 Metaspace
                                   Compressed Class Space

 PS Scavenge                       PS Eden Space
                                   PS Survivor Space

 PS MarkSweep                      PS Eden Space
                                   PS Survivor Space
                                   PS Old Gen


-----------------------------------------------------------------------------------------------------------------------
 MEMORY
-----------------------------------------------------------------------------------------------------------------------
 HEAP-MEMORY-USAGE                 init : 266338304(254.0 MiB)
 [memory in bytes]                 used : 29895120(28.5 MiB)
                                   committed : 173015040(165.0 MiB)
                                   max : 3765960704(3.5 GiB)

 NO-HEAP-MEMORY-USAGE              init : 2555904(2.4 MiB)
 [memory in bytes]                 used : 31363048(29.9 MiB)
                                   committed : 32161792(30.7 MiB)
                                   max : -1(-1 B)

 PENDING-FINALIZE-COUNT            0

-----------------------------------------------------------------------------------------------------------------------
 OPERATING-SYSTEM
-----------------------------------------------------------------------------------------------------------------------
 OS                                Windows 10
 ARCH                              amd64
 PROCESSORS-COUNT                  8
 LOAD-AVERAGE                      -1.0
 VERSION                           10.0

-----------------------------------------------------------------------------------------------------------------------
 THREAD
-----------------------------------------------------------------------------------------------------------------------
 COUNT                             15
 DAEMON-COUNT                      14
 PEAK-COUNT                        16
 STARTED-COUNT                     21
 DEADLOCK-COUNT                    0

-----------------------------------------------------------------------------------------------------------------------
 FILE-DESCRIPTOR
-----------------------------------------------------------------------------------------------------------------------
 MAX-FILE-DESCRIPTOR-COUNT         -1
 OPEN-FILE-DESCRIPTOR-COUNT        -1

怎么快速定位应用的热点，生成火焰图？

profiler 命令支持生成应用热点的火焰图。本质上是通过不断的采样，然后把收集到的采样结果生成火焰图(该命令只支持linux/mac)。

$ profiler start
Started [cpu] profiling
$ profiler status
[cpu] profiling is running for 4 seconds
$ profiler stop
profiler output file: /tmp/demo/arthas-output/20191125-135546.svg
OK

默认情况下，arthas使用3658端口，则可以打开： http://localhost:3658/arthas-output/ 查看到 arthas-output目录下面的profiler结果：

_images/arthas-output.jpg

点击可以查看具体的结果：

_images/arthas-output-svg.jpg

怎样直接从JVM内查找某个类的实例？

vmtool 利用 JVMTI接口，实现查询内存对象，强制GC等功能。

[arthas@17396]$ vmtool -action getInstances --className java.lang.String --limit 10
@String[][
    @String[sun/nio/ch/FileDispatcherImpl],
    @String[sun/nio/ch/FileDispatcherImpl],
    @String[sun/nio/ch/FileDispatcher],
    @String[sun/nio/ch/FileDispatcher],
    @String[sun/nio/ch/FileDispatcher],
    @String[direct],
    @String[sun/nio/ch/FileChannelImpl$Unmapper],
    @String[sun/nio/ch/FileChannelImpl$Unmapper],
    @String[sun/nio/ch/FileChannelImpl$Unmapper],
    @String[sun/nio/ch/FileDispatcherImpl],
]

通过 --limit参数，可以限制返回值数量，避免获取超大数据时对JVM造成压力。默认值是10。

怎样定位慢调用方法。

trace 展示方法内部调用路径，并输出方法路径上的每个节点上耗时

[arthas@18584]$ trace com.example.arthas.ArthasTest bridge
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 137 ms, listenerId: 1
`---ts=2021-08-06 10:30:11;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@18b4aac2
    `---[1011.4579ms] com.example.arthas.ArthasTest:bridge()
        `---[1009.9123ms] com.example.arthas.ArthasTest:put() #13

`---ts=2021-08-06 10:30:12;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@18b4aac2
    `---[1002.9228ms] com.example.arthas.ArthasTest:bridge()
        `---[1002.8016ms] com.example.arthas.ArthasTest:put() #13

从以上信息钟可以看到 bridge方法调用1011.4579ms 其中1009.9123ms是在调用put方法，那我们重点就可以对put方法进行分析，如有必要也可以对put方法进行trace命令追踪。

以上结合了自己的理解，使用arthas命令排查之前提出的问题，arthas提供了丰富的命令功能，想要了解更多的使用方式，请参考命令列表

参考文档

Arthas用户文档

avatar
文章
阅读
粉丝
相关推荐
Java诊断利器Arthas
6.0k阅读
 · 
54点赞
玩转Arthas
1.1k阅读
 · 
6点赞
Java 监控工具Arthas
2.0k阅读
 · 
14点赞
诊断神器Xrebel和Arthas
936阅读
 · 
1点赞
爱上Java诊断利器之Arthas
4.2k阅读
 · 
29点赞
我所理解的Arthas
2.8k阅读
 · 
2点赞
阿里人都在使用的在线诊断工具—Arthas
3.0k阅读
 · 
11点赞
使用arthas trace命令查看代码各方法响应时间
9.6k阅读
 · 
9点赞
记一次线上故障的排查过程
15k阅读
 · 
18点赞

友情链接：