AI 助理
备案控制台
开发者社区 开发与运维 文章 正文

一文带你快速了解 Java 线上问题快速诊断神器 Arthas

2024-06-03 285
版权
版权声明：
本文内容由阿里云实名注册用户自发贡献，版权归原作者所有，阿里云开发者社区不拥有其著作权，亦不承担相应法律责任。具体规则请查看《 阿里云开发者社区用户服务协议》和 《阿里云开发者社区知识产权保护指引》。如果您发现本社区中有涉嫌抄袭的内容，填写 侵权投诉表单进行举报，一经查实，本社区将立刻删除涉嫌侵权内容。
本文涉及的产品
云数据库 RDS MySQL，集群系列 2核4GB
推荐场景：
搭建个人博客
RDS MySQL Serverless 基础系列，0.5-2RCU 50GB
推荐场景：
学生管理系统数据库设计 搭建个人博客
云数据库 RDS MySQL，高可用系列 2核4GB
简介： 【6月更文挑战第1天】一文带你快速了解 Java 线上问题快速诊断神器 Arthas

一、什么是 Arthas

Arthas 是 Alibaba开源的一款 Java 诊断工具，能够查看 Java 应用的线程状态、JVM 信息等，支持在线对业务问题诊断，比如查看方法调用的出入参、执行过程、抛出的异常、输出方法执行耗时等，大大提升了线上问题的排查效率。

官网：https://arthas.aliyun.com/zh-cn/

二、特性一览

image.png

三、Arthas 能为你做什么？

你遇到以下类似问题而束手无策时，Arthas可以帮助你解决：

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

Arthas 支持 JDK 6+，支持 Linux/Mac/Windows，采用命令行交互模式，同时提供丰富的 Tab 自动补全功能，进一步方便进行问题的定位和诊断。

四、快速安装

1、前提条件

[root@c41287379b7c /]# yum install telnet
[root@c41287379b7c /]# yum install unzip

2、一键安装

使用命令下载 Arthas 脚本：

[root@c41287379b7c /]# curl -L https://alibaba.github.io/arthas/install.sh | sh
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100   961  100   961    0     0    743      0  0:00:01  0:00:01 --:--:--   743
downloading... ./as.sh.1598
Arthas install successed.

使用命令下载 Arthas jar包：

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

​
Arthas 提供是 jar 包形式，其本质是个 Java 应用。
​

五、快速使用

1、启动脚本并连接进程

使用脚本快速启动：

[root@c41287379b7c /]# ./as.sh
Arthas script version: 3.1.7
[INFO] JAVA_HOME: /usr/jdk1.8.0_111
Found existing java process, please choose one and hit RETURN.
* [1]: 1 org.apache.catalina.startup.Bootstrap
1      //这里输入1就是连接进程，如果有多个java进程，将在这里出现一个list，输入序号即可连接进程。
updating version 3.1.7 ...
Download arthas from: https://repo1.maven.org/maven2/com/taobao/arthas/arthas-packaging/3.1.7/arthas-packaging-3.1.7-bin.zip
######################################################################## 100.0%
Archive:  /tmp/temp_3.1.7_1673/arthas-3.1.7-bin.zip
   creating: /tmp/temp_3.1.7_1673/async-profiler/
  inflating: /tmp/temp_3.1.7_1673/arthas-spy.jar
  inflating: /tmp/temp_3.1.7_1673/arthas-agent.jar
  inflating: /tmp/temp_3.1.7_1673/arthas-client.jar
  inflating: /tmp/temp_3.1.7_1673/arthas-boot.jar
  inflating: /tmp/temp_3.1.7_1673/arthas-demo.jar
  inflating: /tmp/temp_3.1.7_1673/install-local.sh
  inflating: /tmp/temp_3.1.7_1673/as.sh
  inflating: /tmp/temp_3.1.7_1673/as.bat
  inflating: /tmp/temp_3.1.7_1673/as-service.bat
  inflating: /tmp/temp_3.1.7_1673/async-profiler/libasyncProfiler-linux-x64.so
  inflating: /tmp/temp_3.1.7_1673/async-profiler/libasyncProfiler-mac-x64.so
  inflating: /tmp/temp_3.1.7_1673/arthas-core.jar
update completed.
Arthas home: /root/.arthas/lib/3.1.7/arthas
Calculating attach execution time...
Attaching to 1 using version /root/.arthas/lib/3.1.7/arthas...

