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.htmldashboard
檢視目前系統的實時資料面闆（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@31a6493e jvm
檢視目前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 51 sysprop
檢視目前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_212 sysenv
檢視目前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=4425d962807f monitor
方法執行監控，對比對 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 表達式進行對應變量的檢視。
| express | 觀察表達式 |
| condition-express | 條件表達式 |
| 在方法調用之前觀察 | |
| [e] | 在方法異常之後觀察 |
| [s] | 在方法傳回之後觀察 |
| [f] | 在方法結束之後(正常傳回和異常傳回)觀察，預設打開 |
| [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 對應的方法調用路徑，渲染和統計整個調用鍊路上的所有性能開銷和追蹤調用鍊路。
| [j] | 跳過JDK方法 |
| 指令執行次數 | |
| #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() #25 stack
輸出目前方法被調用的調用路徑，很多時候我們都知道一個方法被執行，但這個方法被執行的路徑非常多，或者你根本就不知道這個方法是從那裡被執行了，此時你需要的是 stack 指令。
$ 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] | 需要記錄的次數 |
| -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.java Step2 使用文本編輯器修改代碼
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.class Step4 用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....... 果然神器~~~
![GitHub連夜封殺！這份阿裡 10W 字内部 Java 字面試手冊到底有多強？[圖]](data:image/gif;base64,R0lGODlhAQABAIAAAP///wAAACwAAAAAAQABAAACAkQBADs=)