有時候在生產或者測試環境有些方法執行比較耗時，一種簡單粗暴的方法是在可能的地點打日志進行監視，另一種就是借助於插件進行檢測。最近也是有機會了解並實際運用了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:\Users\qlq\Desktop\plaintools>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:\Users\jxrt\.arthas\lib\3.4.6\arthas [INFO] Try to attach process 28868 [INFO] Found java home from System Env JAVA_HOME: E:\java\JAVA8 [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:\java\JAVA8_171\jre 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}/logs\arthas-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:\Users\qlq\Desktop\plaintools\arthas\lib\3.4.5\arthas
--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]