real    0m2.298s
user    0m0.302s
sys    0m0.145s
Attach success.
telnet connecting to arthas server... current timestamp is 1583537651
Trying 127.0.0.1...
Connected to 127.0.0.1.
Escape character is '^]'.
  ,---.  ,------. ,--------.,--.  ,--.  ,---.   ,---.
 /  O  \ |  .--. ''--.  .--'|  '--'  | /  O  \ '   .-'
|  .-.  ||  '--'.'   |  |   |  .--.  ||  .-.  |`.  `-.
|  | |  ||  |\  \    |  |   |  |  |  ||  | |  |.-'    |
`--' `--'`--' '--'   `--'   `--'  `--'`--' `--'`-----'


wiki      https://alibaba.github.io/arthas
tutorials https://alibaba.github.io/arthas/arthas-tutorials
version   3.1.7
pid       1
time      2020-03-06 23:34:10

[arthas@1]$

2、启动 jar 包并连接进程

执行该程序的用户需要和目标进程具有相同的权限。

比如以 admin用户来执行：

sudo su admin && java -jar arthas-boot.jar
或 
sudo -u admin -EH java -jar arthas-boot.jar

如果attach不上目标进程，可以查看 ~/logs/arthas/ 目录下的日志。

如果下载速度比较慢，可以使用aliyun的镜像：

java -jar arthas-boot.jar --repo-mirror aliyun --use-http

java -jar arthas-boot.jar -h #打印更多参数信息。

选择应用java进程：

$ $ java -jar arthas-boot.jar
* [1]: 35542
  [2]: 71560 math-game.jar

math-game 进程是第2个，则输入2，再输入回车 /enter。Arthas 会 attach 到目标进程上，并输出日志：

[INFO] Try to attach process 71560
[INFO] Attach process 71560 success.
[INFO] arthas-client connect 127.0.0.1 3658
  ,---.  ,------. ,--------.,--.  ,--.  ,---.   ,---.
 /  O  \ |  .--. ''--.  .--'|  '--'  | /  O  \ '   .-'
|  .-.  ||  '--'.'   |  |   |  .--.  ||  .-.  |`.  `-.
|  | |  ||  |\  \    |  |   |  |  |  ||  | |  |.-'    |
`--' `--'`--' '--'   `--'   `--'  `--'`--' `--'`-----'

wiki: https://arthas.aliyun.com/doc
version: 3.0.5.20181127201536
pid: 71560
time: 2020-11-28 19:16:24

$

出现 Arthas Logo 之后便可以正常使用了。

六、使用示例

1、dashboard（当前系统的实时数据面板）

ID          NAME                              GROUP                   PRIORITY   STATE       %CPU       TIME        INTERRUPTE DAEMON
1572        http-nio-8080-exec-139            main                    5          TIMED_WAITI 18         0:12        false      true
1561        http-nio-8080-exec-138            main                    5          RUNNABLE    17         0:18        false      true
1539        http-nio-8080-exec-131            main                    5          TIMED_WAITI 10         1:17        false      true
1575        http-nio-8080-exec-141            main                    5          TIMED_WAITI 10         0:0         false      true
1573        http-nio-8080-exec-140            main                    5          TIMED_WAITI 9          0:8         false      true
1559        http-nio-8080-exec-136            main                    5          TIMED_WAITI 8          0:29        false      true
1558        grpc-default-executor-1340        main                    5          TIMED_WAITI 4          0:5         false      true
28          grpc-default-worker-ELG-1-4       main                    5          RUNNABLE    4          6:44        false      true
1560        http-nio-8080-exec-137            main                    5          RUNNABLE    4          0:23        false      true
Memory                        used      total     max       usage     GC
heap                          155M      311M      843M      18.47%    gc.ps_scavenge.count               6631
ps_eden_space                 39M       171M      310M      12.72%    gc.ps_scavenge.time(ms)            52792
ps_survivor_space             1M        2M        2M        90.63%    gc.ps_marksweep.count              21
ps_old_gen                    114M      138M      632M      18.10%    gc.ps_marksweep.time(ms)           11572
Runtime
os.name                                                               Linux
os.version                                                            3.10.0-1062.9.1.el7.x86_64
java.version                                                          1.8.0_111
java.home                                                             /usr/jdk1.8.0_111/jre

2、sysprop（查看或修改java属性）

//查看所有属性
[arthas@1]$ sysprop
 KEY                        VALUE
---------------------------------------------------------------------------------------------------------------------------------------
 java.vendor                Oracle Corporation
 sun.java.launcher          SUN_STANDARD
 catalina.base              /apache-tomcat-8.5.9
 sun.management.compiler    HotSpot 64-Bit Tiered Compilers
......
 java.specification.versio  1.8
 n

