Arthas（阿尔萨斯）
工欲善其事 必先利其器 Arthas是Java线上诊断的神器
工具背景
Arthas 是Alibaba开源的Java线上诊断工具，支持JDK 6+，支持Linux/Mac/Winodws，采用命令行交互模式，同时提供丰富的 Tab 自动补全功能，进一步方便进行问题的定位和诊断。
想吐槽一下这个名字，作者是有多爱WOW...
官方文档：https://alibaba.github.io/arthas/index.html
应用场景
当你遇到以下类似问题而束手无策时，Arthas可以帮助你解决：
- 这个类从哪个 jar 包加载的？为什么会报各种类相关的 Exception？
- 我改的代码为什么没有执行到？难道是我没 commit？分支搞错了？
- 遇到问题无法在线上 debug，难道只能通过加日志再重新发布吗？
- 线上遇到某个用户的数据处理有问题，但线上同样无法 debug，线下无法重现！
- 是否有一个全局视角来查看系统的运行状况？
- 有什么办法可以监控到JVM的实时运行状态？
快速安装
wget https://alibaba.github.io/arthas/arthas-boot.jar
java -jar arthas-boot.jar快速开始
选择应用java进程：
$ docker exec -it arthas-demo /bin/sh -c "java -jar /opt/arthas/arthas-boot.jar"
[INFO] arthas-boot version: 3.1.1
[INFO] Found existing java process, please choose one and hit RETURN.
* [1]: 6 /opt/arthas/arthas-demo.jar输入1，再输入回车/enter。Arthas会attach到目标进程上，并输出日志：
[INFO] arthas home: /opt/arthas
[INFO] Try to attach process 6
[INFO] Attach process 6 success.
[INFO] arthas-client connect 127.0.0.1 3658
,---. ,------. m,--------.,--. ,--. ,---. ,---.
/ O \ | .--. ''--. .--'| '--' | / O \ ' .-'
| .-. || '--'.' | | | .--. || .-. |`. `-.
| | | || |\ \ | | | | | || | | |.-' |
`--' `--'`--' '--' `--' `--' `--'`--' `--'`-----'
wiki https://alibaba.github.io/arthas
tutorials https://alibaba.github.io/arthas/arthas-tutorials
version 3.1.1
pid 6
time 2019-06-12 02:07:35
$常用命令
Arthas的具备丰富的功能，并且支持Tab 自动补全，在此不一一列举，详见：https://alibaba.github.io/arthas/advanced-use.html
dashboard
查看当前系统的实时数据面板（Thread/Memory/GC/Runtime/Tomcat），按 ctrl+c 退出。
ID NAME GROUP PRIORITY STATE %CPU TIME INTERRUPTED DAEMON
46 Timer-for-arthas-dashboard-0417c82e-1367-4c system 10 RUNNABLE 100 0:0 false true
10 AsyncAppender-Worker-arthas-cache.result.As system 9 WAITING 0 0:0 false true
8 Attach Listener system 9 RUNNABLE 0 0:0 false true
3 Finalizer system 8 WAITING 0 0:0 false true
2 Reference Handler system 10 WAITING 0 0:0 false true
4 Signal Dispatcher system 9 RUNNABLE 0 0:0 false true
44 as-command-execute-daemon system 10 TIMED_WAITING 0 0:0 false true
12 job-timeout system 9 TIMED_WAITING 0 0:0 false true
1 main main 5 TIMED_WAITING 0 0:45 false false
13 nioEventLoopGroup-2-1 system 10 RUNNABLE 0 0:8 false false
17 nioEventLoopGroup-2-2 system 10 RUNNABLE 0 0:8 false false
33 nioEventLoopGroup-2-3 system 10 RUNNABLE 0 0:8 false false
37 nioEventLoopGroup-2-4 system 10 RUNNABLE 0 0:7 false false
14 nioEventLoopGroup-3-1 system 10 RUNNABLE 0 0:8 false false
15 pool-1-thread-1 system 5 TIMED_WAITING 0 0:0 false false
16 pool-2-thread-1 system 5 WAITING 0 0:0 false false
Memory used total max usage GC
heap 56M 106M 441M 12.87% gc.ps_scavenge.count 23
ps_eden_space 30M 65M 143M 21.67% gc.ps_scavenge.time(ms) 344
ps_survivor_space 544K 1024K 1024K 53.13% gc.ps_marksweep.count 3
ps_old_gen 25M 39M 331M 7.62% gc.ps_marksweep.time(ms) 215
nonheap 32M 33M -1 97.19%
code_cache 7M 8M 240M 3.28%
metaspace 22M 22M -1 97.68%
compressed_class_space 2M 2M 1024M 0.24%
direct 0K 0K - Infinity%
mapped 0K 0K - NaN%
Runtime
os.name Linux
os.version 4.9.125-linuxkit
java.version 1.8.0_212
java.home /usr/lib/jvm/java-1.8-openjdk/jre
systemload.average 0.11
processors 2
uptime 185745s
thread
查看当前线程信息，查看线程的堆栈。
| 参数名称 | 参数说明 |
|---|---|
| id | 线程id |
| [n:] | 指定最忙的前N个线程并打印堆栈 |
| [b] | 找出当前阻塞其他线程的线程 |
| [i ] | 指定cpu占比统计的采样间隔，单位为毫秒 |
显示指定线程的运行堆栈
$ 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)当前最忙的前N个线程并打印堆栈
$ thread -n 3
"as-command-execute-daemon" Id=48 cpuUsage=68% 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:133)
at com.taobao.arthas.core.command.monitor200.ThreadCommand.process(ThreadCommand.java:79)
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:370)
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)
Number of locked synchronizers = 1
- java.util.concurrent.ThreadPoolExecutor$Worker@503ca440
"nioEventLoopGroup-2-3" Id=33 cpuUsage=31% RUNNABLE (in native)
at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93)
at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
- locked io.netty.channel.nio.SelectedSelectionKeySet@46d33dbd
- locked java.util.Collections$UnmodifiableSet@1672a7b2
- locked sun.nio.ch.EPollSelectorImpl@17c134d0
at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
at io.netty.channel.nio.SelectedSelectionKeySetSelector.select(SelectedSelectionKeySetSelector.java:62)
at io.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:791)
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:439)
at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:906)
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.lang.Thread.run(Thread.java:748)
"Reference Handler" Id=2 cpuUsage=0% WAITING on java.lang.ref.Reference$Lock@138fcfa0
at java.lang.Object.wait(Native Method)
- waiting on java.lang.ref.Reference$Lock@138fcfa0
at java.lang.Object.wait(Object.java:502)
at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)当前阻塞其他线程的线程
$ thread -b
"http-bio-8080-exec-4" Id=27 TIMED_WAITING
at java.lang.Thread.sleep(Native Method)
at test.arthas.TestThreadBlocking.doGet(TestThreadBlocking.java:22)
- locked java.lang.Object@725be470 <---- but blocks 4 other threads!
at javax.servlet.http.HttpServlet.service(HttpServlet.java:624)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:731)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at test.filter.TestDurexFilter.doFilter(TestDurexFilter.java:46)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:505)
at com.taobao.tomcat.valves.ContextLoadFilterValve$FilterChainAdapter.doFilter(ContextLoadFilterValve.java:191)
at com.taobao.eagleeye.EagleEyeFilter.doFilter(EagleEyeFilter.java:81)
at com.taobao.tomcat.valves.ContextLoadFilterValve.invoke(ContextLoadFilterValve.java:150)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:170)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:429)
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1085)
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:625)
at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:318)
- locked org.apache.tomcat.util.net.SocketWrapper@7127ee12
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
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)
Number of locked synchronizers = 1
- java.util.concurrent.ThreadPoolExecutor$Worker@31a6493ejvm
查看当前JVM信息。
$ jvm
RUNTIME
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
MACHINE-NAME 6@4425d962807f
JVM-START-TIME 2019-06-12 02:07:19
MANAGEMENT-SPEC-VERSION 1.2
SPEC-NAME Java Virtual Machine Specification
SPEC-VENDOR Oracle Corporation
SPEC-VERSION 1.8
VM-NAME OpenJDK 64-Bit Server VM
VM-VENDOR IcedTea
VM-VERSION 25.212-b04
INPUT-ARGUMENTS []
CLASS-PATH /opt/arthas/arthas-demo.jar
BOOT-CLASS-PATH /usr/lib/jvm/java-1.8-openjdk/jre/lib/resources.jar:/usr/lib/jvm/java-1.8-openjdk/jre/lib/rt.jar:/usr/lib/jvm/java-1.8-openjd
k/jre/lib/sunrsasign.jar:/usr/lib/jvm/java-1.8-openjdk/jre/lib/jsse.jar:/usr/lib/jvm/java-1.8-openjdk/jre/lib/jce.jar:/usr/li
b/jvm/java-1.8-openjdk/jre/lib/charsets.jar:/usr/lib/jvm/java-1.8-openjdk/jre/lib/jfr.jar:/usr/lib/jvm/java-1.8-openjdk/jre/c
lasses
LIBRARY-PATH /usr/lib/jvm/java-1.8-openjdk/jre/lib/amd64/server:/usr/lib/jvm/java-1.8-openjdk/jre/lib/amd64:/usr/lib/jvm/java-1.8-openjdk/
jre/../lib/amd64:/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
CLASS-LOADING
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
LOADED-CLASS-COUNT 3653
TOTAL-LOADED-CLASS-COUNT 3653
UNLOADED-CLASS-COUNT 0
IS-VERBOSE false
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
COMPILATION
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
NAME HotSpot 64-Bit Tiered Compilers
TOTAL-COMPILE-TIME 11209(ms)
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
GARBAGE-COLLECTORS
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
PS Scavenge 24/347(ms)
[count/time]
PS MarkSweep 3/215(ms)
[count/time]
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
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 124780544(119.00 MiB)/33554432(32.00 MiB)/462422016(441.00MiB)/52041680(49.63 MiB)
[committed/init/max/used]
NO-HEAP-MEMORY-USAGE 35520512(33.88 MiB)/2555904(2.44 MiB)/-1(-1 B)/34438440(32.84 MiB)
[committed/init/max/used]
PENDING-FINALIZE-COUNT 0
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
OPERATING-SYSTEM
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
OS Linux
ARCH amd64
PROCESSORS-COUNT 2
LOAD-AVERAGE 0.00341796875
VERSION 4.9.125-linuxkit
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
THREAD
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
COUNT 15
DAEMON-COUNT 7
PEAK-COUNT 16
STARTED-COUNT 46
DEADLOCK-COUNT 0
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
FILE-DESCRIPTOR
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
MAX-FILE-DESCRIPTOR-COUNT 1048576
OPEN-FILE-DESCRIPTOR-COUNT 51sysprop
查看当前JVM的系统属性(System Property)
查看全部系统属性
$ sysprop
KEY VALUE
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
java.runtime.name OpenJDK Runtime Environment
sun.boot.library.path /usr/lib/jvm/java-1.8-openjdk/jre/lib/amd64
java.vm.version 25.212-b04
java.vm.vendor IcedTea
java.vendor.url https://icedtea.classpath.org
path.separator :
java.vm.name OpenJDK 64-Bit Server VM
file.encoding.pkg sun.io
user.country US
sun.java.launcher SUN_STANDARD
sun.os.patch.level unknown
java.vm.specification.name Java Virtual Machine Specification
user.dir /
java.runtime.version 1.8.0_212-b04
JM.LOG.PATH /root/logs
java.awt.graphicsenv sun.awt.X11GraphicsEnvironment
java.endorsed.dirs /usr/lib/jvm/java-1.8-openjdk/jre/lib/endorsed
os.arch amd64
java.io.tmpdir /tmp
line.separator
java.vm.specification.vendor Oracle Corporation
os.name Linux
sun.jnu.encoding UTF-8
java.library.path /usr/lib/jvm/java-1.8-openjdk/jre/lib/amd64/server:/usr/lib/jvm/java-1.8-openjdk/jre/lib/amd64:/usr/lib/jvm/java-1.8-openjdk/jre/../lib/amd6
4:/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
sun.nio.ch.bugLevel
java.specification.name Java Platform API Specification
java.class.version 52.0
sun.management.compiler HotSpot 64-Bit Tiered Compilers
os.version 4.9.125-linuxkit
user.home /root
user.timezone GMT
java.awt.printerjob sun.print.PSPrinterJob
file.encoding UTF-8
java.specification.version 1.8
user.name root
java.class.path /opt/arthas/arthas-demo.jar
java.vm.specification.version 1.8
sun.arch.data.model 64
java.home /usr/lib/jvm/java-1.8-openjdk/jre
sun.java.command /opt/arthas/arthas-demo.jar
java.specification.vendor Oracle Corporation
user.language en
awt.toolkit sun.awt.X11.XToolkit
java.vm.info mixed mode
java.version 1.8.0_212
java.ext.dirs /usr/lib/jvm/java-1.8-openjdk/jre/lib/ext:/usr/java/packages/lib/ext
sun.boot.class.path /usr/lib/jvm/java-1.8-openjdk/jre/lib/resources.jar:/usr/lib/jvm/java-1.8-openjdk/jre/lib/rt.jar:/usr/lib/jvm/java-1.8-openjdk/jre/lib/sunrs
asign.jar:/usr/lib/jvm/java-1.8-openjdk/jre/lib/jsse.jar:/usr/lib/jvm/java-1.8-openjdk/jre/lib/jce.jar:/usr/lib/jvm/java-1.8-openjdk/jre/lib
/charsets.jar:/usr/lib/jvm/java-1.8-openjdk/jre/lib/jfr.jar:/usr/lib/jvm/java-1.8-openjdk/jre/classes
java.vendor IcedTea
file.separator /
java.vendor.url.bug https://icedtea.classpath.org/bugzilla
sun.cpu.endian little
sun.io.unicode.encoding UnicodeLittle
sun.cpu.isalist查看单个系统属性
$ sysprop java.version
java.version=1.8.0_212sysenv
查看当前JVM的环境属性(System Environment Variables)
查看所有环境变量
$ sysenv
KEY VALUE
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
PATH /usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/lib/jvm/java-1.8-openjdk/jre/bin:/usr/lib/jvm/java-1.8-openjdk/bin
JAVA_HOME /usr/lib/jvm/java-1.8-openjdk
TERM xterm
MIRROR_MAVEN_HOST http://maven.aliyun.com/repository/public
MIRROR_ALPINE_HOST mirrors.aliyun.com
LANG C.UTF-8
ALPINE_HOST dl-cdn.alpinelinux.org
HOSTNAME 4425d962807f
JAVA_ALPINE_VERSION 8.212.04-r0
LD_LIBRARY_PATH /usr/lib/jvm/java-1.8-openjdk/jre/lib/amd64/server:/usr/lib/jvm/java-1.8-openjdk/jre/lib/amd64:/usr/lib/jvm/java-1.8-openjdk/jre/../lib/amd6
4
PWD /
MAVEN_HOST http://repo1.maven.org/maven2
JAVA_VERSION 8u212
HOME /root
SHLVL 1查看单个环境变量
$ sysenv HOSTNAME
HOSTNAME=4425d962807fmonitor
方法执行监控，对匹配 class-pattern／method-pattern的类、方法的调用进行监控。
| 参数名称 | 参数说明 |
|---|---|
| class-pattern | 类名表达式匹配 |
| method-pattern | 方法名表达式匹配 |
| [E] | 开启正则表达式匹配，默认为通配符匹配 |
| [c:] | 统计周期，默认值为120秒 |
$ monitor -c 5 demo.MathGame primeFactors
Press Q or Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 26 ms.
timestamp class method total success fail avg-rt(ms) fail-rate
-----------------------------------------------------------------------------------------------
2019-06-14 06:17:39 demo.MathGame primeFactors 5 2 3 0.09 60.00%
timestamp class method total success fail avg-rt(ms) fail-rate
-----------------------------------------------------------------------------------------------
2019-06-14 06:17:44 demo.MathGame primeFactors 5 3 2 0.03 40.00%
timestamp class method total success fail avg-rt(ms) fail-rate
-----------------------------------------------------------------------------------------------
2019-06-14 06:17:49 demo.MathGame primeFactors 5 2 3 0.17 60.00%
timestamp class method total success fail avg-rt(ms) fail-rate
-----------------------------------------------------------------------------------------------
2019-06-14 06:17:54 demo.MathGame primeFactors 5 2 3 0.17 60.00%
timestamp class method total success fail avg-rt(ms) fail-rate
-----------------------------------------------------------------------------------------------
2019-06-14 06:17:59 demo.MathGame primeFactors 5 2 3 0.12 60.00%
timestamp class method total success fail avg-rt(ms) fail-rate
-----------------------------------------------------------------------------------------------
2019-06-14 06:18:04 demo.MathGame primeFactors 5 3 2 0.60 40.00%- timestamp: 时间戳
- class: Java类
- method: 方法（构造方法、普通方法）
- total: 调用次数
- success: 成功次数
- fail: 失败次数
- rt: 平均RT
- fail-rate: 失败率
watch
方法执行数据观测，让你能方便的观察到指定方法的调用情况。能观察到的范围为：返回值、抛出异常、入参，通过编写 OGNL 表达式进行对应变量的查看。
| 参数名称 | 参数说明 |
|---|---|
| class-pattern | 类名表达式匹配 |
| method-pattern | 方法名表达式匹配 |
| express | 观察表达式 |
| condition-express | 条件表达式 |
| [b] | 在方法调用之前观察 |
| [e] | 在方法异常之后观察 |
| [s] | 在方法返回之后观察 |
| [f] | 在方法结束之后(正常返回和异常返回)观察，默认打开 |
| [E] | 开启正则表达式匹配，默认为通配符匹配 |
| [x:] | 指定输出结果的属性遍历深度，默认为 1 |
观察方法出参和返回值
$ watch demo.MathGame primeFactors "{params,returnObj}" -x 2
Press Q or Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 44 ms.
ts=2019-06-14 06:34:19; [cost=0.3721ms] result=@ArrayList[
@Object[][
@Integer[15013],
],
@ArrayList[
@Integer[15013],
],
]
ts=2019-06-14 06:34:20; [cost=0.1084ms] result=@ArrayList[
@Object[][
@Integer[-75392],
],
null,
]观察方法入参
$ watch demo.MathGame primeFactors "{params,returnObj}" -x 2 -b
Press Q or Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 52 ms.
ts=2019-06-14 06:35:07; [cost=0.0194ms] result=@ArrayList[
@Object[][
@Integer[31370],
],
null,
]
ts=2019-06-14 06:35:08; [cost=0.0101ms] result=@ArrayList[
@Object[][
@Integer[-82029],
],
null,
]同时观察方法调用前和方法返回后
$ watch demo.MathGame primeFactors "{params,target,returnObj}" -x 2 -b -s -n 2
Press Q or Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 40 ms.
ts=2019-06-14 06:35:57; [cost=0.0334ms] result=@ArrayList[
@Object[][
@Integer[-136522],
],
@MathGame[
random=@Random[java.util.Random@533ddba],
illegalArgumentCount=@Integer[94006],
],
null,
]
ts=2019-06-14 06:35:58; [cost=0.0098ms] result=@ArrayList[
@Object[][
@Integer[-16431],
],
@MathGame[
random=@Random[java.util.Random@533ddba],
illegalArgumentCount=@Integer[94007],
],
null,
]调整-x的值，观察具体的方法参数值
$ watch demo.MathGame primeFactors "{params,target}" -x 3
Press Q or Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 42 ms.
ts=2019-06-14 06:37:02; [cost=0.085ms] result=@ArrayList[
@Object[][
@Integer[151500],
],
@MathGame[
random=@Random[
serialVersionUID=@Long[3905348978240129619],
seed=@AtomicLong[99287665085135],
multiplier=@Long[25214903917],
addend=@Long[11],
mask=@Long[281474976710655],
DOUBLE_UNIT=@Double[1.1102230246251565E-16],
BadBound=@String[bound must be positive],
BadRange=@String[bound must be greater than origin],
BadSize=@String[size must be non-negative],
seedUniquifier=@AtomicLong[-3282039941672302964],
nextNextGaussian=@Double[0.0],
haveNextNextGaussian=@Boolean[false],
serialPersistentFields=@ObjectStreamField[][isEmpty=false;size=3],
unsafe=@Unsafe[sun.misc.Unsafe@3c9f287f],
seedOffset=@Long[24],
],
illegalArgumentCount=@Integer[94039],
],
]观察异常信息的例子
$ watch demo.MathGame primeFactors "{params[0],throwExp}" -e -x 2
Press Q or Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 33 ms.
ts=2019-06-14 06:38:20; [cost=0.3491ms] result=@ArrayList[
@Integer[-111033],
java.lang.IllegalArgumentException: number is: -111033, need >= 2
at demo.MathGame.primeFactors(MathGame.java:46)
at demo.MathGame.run(MathGame.java:24)
at demo.MathGame.main(MathGame.java:16)
,
]
ts=2019-06-14 06:38:21; [cost=0.0673ms] result=@ArrayList[
@Integer[-150545],
java.lang.IllegalArgumentException: number is: -150545, need >= 2
at demo.MathGame.primeFactors(MathGame.java:46)
at demo.MathGame.run(MathGame.java:24)
at demo.MathGame.main(MathGame.java:16)
,
]trace
方法内部调用路径，并输出方法路径上的每个节点上耗时，trace 命令能主动搜索 class-pattern／method-pattern 对应的方法调用路径，渲染和统计整个调用链路上的所有性能开销和追踪调用链路。
| 参数名称 | 参数说明 |
|---|---|
| class-pattern | 类名表达式匹配 |
| method-pattern | 方法名表达式匹配 |
| condition-express | 条件表达式 |
| [j] | 跳过JDK方法 |
| [E] | 开启正则表达式匹配，默认为通配符匹配 |
| [n:] | 命令执行次数 |
| #cost | 方法执行耗时 |
$ trace demo.MathGame run
Press Q or Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 44 ms.
`---ts=2019-06-14 06:42:24;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@70dea4e
`---[0.6678ms] demo.MathGame:run()
+---[0.0248ms] java.util.Random:nextInt() #23
+---[0.1465ms] demo.MathGame:primeFactors() #24
`---[0.1904ms] demo.MathGame:print() #25stack
输出当前方法被调用的调用路径，很多时候我们都知道一个方法被执行，但这个方法被执行的路径非常多，或者你根本就不知道这个方法是从那里被执行了，此时你需要的是 stack 命令。
| 参数名称 | 参数说明 |
|---|---|
| class-pattern | 类名表达式匹配 |
| method-pattern | 方法名表达式匹配 |
| condition-express | 条件表达式 |
| [E] | 开启正则表达式匹配，默认为通配符匹配 |
| [n:] | 命令执行次数 |
$ stack demo.MathGame primeFactors
Press Q or Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 48 ms.
ts=2019-06-14 06:48:00;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@70dea4e
@demo.MathGame.run()
at demo.MathGame.main(MathGame.java:16)tt
方法执行数据的时空隧道，记录下指定方法每次调用的入参和返回信息，并能对这些不同的时间下调用进行观测。
| 参数名称 | 参数说明 |
|---|---|
| -t | 方法的每次执行情况 |
| -n [n] | 需要记录的次数 |
| condition-express | 条件表达式 |
| -l | 对现有记录进行检索 |
| -s [express] | 对现有记录进行筛选 |
| -i [index] | 查看调用信息 |
| -p | 重做一次调用 |
| --replay-times | 指定调用次数 |
| --replay-interval | 指定调用间隔(单位ms, 默认1000ms) |
记录调用
$ tt -t demo.MathGame primeFactors
Press Q or Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 48 ms.
INDEX TIMESTAMP COST(ms) IS-RET IS-EXP OBJECT CLASS METHOD
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
1038 2019-06-14 07:13:02 0.4279 true false 0x5197848c MathGame primeFactors
1039 2019-06-14 07:13:03 16.4051 true false 0x5197848c MathGame primeFactors
1040 2019-06-14 07:13:04 0.067 true false 0x5197848c MathGame primeFactors
1041 2019-06-14 07:13:05 0.0933 true false 0x5197848c MathGame primeFactors
1042 2019-06-14 07:13:06 0.5713 true false 0x5197848c MathGame primeFactors- INDEX: 时间片段记录编号，每一个编号代表着一次调用，后续tt还有很多命令都是基于此编号指定记录操作，非常重要。
- TIMESTAMP: 方法执行的本机时间，记录了这个时间片段所发生的本机时间
- COST(ms): 方法执行的耗时
- IS-RET: 方法是否以正常返回的形式结束
- IS-EXP: 方法是否以抛异常的形式结束
- OBJECT: 执行对象的hashCode()，注意，曾经有人误认为是对象在JVM中的内存地址，但很遗憾他不是。但他能帮助你简单的标记当前执行方法的类实体
- CLASS: 执行的类名
- METHOD: 执行的方法名
对记录进行检索
$ tt -l
INDEX TIMESTAMP COST(ms) IS-RET IS-EXP OBJECT CLASS METHOD
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
1038 2019-06-14 07:13:02 0.4279 true false 0x5197848c MathGame primeFactors
1039 2019-06-14 07:13:03 16.4051 true false 0x5197848c MathGame primeFactors
1040 2019-06-14 07:13:04 0.067 true false 0x5197848c MathGame primeFactors
1041 2019-06-14 07:13:05 0.0933 true false 0x5197848c MathGame primeFactors
1042 2019-06-14 07:13:06 0.5713 true false 0x5197848c MathGame primeFactors对记录进行筛选
$ tt -s 'method.name=="primeFactors"'
INDEX TIMESTAMP COST(ms) IS-RET IS-EXP OBJECT CLASS METHOD
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
1038 2019-06-14 07:13:02 0.4279 true false 0x5197848c MathGame primeFactors
1039 2019-06-14 07:13:03 16.4051 true false 0x5197848c MathGame primeFactors
1040 2019-06-14 07:13:04 0.067 true false 0x5197848c MathGame primeFactors
1041 2019-06-14 07:13:05 0.0933 true false 0x5197848c MathGame primeFactors
1042 2019-06-14 07:13:06 0.5713 true false 0x5197848c MathGame primeFactors查看调用信息
$ tt -i 1038
INDEX 1038
GMT-CREATE 2019-06-14 07:13:02
COST(ms) 0.4279
OBJECT 0x5197848c
CLASS demo.MathGame
METHOD primeFactors
IS-RETURN true
IS-EXCEPTION false
PARAMETERS[0] @Integer[190307]
RETURN-OBJ @ArrayList[
@Integer[13],
@Integer[14639],
]重做一次调用
$ tt -i 1038 -p
RE-INDEX 1038
GMT-REPLAY 2019-06-14 07:22:58
OBJECT 0x5197848c
CLASS demo.MathGame
METHOD primeFactors
PARAMETERS[0] @Integer[190307]
IS-RETURN true
IS-EXCEPTION false
COST(ms) 0.414
RETURN-OBJ @ArrayList[
@Integer[13],
@Integer[14639],
]
Time fragment[1038] successfully replayed 1 times.jad/mc/redefine
- jad（反编译指定已加载类的源码）
- mc（Memory Compiler/内存编译器，编译.java文件生成.class）
- redefine （加载外部的.class文件，redefine jvm已加载的类）
组合使用这三个命令可以实现线上热更新代码！
Step1 jad命令反编译到磁盘文件
jad --source-only demo.MathGame > /tmp/MathGame.javaStep2 使用文本编辑器修改代码
vi /tmp/MathGame.java public static void print(int number, List<Integer> primeFactors) {
StringBuffer sb = new StringBuffer("" + number + "=");
Iterator<Integer> iterator = primeFactors.iterator();
while (iterator.hasNext()) {
int factor = iterator.next();
sb.append(factor).append('*');
}
if (sb.charAt(sb.length() - 1) == '*') {
sb.deleteCharAt(sb.length() - 1);
}
System.out.println("MyTest.......");
}Step3 mc命令来内存编译修改过的代码
$ mc /tmp/MathGame.java -d /tmp
Memory compiler output:
/tmp/demo/MathGame.classStep4 用redefine命令加载新的字节码
$ redefine /tmp/demo/MathGame.class
redefine success, size: 1现在看一下程序日志
illegalArgumentCount:96218, number is: -169877, need >= 2
illegalArgumentCount:96219, number is: -57731, need >= 2
MyTest.......
illegalArgumentCount:96220, number is: -207843, need >= 2
illegalArgumentCount:96221, number is: -193695, need >= 2
MyTest.......
illegalArgumentCount:96222, number is: -19514, need >= 2
illegalArgumentCount:96223, number is: -199441, need >= 2
illegalArgumentCount:96224, number is: -110791, need >= 2
MyTest.......
illegalArgumentCount:96225, number is: -116154, need >= 2
MyTest.......
MyTest.......
MyTest.......
MyTest.......
MyTest.......
MyTest.......果然神器~~~
