安装
安装很容易 , arthas是以 jar 包的形式运行的
wget https://arthas.aliyun.com/arthas-boot.jar
java -jar arthas-boot.jar
模拟
我们以官方提供的例子为例
wget https://arthas.aliyun.com/math-game.jar
java -jar math-game.jar
然后再另外的窗口运行 arthas , 下面使用 monitor 命令, 该命令可以监控方法调用的情况包括 :
例如我们可以知道知道每5秒, run方法的调用情况.
[arthas@38487]$ monitor demo.run -c 5
The argument 'method-pattern' is required, description: Method of Pattern Matching
[arthas@38487]$ monitor demo.MathGame run -c 5
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 20 ms, listenerId: 2
timestamp class method total success fail avg-rt(ms fail-rate
)
------------------------------------------------------------------------------------------------------------------------------------------------------
2021-06-13 21:58:31 demo.MathGame run 4 4 0 0.15 0.00%
timestamp class method total success fail avg-rt(ms fail-rate
)
------------------------------------------------------------------------------------------------------------------------------------------------------
2021-06-13 21:58:36 demo.MathGame run 5 5 0 0.13 0.00%
timestamp class method total success fail avg-rt(ms fail-rate
)
可以看到 avg-rt(平均响应) 我们可以找到最耗时的方法 , 然后进行定位问题 , 这里我们以下面这篇文章为例子 , 定位 druid 的一个问题 ,
可以看到作者找到了比较耗时的方法调用, 于是作者使用了 trace 命令进行查看,而该方法是调用了 java本身库内的方法 为了定位问题, 作者 monitor 了 ReentrantLock这个方法
最终定位到了问题 , 而为了查看某个线程阻塞的原因, 我们对线程进行了查看, 找到某些阻塞的线程
thread --state BLOCKING
最后看到
java.util.concurrent.locks.ReentrantLock$FairSync@60190bc0
at sun.misc.Unsafe.park(Native Method)
- waiting on java.util.concurrent.locks.ReentrantLock$FairSync@60190bc0
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:870)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1199)
at java.util.concurrent.locks.ReentrantLock$FairSync.lock(ReentrantLock.java:224)
at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285)
at com.alibaba.druid.pool.DruidDataSource.recycle(DruidDataSource.java:1913)
at com.alibaba.druid.pool.DruidPooledConnection.recycle(DruidPooledConnection.java:324)
at com.alibaba.druid.pool.DruidPooledConnection.syncClose(DruidPooledConnection.java:300)
at com.alibaba.druid.pool.DruidPooledConnection.close(DruidPooledConnection.java:255)
at org.springframework.jdbc.datasource.DataSourceUtils.doCloseConnection(DataSourceUtils.java:341)
原来是使用了公平锁导致的,找到了问题就可以进行优化了.
trace 命令
trace命令是为了方法内部调用路径，并输出方法路径上的每个节点上耗时 , 上面的例子有一个就是调用了 trace 的效果
tread 命令
这个命令就比较常用点,用户查找阻塞的线程等等
例如可以这样使用
[arthas@38487]$ thread -n 5
"C2 CompilerThread2" [Internal] cpuUsage=2.84% deltaTime=5ms time=549ms
"C1 CompilerThread3" [Internal] cpuUsage=0.26% deltaTime=0ms time=772ms
"arthas-command-execute" Id=23 cpuUsage=0.12% deltaTime=0ms time=316ms RUNNABLE
at sun.management.ThreadImpl.dumpThreads0(Native Method)
at sun.management.ThreadImpl.getThreadInfo(ThreadImpl.java:448)
at com.taobao.arthas.core.command.monitor200.ThreadCommand.processTopBusyThreads(ThreadCommand.java:206)
at com.taobao.arthas.core.command.monitor200.ThreadCommand.process(ThreadCommand.java:122)
at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl.process(AnnotatedCommandImpl.java:82)
at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl.access$100(AnnotatedCommandImpl.java:18)
at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl$ProcessHandler.handle(AnnotatedCommandImpl.java:111)
at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl$ProcessHandler.handle(AnnotatedCommandImpl.java:108)
at com.taobao.arthas.core.shell.system.impl.ProcessImpl$CommandProcessTask.run(ProcessImpl.java:385)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
"C2 CompilerThread0" [Internal] cpuUsage=0.06% deltaTime=0ms time=518ms
"VM Periodic Task Thread" [Internal] cpuUsage=0.03% deltaTime=0ms time=1348ms
[arthas@38487]$ thread --all
Threads Total: 30, NEW: 0, RUNNABLE: 8, BLOCKED: 0, WAITING: 4, TIMED_WAITING: 3, TERMINATED: 0, Internal threads: 15
ID NAME GROUP PRIORITY STATE %CPU DELTA_TIME TIME INTERRUPTED DAEMON
-1 C1 CompilerThread3 - -1 - 0.32 0.000 0:0.781 false true
23 arthas-command-execute system 5 RUNNABLE 0.09 0.000 0:0.318 false true
-1 VM Periodic Task Thread - -1 - 0.05 0.000 0:1.355 false true
-1 VM Thread - -1 - 0.04 0.000 0:0.168 false true
2 Reference Handler system 10 WAITING 0.0 0.000 0:0.003 false true
3 Finalizer system 8 WAITING 0.0 0.000 0:0.005 false true
4 Signal Dispatcher system 9 RUNNABLE 0.0 0.000 0:0.000 false true
10 Attach Listener system 9 RUNNABLE 0.0 0.000 0:0.012 false true
12 arthas-timer system 9 WAITING 0.0 0.000 0:0.000 false true
15 arthas-NettyHttpTelnetBootstrap-3-1 system 5 RUNNABLE 0.0 0.000 0:0.017 false true
16 arthas-NettyWebsocketTtyBootstrap-4-1 system 5 RUNNABLE 0.0 0.000 0:0.002 false true
17 arthas-NettyWebsocketTtyBootstrap-4-2 system 5 RUNNABLE 0.0 0.000 0:0.001 false true
18 arthas-shell-server system 9 TIMED_WAITIN 0.0 0.000 0:0.007 false true
19 arthas-session-manager system 9 TIMED_WAITIN 0.0 0.000 0:0.002 false true
20 arthas-UserStat system 9 WAITING 0.0 0.000 0:0.000 false true
22 arthas-NettyHttpTelnetBootstrap-3-2 system 5 RUNNABLE 0.0 0.000 0:0.243 false true
25 arthas-NettyHttpTelnetBootstrap-3-3 system 5 RUNNABLE 0.0 0.000 0:0.101 false true
1 main main 5 TIMED_WAITIN 0.0 0.000 0:0.543 false false
-1 C2 CompilerThread2 - -1 - 0.0 0.000 0:0.549 false true
-1 GC task thread#7 (ParallelGC) - -1 - 0.0 0.000 0:0.042 false true
-1 GC task thread#6 (ParallelGC) - -1 - 0.0 0.000 0:0.046 false true
-1 GC task thread#0 (ParallelGC) - -1 - 0.0 0.000 0:0.045 false true
-1 C2 CompilerThread0 - -1 - 0.0 0.000 0:0.518 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.526 false true
-1 GC task thread#1 (ParallelGC) - -1 - 0.0 0.000 0:0.038 false true
-1 GC task thread#2 (ParallelGC) - -1 - 0.0 0.000 0:0.046 false true
-1 GC task thread#3 (ParallelGC) - -1 - 0.0 0.000 0:0.033 false true
-1 GC task thread#5 (ParallelGC) - -1 - 0.0 0.000 0:0.044 false true
-1 GC task thread#4 (ParallelGC) - -1 - 0.0 0.000 0:0.051 false true
[arthas@38487]$ thread 1
"main" Id=1 TIMED_WAITING
at java.lang.Thread.sleep(Native Method)
at java.lang.Thread.sleep(Thread.java:340)
at java.util.concurrent.TimeUnit.sleep(TimeUnit.java:386)
at demo.MathGame.main(MathGame.java:17)
[arthas@38487]$ thread --state RUNNABLE
Threads Total: 15, NEW: 0, RUNNABLE: 8, BLOCKED: 0, WAITING: 4, TIMED_WAITING: 3, TERMINATED: 0
ID NAME GROUP PRIORITY STATE %CPU DELTA_TIME TIME INTERRUPTED DAEMON
23 arthas-command-execute system 5 RUNNABLE 0.05 0.000 0:0.324 false true
4 Signal Dispatcher system 9 RUNNABLE 0.0 0.000 0:0.000 false true
10 Attach Listener system 9 RUNNABLE 0.0 0.000 0:0.012 false true
15 arthas-NettyHttpTelnetBootstrap-3-1 system 5 RUNNABLE 0.0 0.000 0:0.017 false true
16 arthas-NettyWebsocketTtyBootstrap-4-1 system 5 RUNNABLE 0.0 0.000 0:0.002 false true
17 arthas-NettyWebsocketTtyBootstrap-4-2 system 5 RUNNABLE 0.0 0.000 0:0.001 false true
22 arthas-NettyHttpTelnetBootstrap-3-2 system 5 RUNNABLE 0.0 0.000 0:0.243 false true
25 arthas-NettyHttpTelnetBootstrap-3-3 system 5 RUNNABLE 0.0 0.000 0:0.117 false true
[arthas@38487]$
参考资料
- https://arthas.aliyun.com/doc/index.html (重要,文档,推荐一看)