[arthas@1]$
//查看特定属性
[arthas@1]$ sysprop java.rmi.server.hostname
java.rmi.server.hostname=106.54.17.234
[arthas@1]$ sysprop file.encoding
file.encoding=ANSI_X3.4-1968
[arthas@1]$
//修改属性
[arthas@1]$ sysprop user.country
user.country=US
[arthas@1]$ sysprop user.country CN
Successfully changed the system property.
user.country=CN

3、mbean（实时查看Mbean信息）

参数-i 1000是指定1秒刷新一次。

[arthas@1]$ mbean -i 1000 java.lang:type=Threading *Count
 NAME                     VALUE
--------------------------------
 PeakThreadCount          61
 DaemonThreadCount        51
 ThreadCount              59
 TotalStartedThreadCount  1586

4、thread（查看线程）

//查看所有线程
[arthas@1]$ thread
Threads Total: 59, NEW: 0, RUNNABLE: 24, BLOCKED: 0, WAITING: 9, TIMED_WAITING: 26, TERMINATED: 0
ID      NAME                    GROUP            PRIORIT STATE   %CPU    TIME    INTERRU DAEMON
1572    http-nio-8080-exec-139  main             5       TIMED_W 17      1:32    false   true
1597    http-nio-8080-exec-151  main             5       RUNNABL 15      0:10    false   true
1539    http-nio-8080-exec-131  main             5       TIMED_W 11      2:37    false   true
1591    http-nio-8080-exec-148  main             5       RUNNABL 11      0:23    false   true
1587    http-nio-8080-exec-146  main             5       TIMED_W 9       0:33    false   true
1585    grpc-default-executor-1 main             5       TIMED_W 5       0:9     false   true
......
Affect(row-cnt:0) cost in 106 ms.
[arthas@1]$

从上面查看所有的 threads 来看 1572 消耗CPU 17%（此百分比是按单 CPU 计算的）。所以需要查看这个线程在做什么。

//查看指定线程栈信息
[arthas@1]$ thread 1572
"http-nio-8080-exec-139" Id=1572 RUNNABLE
    at java.net.SocketInputStream.socketRead0(Native Method)
    at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
    at java.net.SocketInputStream.read(SocketInputStream.java:170)
    at java.net.SocketInputStream.read(SocketInputStream.java:141)
    at com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:100)
    at com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:143)
    at com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:173)
    -  locked com.mysql.jdbc.util.ReadAheadInputStream@afb14dd
    at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:2954)
    at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3375)
    at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3365)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3805)
    at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2478)
    at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2625)
    at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2551)
    -  locked com.mysql.jdbc.JDBC4Connection@21123f41
    at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1861)
    -  locked com.mysql.jdbc.JDBC4Connection@21123f41
    at com.mysql.jdbc.PreparedStatement.execute$original$vADsw8UZ(PreparedStatement.java:1192)
    -  locked com.mysql.jdbc.JDBC4Connection@21123f41
    at com.mysql.jdbc.PreparedStatement.execute$original$vADsw8UZ$accessor$md9IHdH2(PreparedStatement.java)
 ......
    Number of locked synchronizers = 1
    - java.util.concurrent.ThreadPoolExecutor$Worker@31355af3

Affect(row-cnt:0) cost in 152 ms.
[arthas@1]$

5、thread -n(查看占CPU前几的线程栈信息)

查看占 CPU 前 3 的线程栈，间隔 1 秒。

[arthas@1]$ thread -n 3 -i 1000
"http-nio-8080-exec-153" Id=1604 cpuUsage=31% RUNNABLE
    at java.lang.Throwable.fillInStackTrace(Native Method)
    at java.lang.Throwable.fillInStackTrace(Throwable.java:783)
    -  locked java.lang.NoSuchMethodException@41cb2ff9
    at java.lang.Throwable.<init>(Throwable.java:265)
    at java.lang.Exception.<init>(Exception.java:66)
    ......
    Number of locked synchronizers = 1
    - java.util.concurrent.ThreadPoolExecutor$Worker@35ddf68a


"http-nio-8080-exec-150" Id=1595 cpuUsage=27% TIMED_WAITING on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@3fb3dff3
    at sun.misc.Unsafe.park(Native Method)
    -  waiting on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@3fb3dff3
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
    at java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
    at org.apache.tomcat.util.threads.TaskQueue.poll(TaskQueue.java:85)
    at org.apache.tomcat.util.threads.TaskQueue.poll(TaskQueue.java:31)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Thread.java:745)


