有时候在生产或者测试环境有些方法执行比较耗时，一种简单粗暴的方法是在可能的地点打日志进行监视，另一种就是借助于插件进行检测。最近也是有机会了解并实际运用了arthas这个插件，还是挺方便的。而且也可以用于查看JVM信息、线程信息以及系统属性等信息。
arthas(中文阿尔萨斯)： https://arthas.aliyun.com/zh-cn/
下载：
curl -O https://arthas.aliyun.com/arthas-boot.jar
0.本地准备一个java进程
package arthas;
public class ArthasTest {
public static void main(String[] args) {
System.out.println(Thread.currentThread().getName());
String test = System.getProperty("test");
while (true) {
String test2 = System.getProperty("test");
if (test2 != null && !test2.equals(test)) {
System.out.println(test2);
test = test2;
}
}
}
}
启动该主类
1.启动arthas
C:UsersqlqDesktopplaintools>java -jar arthas-boot.jar [INFO] arthas-boot version: 3.4.5 [INFO] Found existing java process, please choose one and input the serial number of the process, eg : 1. Then hit ENTER. * [1]: 20384 org.jetbrains.idea.maven.server.RemoteMavenServer36 [2]: 1556 [3]: 28868 arthas.ArthasTest [4]: 16780 org.jetbrains.jps.cmdline.Launcher [5]: 7676 org.jetbrains.jps.cmdline.Launcher 3 [INFO] local lastest version: 3.4.5, remote lastest version: 3.4.6, try to download from remote. [INFO] Start download arthas from remote server: https://arthas.aliyun.com/download/3.4.6?mirror=aliyun [INFO] File size: 11.99 MB, downloaded size: 813.01 KB, downloading ... [INFO] File size: 11.99 MB, downloaded size: 1.58 MB, downloading ... [INFO] File size: 11.99 MB, downloaded size: 2.36 MB, downloading ... [INFO] File size: 11.99 MB, downloaded size: 3.14 MB, downloading ... [INFO] File size: 11.99 MB, downloaded size: 3.93 MB, downloading ... [INFO] File size: 11.99 MB, downloaded size: 4.71 MB, downloading ... [INFO] File size: 11.99 MB, downloaded size: 5.49 MB, downloading ... [INFO] File size: 11.99 MB, downloaded size: 6.28 MB, downloading ... [INFO] File size: 11.99 MB, downloaded size: 7.06 MB, downloading ... [INFO] File size: 11.99 MB, downloaded size: 7.33 MB, downloading ... [INFO] File size: 11.99 MB, downloaded size: 8.81 MB, downloading ... [INFO] File size: 11.99 MB, downloaded size: 9.59 MB, downloading ... [INFO] File size: 11.99 MB, downloaded size: 10.37 MB, downloading ... [INFO] File size: 11.99 MB, downloaded size: 11.56 MB, downloading ... [INFO] Download arthas success. [INFO] arthas home: C:Usersjxrt.arthaslib3.4.6arthas [INFO] Try to attach process 28868 [INFO] Found java home from System Env JAVA_HOME: E:javaJAVA8 [INFO] Attach process 28868 success. [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.4.6 pid 28868 time 2021-01-12 20:54:40 [arthas@28868]$
arthas 会自动检测进程ID，需要自己选择一个PID然后进入，上面我输入3
2.基本命令
1.dashboard 当前系统的实时数据面板：包括线程、JVM、操作系统属性等
[arthas@28868]$ dashboard ID NAME GROUP PRIORITY STATE %CPU DELTA_TIME TIME INTERRUPTED DAEMON 1 main main 5 RUNNABLE 0.0 0.000 6:9.250 false false -1 C1 CompilerThread3 - -1 - 0.0 0.000 0:0.546 false true -1 C2 CompilerThread2 - -1 - 0.0 0.000 0:0.296 false true -1 C2 CompilerThread0 - -1 - 0.0 0.000 0:0.281 false true -1 C2 CompilerThread1 - -1 - 0.0 0.000 0:0.203 false true 25 arthas-NettyHttpTelnetBootstrap-3-2 system 5 RUNNABLE 0.0 0.000 0:0.078 false true 5 Attach Listener system 5 RUNNABLE 0.0 0.000 0:0.046 false true -1 VM Thread - -1 - 0.0 0.000 0:0.031 false true 2 Reference Handler system 10 WAITING 0.0 0.000 0:0.015 false true 3 Finalizer system 8 WAITING 0.0 0.000 0:0.015 false true 18 arthas-NettyHttpTelnetBootstrap-3-1 system 5 RUNNABLE 0.0 0.000 0:0.015 false true 26 arthas-command-execute system 5 TIMED_WAITING 0.0 0.000 0:0.015 false true 4 Signal Dispatcher system 9 RUNNABLE 0.0 0.000 0:0.000 false true 15 arthas-timer system 5 WAITING 0.0 0.000 0:0.000 false true 19 arthas-NettyWebsocketTtyBootstrap-4-1 system 5 RUNNABLE 0.0 0.000 0:0.000 false true 20 arthas-NettyWebsocketTtyBootstrap-4-2 system 5 RUNNABLE 0.0 0.000 0:0.000 false true 21 arthas-shell-server system 5 TIMED_WAITING 0.0 0.000 0:0.000 false true 22 arthas-session-manager system 5 TIMED_WAITING 0.0 0.000 0:0.000 false true 23 arthas-UserStat system 5 WAITING 0.0 0.000 0:0.000 false true 27 Timer-for-arthas-dashboard-2d53a13f-e23f-4 system 5 RUNNABLE 0.0 0.000 0:0.000 false true -1 GC task thread#7 (ParallelGC) - -1 - 0.0 0.000 0:0.000 false true -1 GC task thread#6 (ParallelGC) - -1 - 0.0 0.000 0:0.000 false true -1 VM Periodic Task Thread - -1 - 0.0 0.000 0:0.000 false true -1 GC task thread#0 (ParallelGC) - -1 - 0.0 0.000 0:0.000 false true -1 Service Thread - -1 - 0.0 0.000 0:0.000 false true -1 GC task thread#1 (ParallelGC) - -1 - 0.0 0.000 0:0.000 false true -1 GC task thread#2 (ParallelGC) - -1 - 0.0 0.000 0:0.000 false true Memory used total max usage GC heap 58M 241M 3582M 1.64% gc.ps_scavenge.count 1 ps_eden_space 50M 63M 1322M 3.80% gc.ps_scavenge.time(ms) 7 ps_survivor_space 8M 10M 10M 79.64% gc.ps_marksweep.count 0 ps_old_gen 88K 172032K 2751488K 0.00% gc.ps_marksweep.time(ms) 0 nonheap 27M 28M -1 96.88% code_cache 5M 5M 240M 2.21% metaspace 19M 20M -1 96.71% compressed_class_space 2M 2M 1024M 0.23% direct 0K 0K - 105.88% mapped 0K 0K - 0.00% Runtime os.name Windows 10 os.version 10.0 java.version 1.8.0_171 java.home E:javaJAVA8_171jre systemload.average -1.00 processors 8 timestamp/uptime Tue Jan 12 20:56:26 CST 2021/370s
上面信息可以看到JVM的内存信息，也可以查看到每个区域的GC信息。同时也可以看到使用的垃圾收集器是JDK8默认的-XX:+UseParallelGC 使用ParallelScavenge + Serial Old(PS MarkSweep)收集器组合
2.thread 查看线程信息
[arthas@28868]$ thread Threads Total: 29, NEW: 0, RUNNABLE: 8, BLOCKED: 0, WAITING: 4, TIMED_WAITING: 2, TERMINATED: 0, Internal threads: 15 ID NAME GROUP PRIORITY STATE %CPU DELTA_TIME TIME INTERRUPTED DAEMON 1 main main 5 RUNNABLE 101.42 0.203 8:3.609 false false 2 Reference Handler system 10 WAITING 0.0 0.000 0:0.015 false true 3 Finalizer system 8 WAITING 0.0 0.000 0:0.015 false true 4 Signal Dispatcher system 9 RUNNABLE 0.0 0.000 0:0.000 false true 5 Attach Listener system 5 RUNNABLE 0.0 0.000 0:0.046 false true 15 arthas-timer system 5 WAITING 0.0 0.000 0:0.000 false true 18 arthas-NettyHttpTelnetBootstrap-3-1 system 5 RUNNABLE 0.0 0.000 0:0.015 false true 19 arthas-NettyWebsocketTtyBootstrap-4-1 system 5 RUNNABLE 0.0 0.000 0:0.000 false true 20 arthas-NettyWebsocketTtyBootstrap-4-2 system 5 RUNNABLE 0.0 0.000 0:0.000 false true 21 arthas-shell-server system 5 TIMED_WAITING 0.0 0.000 0:0.000 false true 22 arthas-session-manager system 5 TIMED_WAITING 0.0 0.000 0:0.000 false true 23 arthas-UserStat system 5 WAITING 0.0 0.000 0:0.000 false true 25 arthas-NettyHttpTelnetBootstrap-3-2 system 5 RUNNABLE 0.0 0.000 0:0.125 false true 26 arthas-command-execute system 5 RUNNABLE 0.0 0.000 0:0.015 false true -1 C2 CompilerThread2 - -1 - 0.0 0.000 0:0.328 false true -1 GC task thread#7 (ParallelGC) - -1 - 0.0 0.000 0:0.000 false true -1 GC task thread#6 (ParallelGC) - -1 - 0.0 0.000 0:0.000 false true -1 VM Periodic Task Thread - -1 - 0.0 0.000 0:0.000 false true -1 GC task thread#0 (ParallelGC) - -1 - 0.0 0.000 0:0.000 false true -1 C2 CompilerThread0 - -1 - 0.0 0.000 0:0.296 false true -1 Service Thread - -1 - 0.0 0.000 0:0.000 false true -1 C2 CompilerThread1 - -1 - 0.0 0.000 0:0.218 false true -1 GC task thread#1 (ParallelGC) - -1 - 0.0 0.000 0:0.000 false true -1 C1 CompilerThread3 - -1 - 0.0 0.000 0:0.609 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.000 false true -1 GC task thread#3 (ParallelGC) - -1 - 0.0 0.000 0:0.000 false true -1 GC task thread#5 (ParallelGC) - -1 - 0.0 0.000 0:0.000 false true -1 GC task thread#4 (ParallelGC) - -1 - 0.0 0.000 0:0.000 false true
例如：thread 1会打印线程ID 1的栈，通常是main函数的线程。
[arthas@28868]$ thread 1 | grep 'main('
at arthas.ArthasTest.main(ArthasTest.java:15)
补充：也可以查看线程的阻塞情况，只支持找出synchronized关键字阻塞住的线程， 如果是java.util.concurrent.Lock， 目前还不支持。
如下一段程序：
package arthas;
public class ArthasTest {
public static void main(String[] args) {
MyTask myTask = new MyTask();
for (int i = 0; i < 2; i++) {
new Thread(myTask).start();
}
}
}
class MyTask implements Runnable {
@Override
public void run() {
System.out.println(Thread.currentThread().getName() + "开始执行");
synchronized (this) {
System.out.println(Thread.currentThread().getName() + " 占用锁");
try {
Thread.sleep(1 * 30 * 60 * 1000);
} catch (InterruptedException e) {
e.printStackTrace();
}
}
}
}
结果：
Thread-0开始执行
Thread-0 占用锁
Thread-1开始执行
可以用jstack查看，也可以用arthas：如下
[arthas@22336]$ thread -b
"Thread-0" Id=14 TIMED_WAITING
at java.lang.Thread.sleep(Native Method)
at arthas.MyTask.run(ArthasTest.java:21)
- locked arthas.MyTask@7253ba6b <---- but blocks 1 other threads!
at java.lang.Thread.run(Thread.java:748)
[arthas@22336]$ thread
Threads Total: 31, NEW: 0, RUNNABLE: 8, BLOCKED: 1, WAITING: 4, TIMED_WAITING: 3, TERMINATED: 0, Internal threads: 15
ID NAME GROUP PRIORITY STATE %CPU DELTA_TIME TIME INTERRUPTED DAEMON
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
5 Attach Listener system 5 RUNNABLE 0.0 0.000 0:0.031 false true
18 arthas-timer system 5 WAITING 0.0 0.000 0:0.000 false true
21 arthas-NettyHttpTelnetBootstrap-3-1 system 5 RUNNABLE 0.0 0.000 0:0.031 false true
22 arthas-NettyWebsocketTtyBootstrap-4-1 system 5 RUNNABLE 0.0 0.000 0:0.000 false true
23 arthas-NettyWebsocketTtyBootstrap-4-2 system 5 RUNNABLE 0.0 0.000 0:0.000 false true
24 arthas-shell-server system 5 TIMED_WAITING 0.0 0.000 0:0.000 false true
25 arthas-session-manager system 5 TIMED_WAITING 0.0 0.000 0:0.000 false true
26 arthas-UserStat system 5 WAITING 0.0 0.000 0:0.000 false true
28 arthas-NettyHttpTelnetBootstrap-3-2 system 5 RUNNABLE 0.0 0.000 0:0.093 false true
29 arthas-command-execute system 5 RUNNABLE 0.0 0.000 0:0.015 false true
14 Thread-0 main 5 TIMED_WAITING 0.0 0.000 0:0.000 false false
15 Thread-1 main 5 BLOCKED 0.0 0.000 0:0.000 false false
16 DestroyJavaVM main 5 RUNNABLE 0.0 0.000 0:0.343 false false
-1 C2 CompilerThread2 - -1 - 0.0 0.000 0:0.218 false true
-1 GC task thread#7 (ParallelGC) - -1 - 0.0 0.000 0:0.000 false true
-1 GC task thread#6 (ParallelGC) - -1 - 0.0 0.000 0:0.000 false true
-1 VM Periodic Task Thread - -1 - 0.0 0.000 0:0.000 false true
-1 GC task thread#0 (ParallelGC) - -1 - 0.0 0.000 0:0.000 false true
-1 C2 CompilerThread0 - -1 - 0.0 0.000 0:0.203 false true
-1 Service Thread - -1 - 0.0 0.000 0:0.000 false true
-1 C2 CompilerThread1 - -1 - 0.0 0.000 0:0.218 false true
-1 GC task thread#1 (ParallelGC) - -1 - 0.0 0.000 0:0.000 false true
-1 C1 CompilerThread3 - -1 - 0.0 0.000 0:0.640 false true
-1 VM Thread - -1 - 0.0 0.000 0:0.015 false true
-1 GC task thread#2 (ParallelGC) - -1 - 0.0 0.000 0:0.000 false true
-1 GC task thread#3 (ParallelGC) - -1 - 0.0 0.000 0:0.000 false true
-1 GC task thread#5 (ParallelGC) - -1 - 0.0 0.000 0:0.000 false true
-1 GC task thread#4 (ParallelGC) - -1 - 0.0 0.000 0:0.000 false true
[arthas@22336]$ thread 15
"Thread-1" Id=15 BLOCKED on arthas.MyTask@7253ba6b owned by "Thread-0" Id=14
at arthas.MyTask.run(ArthasTest.java:19)
- blocked on arthas.MyTask@7253ba6b
at java.lang.Thread.run(Thread.java:748)
thread -b 找出当前阻塞其他线程的线程。 可以看到 Thread-0 阻塞了其他一个线程
Thread 查看线程状态可以看到ID为15的Thread-1处于阻塞状态。
Thread 15 查看具体的信息，可以看到当前阻塞的资源被哪个线程占有等情况。
3. jad 反编译类信息
[arthas@28868]$ jad arthas.ArthasTest
ClassLoader:
+-sun.misc.Launcher$AppClassLoader@18b4aac2
+-sun.misc.Launcher$ExtClassLoader@3af87f7
Location:
/E:/xiangmu/MvnPro/target/classes/
/*
* Decompiled with CFR.
*/
package arthas;
public class ArthasTest {
public static void main(String[] args) {
System.out.println(Thread.currentThread().getName());
String test = System.getProperty("test");
while (true) {
String test2;
if ((test2 = System.getProperty("test")) == null || test2.equals(test)) {
continue;
}
System.out.println(test2);
test = test2;
}
}
}
4. 开启保存日志
options 查看配置，相当于查看arthas内置的全局配置属性
options save-result true 开启保存日志。会保存到{user}/logsarthas-cache/result.log 中
5.退出
如果只是退出当前的连接，可以用quit或者exit命令。Attach到目标进程上的arthas还会继续运行，端口会保持开放，下次连接时可以直接连接上。
如果想完全退出arthas，可以执行stop命令。
3. 实操
1. 修改以及查看JVM的环境变量和JVM的系统属性
sysenv 查看JVM的环境变量
sysprop 查看JVM的所有的系统属性
sysprop java.version 查看单个系统的属性
sysprop user.country US 修改user.country 属性的值为US
比如上面修改 test 属性为 testValue，修改之后会被程序System.getProperty(key) 获取到
[arthas@28868]$ sysprop test testValue Successfully changed the system property. KEY VALUE ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------- test testValue [arthas@28868]$ sysprop test KEY VALUE ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------- test testValue
我们到IDEA查看main线程打出的信息：testValue
2. 监视方法的执行时长以及方法的返回值
比如如下简单的Controller和Service：
controller：
package com.xm.ggn.controller;
import com.xm.ggn.service.common.MessageService2;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.beans.factory.annotation.Value;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RestController;
@RestController
public class TestController {
@Value("${test:defaultValue}")
private String test;
@RequestMapping("test")
public String test() {
return test;
}
@Autowired
private MessageService2 messageService;
@RequestMapping("tx1")
public void tx1() {
messageService.tx1();
}
@RequestMapping("tx2")
public void tx2() {
messageService.tx2();
}
@RequestMapping("tx4")
public void tx4() {
messageService.tx4();
}
}
service：
package com.xm.ggn.service.common;
public interface MessageService2 {
void tx1();
void tx2();
void tx3();
void tx4();
}
serviceimpl：
package com.xm.ggn.service.common.impl;
import com.xm.ggn.bean.common.Message;
import com.xm.ggn.mapper.common.MessageMapper;
import com.xm.ggn.service.common.MessageService2;
import org.springframework.aop.framework.AopContext;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.stereotype.Service;
import javax.transaction.Transactional;
@Service
//@Transactional
public class MessageService2Impl implements MessageService2 {
@Autowired
private MessageMapper messageMapper;
@Override
@Transactional
public void tx1() {
// 调用tx3方法会回滚，因为这里有事务直接，会走代理，且tx3方法会加入本事务
tx3();
}
@Override
public void tx2() {
try {
Thread.sleep(1 * 1000);
} catch (InterruptedException e) {
e.printStackTrace();
}
// 调用tx3方法不会回滚，因为这里没有事务。即使tx3有事务也不会走代理，因为通过内部方法调用不会走代理。解决办法查看tx4 方法
tx3();
}
@Override
@Transactional
public void tx3() {
Message message = new Message();
message.setTitle("tx3");
messageMapper.insert(message);
int i = 1 / 0;
}
// 这样进行方法内部调用AOP会生效，主启动类加@EnableAspectJAutoProxy(proxyTargetClass = true, exposeProxy = true) 注解
@Override
public void tx4() {
MessageService2 messageService = (MessageService2) AopContext.currentProxy();
// 这样调用tx3会进行回滚，走的是代理类的方法
messageService.tx3();
}
}
启动应用后启动arthas并且监视对应进程
1. 搜索类以及反编译查看AOP增强的类
1. 搜索：模糊搜索
[arthas@13232]$ sc *.MessageService2 com.xm.ggn.service.common.MessageService2 com.xm.ggn.service.common.impl.MessageService2Impl com.xm.ggn.service.common.impl.MessageService2Impl$$EnhancerBySpringCGLIB$$7fa3a2fc Affect(row-cnt:3) cost in 56 ms.
如果查看加载的所有类，可以用：
sc *
2. 反编译查看AOP增强的类
[arthas@13232]$ jad com.xm.ggn.service.common.impl.MessageService2Impl$$EnhancerBySpringCGLIB$$7fa3a2fc
ClassLoader:
+-sun.misc.Launcher$AppClassLoader@18b4aac2
+-sun.misc.Launcher$ExtClassLoader@3c22fc4c
Location:
/E:/xiangmu/bs-media/media-server/target/classes/
/*
* Decompiled with CFR.
*
* Could not load the following classes:
* com.xm.ggn.service.common.impl.MessageService2Impl
*/
package com.xm.ggn.service.common.impl;
import com.xm.ggn.service.common.impl.MessageService2Impl;
import java.lang.reflect.Method;
import org.aopalliance.aop.Advice;
import org.springframework.aop.Advisor;
import org.springframework.aop.SpringProxy;
import org.springframework.aop.TargetClassAware;
import org.springframework.aop.TargetSource;
import org.springframework.aop.framework.Advised;
import org.springframework.aop.framework.AopConfigException;
import org.springframework.cglib.core.ReflectUtils;
import org.springframework.cglib.core.Signature;
import org.springframework.cglib.proxy.Callback;
import org.springframework.cglib.proxy.Dispatcher;
import org.springframework.cglib.proxy.Factory;
import org.springframework.cglib.proxy.MethodInterceptor;
import org.springframework.cglib.proxy.MethodProxy;
import org.springframework.cglib.proxy.NoOp;
public class MessageService2Impl$$EnhancerBySpringCGLIB$$7fa3a2fc
extends MessageService2Impl
implements SpringProxy,
Advised,
Factory {
private boolean CGLIB$BOUND;
public static Object CGLIB$FACTORY_DATA;
...
}
2. 检测方法的执行时长： trace
比如检测：com.xm.ggn.controller.TestController 类的所有方法，如下：
[arthas@13232]$ trace com.xm.ggn.controller.TestController *
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 5) cost in 93 ms, listenerId: 1
`---ts=2021-01-12 21:15:57;thread_name=http-nio-8088-exec-1;id=108;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@3ee39a1c
`---[45.0785ms] com.xm.ggn.controller.TestController:tx4() [throws Exception]
+---[44.0299ms] com.xm.ggn.service.common.MessageService2:tx4() #40 [throws Exception]
`---throw:java.lang.ArithmeticException #39 [/ by zero]
trace还有好几个参数可以过滤以及支持检测多个类的多个方法以及根据时长过滤等
补充：用trace命令检测多个类的多个方法，形成调用链检测
比如如下
(1) Service1
package com.xm.ggn.test.arthas;
import lombok.extern.slf4j.Slf4j;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.stereotype.Service;
import java.util.concurrent.TimeUnit;
/**
* @author: 乔利强
* @date: 2021/2/7 14:37
* @description:
*/
@Service
@Slf4j
public class ArthasTestService {
@Autowired
private ArthasTestService2 arthasTestService2;
public void method1() {
log.debug("method1");
try {
TimeUnit.SECONDS.sleep(1);
} catch (InterruptedException ignore) {
}
this.method2();
this.method3();
}
public void method2() {
log.debug("method2");
try {
TimeUnit.SECONDS.sleep(2);
} catch (InterruptedException ignore) {
}
arthasTestService2.method1();
arthasTestService2.method2();
}
public void method3() {
log.debug("method3");
try {
TimeUnit.SECONDS.sleep(3);
} catch (InterruptedException ignore) {
}
}
}
(2)Service2
package com.xm.ggn.test.arthas;
import lombok.extern.slf4j.Slf4j;
import org.springframework.stereotype.Service;
import java.util.concurrent.TimeUnit;
/**
* @author: 乔利强
* @date: 2021/2/7 14:37
* @description:
*/
@Service
@Slf4j
public class ArthasTestService2 {
public void method1() {
log.debug("method1");
try {
TimeUnit.SECONDS.sleep(1);
} catch (InterruptedException ignore) {
}
}
public void method2() {
log.debug("method2");
try {
TimeUnit.SECONDS.sleep(2);
} catch (InterruptedException ignore) {
}
}
}
(3)Controller
package com.xm.ggn.test.arthas;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RestController;
/**
* @author: 乔利强
* @date: 2021/2/7 14:34
* @description:
*/
@RestController
@RequestMapping("/arthas")
public class ArthasTestCcontroller {
@Autowired
private ArthasTestService arthasTestService;
@GetMapping("testTrace")
public void testTrace() {
arthasTestService.method1();
}
}
(4)测试：
1》trace检测单个类，结果如下： 可以看到没监测ArthasTestService2 内部调用时长
[arthas@28892]$ sc *.ArthasTestService*
com.xm.ggn.test.arthas.ArthasTestService
com.xm.ggn.test.arthas.ArthasTestService2
Affect(row-cnt:2) cost in 50 ms.
[arthas@28892]$ trace com.xm.ggn.test.arthas.ArthasTestService *
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 4) cost in 83 ms, listenerId: 1
`---ts=2021-02-07 19:32:08;thread_name=http-nio-8088-exec-1;id=12e;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@87060c0
`---[9003.109599ms] com.xm.ggn.test.arthas.ArthasTestService:method1()
+---[0.035ms] org.slf4j.Logger:debug() #22
+---[5002.6882ms] com.xm.ggn.test.arthas.ArthasTestService:method2() #28
| `---[5002.1293ms] com.xm.ggn.test.arthas.ArthasTestService:method2()
| +---[0.008ms] org.slf4j.Logger:debug() #34
| +---[1000.8634ms] com.xm.ggn.test.arthas.ArthasTestService2:method1() #40
| `---[2000.6096ms] com.xm.ggn.test.arthas.ArthasTestService2:method2() #41
`---[3000.115601ms] com.xm.ggn.test.arthas.ArthasTestService:method3() #29
`---[3000.07ms] com.xm.ggn.test.arthas.ArthasTestService:method3()
`---[0.007ms] org.slf4j.Logger:debug() #45
2》 监测两个类的多个方法： 可以看到也监测了ArthasTestService2的相关方法
[arthas@28892]$ trace -E com.xm.ggn.test.arthas.ArthasTestService|com.xm.ggn.test.arthas.ArthasTestService2 method1|method2|method3
Press Q or Ctrl+C to abort.
Affect(class count: 2 , method count: 5) cost in 122 ms, listenerId: 3
`---ts=2021-02-07 19:34:51;thread_name=http-nio-8088-exec-4;id=131;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@87060c0
`---[9002.5463ms] com.xm.ggn.test.arthas.ArthasTestService:method1()
+---[0.0627ms] org.slf4j.Logger:debug() #22
+---[5001.5262ms] com.xm.ggn.test.arthas.ArthasTestService:method2() #28
| `---[5001.484ms] com.xm.ggn.test.arthas.ArthasTestService:method2()
| +---[0.008101ms] org.slf4j.Logger:debug() #34
| +---[1000.377399ms] com.xm.ggn.test.arthas.ArthasTestService2:method1() #40
| | `---[1000.288999ms] com.xm.ggn.test.arthas.ArthasTestService2:method1()
| | `---[0.0178ms] org.slf4j.Logger:debug() #18
| `---[2000.178ms] com.xm.ggn.test.arthas.ArthasTestService2:method2() #41
| `---[2000.134ms] com.xm.ggn.test.arthas.ArthasTestService2:method2()
| `---[0.0112ms] org.slf4j.Logger:debug() #26
`---[3000.27ms] com.xm.ggn.test.arthas.ArthasTestService:method3() #29
`---[3000.235499ms] com.xm.ggn.test.arthas.ArthasTestService:method3()
`---[0.007101ms] org.slf4j.Logger:debug() #45
这里暂时没找到监测两个类或多个类所有方法的套路~~~
结果解释：
(1)[5001.5262ms] com.xm.ggn.test.arthas.ArthasTestService:method2() #28 当前节点在当前步骤的耗时，单位为毫秒。 #28 表示在源文件的第28行。
(2)还有另一种写法：[min=0.020435ms,max=0.022325ms,total=0.04276ms,count=2] org.springframework.util.Assert:isTrue() #95 表示对该方法中相同的方法调用进行了合并。比如：
if ("1".equals(a) && "2".equals(b)) {
// doXXX
}
3.查看某个类调用过程中的返回值： 比如观察方法出参和返回值 watch
[arthas@19792]$ watch com.xm.ggn.controller.TestController * "{params,returnObj}"
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 5) cost in 79 ms, listenerId: 3
method=com.xm.ggn.controller.TestController.test location=AtExit
ts=2021-01-12 21:32:16; [cost=0.0674ms] result=@ArrayList[
@Object[][isEmpty=true;size=0],
@String[defaultValue],
]
调用一次test 方法之后结果如上。可以看到参数为空，返回值是一个String值为"defaultValue"。
这个结果可能不太明显，增加一个测试用例：
(1)Controller增加一个方法：
@RequestMapping("testMap")
public Map test(String key1, String key2) {
HashMap<String, Object> stringObjectHashMap = new HashMap<>();
stringObjectHashMap.put(key1, key1);
stringObjectHashMap.put(key2, key2);
return stringObjectHashMap;
}
(2)arthas检测： -x 指定输出结果的属性遍历深度，默认为 1
[arthas@27848]$ watch com.xm.ggn.controller.TestController * "{params,returnObj}" -x 3
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 6) cost in 38 ms, listenerId: 5
(3)访问：
http://localhost:8088/testMap?key1=111&key2=222
(4)arthas控制台输出
method=com.xm.ggn.controller.TestController.test location=AtExit
ts=2021-01-12 21:40:26; [cost=0.0351ms] result=@ArrayList[
@Object[][
@String[111],
@String[222],
],
@HashMap[
@String[111]:@String[111],
@String[222]:@String[222],
],
]
补充：第一次运行jar包选择进程进入的时候会自动从互联网下载几个依赖包，自动放在 ${user}/.arthas/lib。如果是离线环境可以将lib下面的包传到离线的服务器，启动的时候指定路径：如下：
java -jar arthas-boot.jar --arthas-home C:UsersqlqDesktopplaintoolsarthaslib3.4.5arthas
--arthas-home 指定依赖包的路径
补充：Arthas目前支持Web Console，用户在attach成功之后，可以直接访问：http://127.0.0.1:3658/。默认情况下，arthas只listen 127.0.0.1，所以如果想从远程连接，则可以使用 --target-ip参数指定listen的IP，更多参考-h的帮助说明。
补充：logger查看以及修改日志级别
[arthas@11520]$ 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:/E:/Maven/repository/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
[arthas@11520]$ logger --name ROOT --level debug #修改日志级别
Update logger level success.
[arthas@11520]$ logger #查看日志级别
name ROOT
class ch.qos.logback.classic.Logger
classLoader sun.misc.Launcher$AppClassLoader@18b4aac2
classLoaderHash 18b4aac2
level DEBUG
effectiveLevel DEBUG
additivity true
codeSource file:/E:/Maven/repository/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
补充：sc 也可以查看类以及静态变量的信息，如下：
[arthas@9432]$ sc -d -f com.xm.ggn.test.FieldTest
class-info com.xm.ggn.test.FieldTest
code-source /E:/xiangmu/bs-media/media-server/target/classes/
name com.xm.ggn.test.FieldTest
isInterface false
isAnnotation false
isEnum false
isAnonymousClass false
isArray false
isLocalClass false
isMemberClass false
isPrimitive false
isSynthetic false
simple-name FieldTest
modifier public
annotation
interfaces
super-class +-java.lang.Object
class-loader +-sun.misc.Launcher$AppClassLoader@18b4aac2
+-sun.misc.Launcher$ExtClassLoader@707ed9b0
classLoaderHash 18b4aac2
fields name test
type java.lang.String
modifier final,public,static
value 123
name name
type java.lang.String
modifier private
也可以使用ognl获取静态变量：
[arthas@9432]$ ognl '@com.xm.ggn.test.FieldTest@test' @String[123]