"http-nio-8080-exec-147" Id=1589 cpuUsage=19% RUNNABLE
    at java.net.SocketInputStream.socketRead0(Native Method)
    at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
    at java.net.SocketInputStream.read(SocketInputStream.java:170)
    at java.net.SocketInputStream.read(SocketInputStream.java:141)
    at com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:100)
    at com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:143)
    at com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:173)
    -  locked com.mysql.jdbc.util.ReadAheadInputStream@afb14dd
    ......

    Number of locked synchronizers = 1
    - java.util.concurrent.ThreadPoolExecutor$Worker@5a014dec


Affect(row-cnt:0) cost in 1140 ms.
[arthas@1]$

6、jad（反编译代码）

[arthas@1]$ jad com.7dgroup.blog.controller.BackBlogController

ClassLoader:
+-ParallelWebappClassLoader
    context: ROOT
    delegate: false
  ----------> Parent Classloader:
  java.net.URLClassLoader@22d7b4f8

  +-java.net.URLClassLoader@22d7b4f8
    +-sun.misc.Launcher$AppClassLoader@18b4aac2
      +-sun.misc.Launcher$ExtClassLoader@5f4fff0

Location:
/apache-tomcat-8.5.9/webapps/ROOT/WEB-INF/classes/

/*
 * Decompiled with CFR.
 *
 * Could not load the following classes:
 *  com.7dgroup.blog.common.exception.JsonResponseException
 ......
 */
package com.7dgroup.blog.controller;

import com.7dgroup.blog.common.exception.JsonResponseException;
import com.7dgroup.blog.common.model.Page;
import com.7dgroup.blog.common.model.Response;
import com.7dgroup.blog.controller.BackBlogController;
import com.7dgroup.blog.model.Blog;
import com.7dgroup.blog.model.User;
import com.7dgroup.blog.service.BlogReadService;
import com.7dgroup.blog.service.BlogWriteService;
import com.7dgroup.blog.service.CategoryService;
import com.7dgroup.blog.vo.BlogQuery;
import java.lang.reflect.Method;
import java.util.Date;
import java.util.List;
import java.util.concurrent.Callable;
import javax.servlet.http.HttpSession;
import org.apache.skywalking.apm.agent.core.plugin.interceptor.enhance.ConstructorInter;
import org.apache.skywalking.apm.agent.core.plugin.interceptor.enhance.EnhancedInstance;
import org.apache.skywalking.apm.agent.core.plugin.interceptor.enhance.InstMethodsInter;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.stereotype.Controller;
import org.springframework.ui.Model;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RequestParam;
import org.springframework.web.bind.annotation.ResponseBody;

@Controller
@RequestMapping(value={
   "/back/blog"})
public class BackBlogController
implements EnhancedInstance,
EnhancedInstance {
   
    @Autowired
    BlogReadService blogReadService;
    @Autowired
    BlogWriteService blogWriteService;
    @Autowired
    CategoryService categoryService;
    private volatile Object _$EnhancedClassField_ws;
    public static volatile /* synthetic */ InstMethodsInter delegate$3vsfol1;
    public static volatile /* synthetic */ InstMethodsInter delegate$s214mp1;
    public static volatile /* synthetic */ ConstructorInter delegate$1726vl1;
    private static final /* synthetic */ Method cachedValue$fhzPhYBQ$0j0d661;
    private static final /* synthetic */ Method cachedValue$fhzPhYBQ$7jqr912;
    private static final /* synthetic */ Method cachedValue$fhzPhYBQ$k1ffbv0;
    private static final /* synthetic */ Method cachedValue$fhzPhYBQ$50tnsu0;
    public static volatile /* synthetic */ InstMethodsInter delegate$l07kai0;
    public static volatile /* synthetic */ InstMethodsInter delegate$b310fa0;
    public static volatile /* synthetic */ ConstructorInter delegate$51jjf90;
    private static final /* synthetic */ Method cachedValue$CYumwYK8$0j0d661;
    private static final /* synthetic */ Method cachedValue$CYumwYK8$7jqr912;
    private static final /* synthetic */ Method cachedValue$CYumwYK8$k1ffbv0;
    private static final /* synthetic */ Method cachedValue$CYumwYK8$50tnsu0;

    public BackBlogController() {
   
        this(null);
        delegate$51jjf90.intercept(this, new Object[0]);
    }

    private /* synthetic */ BackBlogController(auxiliary.xIr7AqvV xIr7AqvV2) {
   
    }

    @RequestMapping(value={
   ""})
    public String page(Model model, Page<Blog> page, BlogQuery blogQuery, HttpSession httpSession) {
   
        return (String)delegate$b310fa0.intercept(this, new Object[]{
   model, page, blogQuery, httpSession}, (Callable<?>)new auxiliary.ADTaVnew(this, model, page, blogQuery, httpSession), cachedValue$CYumwYK8$7jqr912);
    }

   ......

    final /* synthetic */ Object delete$original$PYp487Vn$accessor$CYumwYK8(Long l) {
   
        return this.delete$original$PYp487Vn(l);
    }
}

Affect(row-cnt:9) cost in 1594 ms.
[arthas@1]$

7、sc（查看已经加载的类）

[arthas@1]$ sc -d com.jt.blog.controller.BackBlogController
 class-info        com.jt.blog.controller.BackBlogController
 code-source       /apache-tomcat-8.5.9/webapps/ROOT/WEB-INF/classes/
 name              com.jt.blog.controller.BackBlogController
 isInterface       false
 isAnnotation      false
 isEnum            false
 isAnonymousClass  false
 isArray           false
 isLocalClass      false
 isMemberClass     false
 isPrimitive       false
 isSynthetic       false
 simple-name       BackBlogController
 modifier          public
 ......
 classLoaderHash   15101d33

Affect(row-cnt:2) cost in 48 ms.
[arthas@1]$

8、sm（列出某个类加载的方法）

[arthas@1]$ sm com.jt.blog.controller.BackBlogController
com.jt.blog.controller.BackBlogController{
   mathJaxContainer[0]}d6e1bd41 <init>()V
com.jt.blog.controller.BackBlogController{
   mathJaxContainer[1]}d6e1bd41 page(Lorg/springframework/ui/Model;Lcom/jt/blog/common/model/Page;Lcom/jt/blog/vo/BlogQuery;Ljavax/servlet/http/HttpSession;)Ljava/lang/String;
......
Affect(row-cnt:73) cost in 17 ms.
[arthas@1]$

9、trace（跟踪方法的消耗时间）

我们可以使用 trace 命令来查找最耗时的方法，在此过程中需要知道包名、类名，以及方法的名字。

[arthas@1]$ trace com.jt.blog.controller.BackBlogController{
   mathJaxContainer[2]}d6e1bd41 page
Press Q or Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 235 ms.
`---ts=2020-03-07 00:40:01;thread_name=http-nio-8080-exec-167;id=662;is_daemon=true;priority=5;TCCL=org.apache.catalina.loader.ParallelWebappClassLoader@15101d33
    `---[91.777786ms] com.jt.blog.controller.BackBlogController{
   mathJaxContainer[3]}d6e1bd41:page()
        `---[91.101545ms] org.springframework.cglib.proxy.MethodInterceptor:intercept() #0

`---ts=2020-03-07 00:40:02;thread_name=http-nio-8080-exec-166;id=661;is_daemon=true;priority=5;TCCL=org.apache.catalina.loader.ParallelWebappClassLoader@15101d33
    `---[58.901494ms] com.jt.blog.controller.BackBlogController{
   mathJaxContainer[4]}d6e1bd41:page()
        `---[58.727281ms] org.springframework.cglib.proxy.MethodInterceptor:intercept() #0

`---ts=2020-03-07 00:40:02;thread_name=http-nio-8080-exec-150;id=63b;is_daemon=true;priority=5;TCCL=org.apache.catalina.loader.ParallelWebappClassLoader@15101d33
    `---[93.064632ms] com.jt.blog.controller.BackBlogController{
   mathJaxContainer[5]}d6e1bd41:page()
        `---[92.902346ms] org.springframework.cglib.proxy.MethodInterceptor:intercept() #0
......


[arthas@1]$ trace tk.mybatis.mapper.common.Mapper insert
Press Q or Ctrl+C to abort.
Affect(class-cnt:5 , method-cnt:5) cost in 538 ms.
`---ts=2020-03-07 00:59:22;thread_name=http-nio-8080-exec-172;id=671;is_daemon=true;priority=5;TCCL=org.apache.catalina.loader.ParallelWebappClassLoader@15101d33
    `---[2.938966ms] com.sun.proxy.$Proxy90:insert()

`---ts=2020-03-07 00:59:22;thread_name=http-nio-8080-exec-172;id=671;is_daemon=true;priority=5;TCCL=org.apache.catalina.loader.ParallelWebappClassLoader@15101d33
    `---[0.895433ms] com.sun.proxy.$Proxy93:insert()

`---ts=2020-03-07 00:59:24;thread_name=http-nio-8080-exec-150;id=63b;is_daemon=true;priority=5;TCCL=org.apache.catalina.loader.ParallelWebappClassLoader@15101d33
    `---[2.156481ms] com.sun.proxy.$Proxy90:insert()

[arthas@1]$ trace com.jt.blog.service.BlogReadServiceImpl page
Press Q or Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 371 ms.
`---ts=2020-03-07 01:04:44;thread_name=http-nio-8080-exec-6;id=32;is_daemon=true;priority=5;TCCL=org.apache.catalina.loader.ParallelWebappClassLoader@3d0c8d44
    `---[75.94035ms] com.jt.blog.service.BlogReadServiceImpl:page()
        +---[0.034707ms] com.jt.blog.common.model.Response:<init>() #34
        +---[0.019337ms] com.jt.blog.common.model.Page:getPageNo() #36
        +---[0.01106ms] com.jt.blog.common.model.Page:getPageSize() #36
        +---[4.590002ms] com.github.pagehelper.PageHelper:startPage() #36
        +---[0.542359ms] tk.mybatis.mapper.entity.Example:<init>() #37
        +---[0.070315ms] tk.mybatis.mapper.entity.Example:createCriteria() #38
        +---[0.037231ms] com.jt.blog.vo.BlogQuery:getCategoryId() #40
        +---[0.007289ms] com.jt.blog.vo.BlogQuery:getBeginTime() #43
        +---[0.007167ms] com.jt.blog.vo.BlogQuery:getPersonal() #46
        +---[0.006318ms] com.jt.blog.vo.BlogQuery:getPersonal() #47
        +---[0.009675ms] tk.mybatis.mapper.entity.Example$Criteria:andEqualTo() #47
        +---[30.90447ms] tk.mybatis.mapper.common.Mapper:selectByExample() #50
        +---[36.179664ms] com.jt.blog.service.BlogReadServiceImpl:wrapBlogStatistics() #51 [throws Exception]
        +---[0.785948ms] com.google.common.base.Throwables:getStackTraceAsString() #58
        +---[0.522234ms] org.slf4j.Logger:error() #58
        `---[0.030388ms] com.jt.blog.common.model.Response:setError() #59

`---ts=2020-03-07 01:04:44;thread_name=http-nio-8080-exec-10;id=3c;is_daemon=true;priority=5;TCCL=org.apache.catalina.loader.ParallelWebappClassLoader@3d0c8d44
    `---[94.699363ms] com.jt.blog.service.BlogReadServiceImpl:page()
        +---[0.009802ms] com.jt.blog.common.model.Response:<init>() #34
        +---[0.007825ms] com.jt.blog.common.model.Page:getPageNo() #36
    ......

我们可以看到 page方法总耗时 75.94035 ms：

  • selectByExample 调用耗时 30.90447 ms；
  • wrapBlogStatistics 调用耗时 36.179664 ms；
  • startPage 调用耗时 4.590002 ms。

selectByExample 和 wrapBlogStatistics 方法耗时比较长，能够定位到方法级别的消耗时长时，就找到慢的原因了。

10、stack （查看某方法的调用栈）

[arthas@1]$ stack tk.mybatis.mapper.common.Mapper insert
Press Q or Ctrl+C to abort.
Affect(class-cnt:5 , method-cnt:5) cost in 561 ms.
ts=2020-03-07 01:00:51;thread_name=http-nio-8080-exec-171;id=66f;is_daemon=true;priority=5;TCCL=org.apache.catalina.loader.ParallelWebappClassLoader@15101d33
    @com.jt.blog.service.BlogWriteServiceImpl.create()
        at sun.reflect.GeneratedMethodAccessor255.invoke(null:-1)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:302)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
        ......

ts=2020-03-07 01:00:51;thread_name=http-nio-8080-exec-171;id=66f;is_daemon=true;priority=5;TCCL=org.apache.catalina.loader.ParallelWebappClassLoader@15101d33
    @com.jt.blog.service.BlogWriteServiceImpl.create()
        at sun.reflect.GeneratedMethodAccessor255.invoke(null:-1)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        ......

[arthas@1]$

11、classloader（查看classloader的继承树，urls，类加载信息）

[arthas@1]$ classloader
 name                                                                 numberOfInstances  loadedCountTotal
 org.apache.catalina.loader.ParallelWebappClassLoader                 2                  6680
 BootstrapClassLoader                                                 1                  3836
 sun.misc.Launcher$AppClassLoader                                     1                  3029
 com.taobao.arthas.agent.ArthasClassloader                            1                  1194
 java.net.URLClassLoader                                              1                  860
 org.apache.skywalking.apm.agent.core.plugin.loader.AgentClassLoader  3                  306
 sun.reflect.DelegatingClassLoader                                    289                289
 sun.misc.Launcher$ExtClassLoader                                     1                  13
 javax.management.remote.rmi.NoCallStackClassLoader                   2                  2
Affect(row-cnt:9) cost in 36 ms.
[arthas@1]$

12、monitor （监控方法）

[arthas@1]$ monitor -h
 USAGE:
   monitor [-c <value>] [-h] [-n <value>] [-E <value>] class-pattern method-pattern

 SUMMARY:
   Monitor method execution statistics, e.g. total/success/failure count, average rt, fail rate, etc.

 Examples:
   monitor org.apache.commons.lang.StringUtils isBlank
   monitor org.apache.commons.lang.StringUtils isBlank -c 5
   monitor -E org\.apache\.commons\.lang\.StringUtils isBlank

 WIKI:
   https://alibaba.github.io/arthas/monitor

 OPTIONS:
 -c, --cycle <value>                          The monitor interval (in seconds), 60 seconds by default
 -h, --help                                   this help
 -n, --limits <value>                         Threshold of execution times
 -E, --regex <value>                          Enable regular expression to match (wildcard matching by default)
 <class-pattern>                              Path and classname of Pattern Matching
 <method-pattern>                             Method of Pattern Matching

[arthas@1]$

示例：

[arthas@1]$ monitor tk.mybatis.mapper.common.Mapper insert
Press Q or Ctrl+C to abort.
Affect(class-cnt:5 , method-cnt:5) cost in 411 ms.
 timestamp            class                   method  total  success  fail  avg-rt(ms)  fail-rat
                                                                                        e
-------------------------------------------------------------------------------------------------
 2020-03-07 01:11:38  com.sun.proxy.$Proxy93  insert  197    197      0     1.67        0.00%
 2020-03-07 01:11:38  com.sun.proxy.$Proxy90  insert  197    197      0     3.39        0.00%

七、总结

在本文我主要介绍了 Arthas 是什么、为什么使用 Arthas，以及通过实际操作演示 Arthas 常用命令是如何使用的的，操作实例都是比较典型的排查线上问题的方式，通过实例的演示也能看出来 Arthas 的强大和便捷性。

文章标签：
应用实时监控服务
云数据库 RDS MySQL 版
测试技术
Arthas
Java
监控
Linux
关键词：
Java Arthas
Java诊断
Java线上问题arthas
arthas诊断
Java诊断arthas
相关实践学习
通过云拨测对指定服务器进行Ping/DNS监测
本实验将通过云拨测对指定服务器进行Ping/DNS监测，评估网站服务质量和用户体验。
zuozewei
目录
相关文章
程序三两行
|
6月前
|
Arthas 监控 Java
Java 诊断利器 Arthas使用
Java 诊断利器 Arthas使用
程序三两行
213 0
qhhf_地道酬勤
|
2月前
|
Arthas Java 测试技术
Java字节码文件、组成，jclasslib插件、阿里arthas工具，Java注解
Java字节码文件、组成、详解、分析；常用工具，jclasslib插件、阿里arthas工具；如何定位线上问题；Java注解
qhhf_地道酬勤
75 5
Java字节码文件、组成，jclasslib插件、阿里arthas工具，Java注解
请看我回答~
|
3月前
|
机器学习/深度学习 人工智能 算法
探索人工智能在医疗诊断中的应用与挑战Java编程中的对象和类：基础与实践
【8月更文挑战第27天】随着人工智能（AI）技术的飞速发展，其在医疗领域的应用日益广泛。本文深入探讨了AI技术在医疗诊断中的具体应用案例，包括图像识别、疾病预测和药物研发等方面，并分析了当前面临的主要挑战，如数据隐私、算法偏见和法规限制等。文章旨在为读者提供一个全面的视角，理解AI在改善医疗服务质量方面的潜力及其局限性。
请看我回答~
50 2
杰哥在此
|
4月前
|
监控 Java 数据库连接
Java面试题：如何诊断和解决Java应用的内存泄漏问题？
Java面试题：如何诊断和解决Java应用的内存泄漏问题？
杰哥在此
53 2
杰哥在此
|
4月前
|
存储 算法 安全
Java面试题：给定一个可能产生内存泄漏的场景，如何诊断并解决？实现一个生产者-消费者模型，使用适当的同步机制与并发工具类，Java并发工具包与框架：性能与调优
Java面试题：给定一个可能产生内存泄漏的场景，如何诊断并解决？实现一个生产者-消费者模型，使用适当的同步机制与并发工具类，Java并发工具包与框架：性能与调优
杰哥在此
34 0
杰哥在此
|
4月前
|
安全 算法 Java
Java面试题：如何诊断和解决Java应用程序中的内存泄漏问题？如何实现一个线程安全的计数器？如何合理配置线程池以应对不同的业务场景？
Java面试题：如何诊断和解决Java应用程序中的内存泄漏问题？如何实现一个线程安全的计数器？如何合理配置线程池以应对不同的业务场景？
杰哥在此
33 0
威哥爱编程
|
6月前
|
Arthas 监控 IDE
去哪儿网开源的一个对应用透明，无侵入的Java应用诊断工具
今天 V 哥给大家带来一款开源工具Bistoury，Bistoury 是去哪儿网开源的一个对应用透明，无侵入的java应用诊断工具，用于提升开发人员的诊断效率和能力。
威哥爱编程
66 0
jworldexpo
|
Arthas 监控 Java
基于arthas排查Java内存问题
基于arthas排查Java内存问题，准确快速定位线上问题
jworldexpo
1001 0
基于arthas排查Java内存问题
运营研究坊
|
8天前
|
安全 Java 测试技术
Java并行流陷阱：为什么指定线程池可能是个坏主意
本文探讨了Java并行流的使用陷阱，尤其是指定线程池的问题。文章分析了并行流的设计思想，指出了指定线程池的弊端，并提供了使用CompletableFuture等替代方案。同时，介绍了Parallel Collector库在处理阻塞任务时的优势和特点。
运营研究坊
32 2
众所周知
|
4天前
|
安全 Java 开发者
深入解读JAVA多线程：wait()、notify()、notifyAll()的奥秘
在Java多线程编程中，`wait()`、`notify()`和`notifyAll()`方法是实现线程间通信和同步的关键机制。这些方法定义在`java.lang.Object`类中，每个Java对象都可以作为线程间通信的媒介。本文将详细解析这三个方法的使用方法和最佳实践，帮助开发者更高效地进行多线程编程。 示例代码展示了如何在同步方法中使用这些方法，确保线程安全和高效的通信。
众所周知
21 9

热门文章

最新文章

  • 1
    java Redis工具类
  • 2
    Java杂记9—NIO
  • 3
    Java——基于java自身包实现消息系统间的通信（TCP/IP+BIO）
  • 4
    java8 List根据对象中属性去重-多属性去重-去除重复字符串
  • 5
    Java接口签名(Signature)实现方案
  • 6
    Java的几种创建实例方法的性能对比
  • 7
    16.2. jps - Java Virtual Machine Process Status Tool
  • 8
    Java多线程初学者指南（9）：为什么要进行数据同步
  • 9
    Java 动态写轮眼 SharinganJPanel (整理)
  • 10
    Java项目导出源代码jar包在Eclipse中查看中文注释乱码的问题
  • 1
    Arthas之动态加载类（retransform）
    295
  • 2
    Arthas查看已加载类的源码（jad）
    231
  • 3
    Arthas下载与启动
    193
  • 4
    arthas使用教程
    419
  • 5
    揭秘Arthas：如何轻松查看入参的命令
    230
  • 6
    Java 诊断利器 Arthas使用
    214
  • 7
    金石原创 |【JVM实战系列】「监控调优体系」实战开发arthas-spring-boot-starter监控你的微服务是否健康!
    93
  • 8
    Java诊断利器Arthas安装和使用
    75
  • 9
    Arthas本身并没有提供直接让进程结束时自动生成火焰图的配置
    161
  • 10
    Arthas 可以用于监控和诊断在 Windows 系统下部署的 Tomcat 服务
    833

    • 相关课程

    更多
  • Java面试疑难点解析 - 面试技巧及语言基础
  • Java面试疑难点解析 - Java Web开发
  • Java面试疑难点解析 - 系统架构及项目设计
  • Java编程入门
  • Java面向对象编程
  • Java高级编程

    • 相关电子书

    更多
  • Spring Cloud Alibaba - 重新定义 Java Cloud-Native
  • The Reactive Cloud Native Arch
  • JAVA开发手册1.5.0

    • 相关实验场景

    更多
  • 阿里云平台上进行Java程序的编译与运行
  • Arthas中session、tee、version、wc基础命令应用
  • Arthas中plaintext、pwd、quit-stop、reset基础命令应用
  • Arthas中help、history、keymap、options基础命令应用
  • Arthas中cat 、cls、echo、grep基础命令应用
  • 使用Java面向对象编写网络通信程序应用
    • 下一篇
    阿里云OSS设置跨域访问