Arthas - 开源 Java 诊断工具
生活随笔
收集整理的這篇文章主要介紹了
Arthas - 开源 Java 诊断工具
小編覺得挺不錯的,現(xiàn)在分享給大家,幫大家做個參考.
轉(zhuǎn)載自??Arthas使用
Authas — 開源的java診斷工具
下載安裝
authas是一個jar包，可以直接下載后運行
wget https://alibaba.github.io/arthas/arthas-boot.jarjava -jar arthas-boot.jar就可以啟動起來。啟動后，authas會自動檢測存在的java進程，這時候需要選擇你想要診斷的進程，回車即可。如下圖所示：
?
如果不知道某個java進程的詳情，可以使用
jps -mlVv 或 ps -ef| grep java來查看.
?
常用命令
基礎命令
help——查看命令幫助信息 cat——打印文件內(nèi)容，和linux里的cat命令類似 pwd——返回當前的工作目錄，和linux命令類似 cls——清空當前屏幕區(qū)域 session——查看當前會話的信息 reset——重置增強類，將被 Arthas 增強過的類全部還原，Arthas 服務端關閉時會重置所有增強過的類 version——輸出當前目標 Java 進程所加載的 Arthas 版本號 history——打印命令歷史 quit——退出當前 Arthas 客戶端，其他 Arthas 客戶端不受影響 shutdown——關閉 Arthas 服務端，所有 Arthas 客戶端全部退出 keymap——Arthas快捷鍵列表及自定義快捷鍵JVM相關
Dashboard
dashboardUSAGE:dashboard [-b] [-i <value>] [-n <value>]SUMMARY:Overview of target jvm's thread, memory, gc, vm, tomcat info.EXAMPLES:dashboarddashboard -n 10dashboard -i 2000WIKI:https://alibaba.github.io/arthas/dashboardOPTIONS:-b, --batch Execute this command in batch mode.-i, --interval <value> The interval (in ms) between two executions, default is 5000 ms.-n, --number-of-execution <value> The number of times this command will be executed.?
可以看到，這里會顯示出線程(按照cpu占用百分比倒排)、內(nèi)存(堆空間實時情況)、GC情況等數(shù)據(jù)。
常用的參數(shù)：
-i 400ms 每次執(zhí)行間隔時間
-n 執(zhí)行多少次dashboard，不指定的話會一直刷新
thread
thread命令用來查看當前jvm中的線程信息的，如下圖所示：
?
?
可以看到，默認執(zhí)行thread命令，會直接打印出當前所有的線程。
$ threadUSAGE:thread [-b] [-i <value>] [-n <value>] [id]SUMMARY:Display thread info, thread stackEXAMPLES:threadthread 51thread -n -1thread -n 5thread -bthread -i 2000WIKI:https://alibaba.github.io/arthas/threadOPTIONS:-b, --include-blocking-th Find the thread who is holding a lock that blocks tread he most number of threads.-i, --sample-interval <va Specify the sampling interval (in ms) when calculatlue> ing cpu usage.-n, --top-n-threads <valu The number of thread(s) to show, ordered by cpu utie> lization, -1 to show all.<id> Show thread stack常用參數(shù)：
-b 查看目前block的線程
-i 5000ms 查看在接下來的多長時間內(nèi) 統(tǒng)計cpu利用率
-n 5 查看cpu占用率前5的線程的堆棧信息
<thread_id> 直接跟著線程id，可以看到thread的堆棧信息
如下：
$ thread -n 1 "as-command-execute-daemon" Id=396 cpuUsage=53% RUNNABLEat 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@21b51d37Affect(row-cnt:0) cost in 541 ms.可以看到這里占用cpu最高的一個線程的棧信息。
jvm
查看當前jvm信息
sysprop
查看和修改JVM的系統(tǒng)屬性
sysenv
查看JVM的環(huán)境變量
getstatic
查看類的靜態(tài)屬性
class/classloader相關
mc
Memory Compiler/內(nèi)存編譯器，編譯.java文件生成.class。
mc /tmp/Test.javaredefine
加載外部的.class文件，redefine jvm已加載的類。
redefine /tmp/Test.class redefine -c 327a647b /tmp/Test.class /tmp/Test\$Inner.classsc
Search class
查看jvm中已加載的類，不過直接執(zhí)行sc并沒有太多信息，如下：
$ sc com.google.common.hash.HashFunction com.google.common.hash.AbstractHashFunction com.google.common.hash.HashFunction com.google.common.hash.MessageDigestHashFunction Affect(row-cnt:3) cost in 213 ms.需要加入-d參數(shù)，如下
$ sc -d com.google.common.hash.HashFunctionclass-info com.google.common.hash.AbstractHashFunctioncode-sourcename com.google.common.hash.AbstractHashFunctionisInterface falseisAnnotation falseisEnum falseisAnonymousClass falseisArray falseisLocalClass falseisMemberClass falseisPrimitive falseisSynthetic falsesimple-name AbstractHashFunctionmodifier abstractannotation com.google.errorprone.annotations.Immutableinterfaces com.google.common.hash.HashFunctionsuper-class +-java.lang.Objectclass-loader +-com.intellij.util.lang.UrlClassLoader@277050dcclassLoaderHash 277050dcclass-info com.google.common.hash.HashFunctioncode-sourcename com.google.common.hash.HashFunctionisInterface trueisAnnotation falseisEnum falseisAnonymousClass falseisArray falseisLocalClass falseisMemberClass falseisPrimitive falseisSynthetic falsesimple-name HashFunctionmodifier abstract,interface,publicannotation com.google.errorprone.annotations.Immutableinterfacessuper-classclass-loader +-com.intellij.util.lang.UrlClassLoader@277050dcclassLoaderHash 277050dcclass-info com.google.common.hash.MessageDigestHashFunctioncode-sourcename com.google.common.hash.MessageDigestHashFunctionisInterface falseisAnnotation falseisEnum falseisAnonymousClass falseisArray falseisLocalClass falseisMemberClass falseisPrimitive falseisSynthetic falsesimple-name MessageDigestHashFunctionmodifier finalannotation com.google.errorprone.annotations.Immutableinterfaces java.io.Serializablesuper-class +-com.google.common.hash.AbstractHashFunction+-java.lang.Objectclass-loader +-com.intellij.util.lang.UrlClassLoader@277050dcclassLoaderHash 277050dcAffect(row-cnt:3) cost in 102 ms.可以看到這里有更詳細的信息。
具體的參數(shù)如下：
$ help scUSAGE:sc [-d] [-x <value>] [-f] [-h] [-E] class-patternSUMMARY:Search all the classes loaded by JVMEXAMPLES:sc -d org.apache.commons.lang.StringUtilssc -d org/apache/commons/lang/StringUtilssc -d *StringUtilssc -d -f org.apache.commons.lang.StringUtilssc -E org\\.apache\\.commons\\.lang\\.StringUtilsWIKI:https://alibaba.github.io/arthas/scOPTIONS:-d, --details Display the details of class-x, --expand <value> Expand level of object (0 by default)-f, --field Display all the member variables-h, --help this help-E, --regex Enable regular expression to match (wildcard matching by default)<class-pattern> Class name pattern, use either '.' or '/' as separatorsm
search method
$ sm xx.xxx.xx.xx.xxx.xx.CouponService xx.xxx.xx.xx.xxx.xx.CouponServiceImpl <init>()V xx.xxx.xx.xx.xxx.xx.CouponServiceImpl matchCouponOnShopIds(Ljava/lang/Long;Ljava/util/List;)Ljava/util/Map; xx.xxx.xx.xx.xxx.xx.CouponServiceImpl$$EnhancerByGuice$$9b64c3b8 <init>()V xx.xxx.xx.xx.xxx.xx.CouponServiceImpl$$EnhancerByGuice$$9b64c3b8 CGLIB$matchCouponOnShopIds$0(Ljava/lang/Long;Ljava/util/List;)Ljava/util/Map; xx.xxx.xx.xx.xxx.xx.CouponServiceImpl$$EnhancerByGuice$$9b64c3b8 CGLIB$SET_THREAD_CALLBACKS([Lcom/google/inject/internal/cglib/pr$ oxy/$Callback;)V xx.xxx.xx.xx.xxx.xx.CouponServiceImpl$$EnhancerByGuice$$9b64c3b8 CGLIB$SET_STATIC_CALLBACKS([Lcom/google/inject/internal/cglib/proxy/$Callback;)V xx.xxx.xx.xx.xxx.xx.CouponServiceImpl$$EnhancerByGuice$$9b64c3b8 CGLIB$STATICHOOK35()V xx.xxx.xx.xx.xxx.xx.CouponServiceImpl$$EnhancerByGuice$$9b64c3b8 CGLIB$BIND_CALLBACKS(Ljava/lang/Object;)V xx.xxx.xx.xx.xxx.xx.CouponServiceImpl$$EnhancerByGuice$$9b64c3b8 CGLIB$findMethodProxy(Lcom/google/inject/internal/cglib/core/$Signature;)Lcom/google/inject/internal/cglib/proxy/$MethodProxy; xx.xxx.xx.xx.xxx.xx.CouponServiceImpl$$EnhancerByGuice$$9b64c3b8 matchCouponOnShopIds(Ljava/lang/Long;Ljava/util/List;)Ljava/util/Map; xx.xxx.xx.xx.xxx.xx.CouponService matchCouponOnShopIds(Ljava/lang/Long;Ljava/util/List;)Ljava/util/Map; com.sun.proxy.$Proxy197 <init>(Ljava/lang/reflect/InvocationHandler;)V com.sun.proxy.$Proxy197 matchCouponOnShopIds(Ljava/lang/Long;Ljava/util/List;)Ljava/util/Map; com.sun.proxy.$Proxy197 equals(Ljava/lang/Object;)Z com.sun.proxy.$Proxy197 toString()Ljava/lang/String; com.sun.proxy.$Proxy197 hashCode()I Affect(row-cnt:16) cost in 53 ms.可以看到，通過sm命令可以查到對應類的所有方法
通過加入-d參數(shù)可以獲取method的信息信息
$ sm xx.xxx.xx.xx.xxx.xx.CouponService -ddeclaring-class xx.xxx.xx.xx.xxx.xx.CouponServiceImplconstructor-name <init>modifier publicannotationparametersexceptionsdeclaring-class xx.xxx.xx.xx.xxx.xx.CouponServiceImplmethod-name matchCouponOnShopIdsmodifier publicannotationparameters java.lang.Longjava.util.Listreturn java.util.Mapexceptions xx.xxx.xx.xx.xxx.xx.ServiceException...sh
jad
反編譯代碼，如下
$ jad com.google.common.hash.HashFunctionClassLoader: +-com.intellij.util.lang.UrlClassLoader@277050dcLocation:/** Decompiled with CFR 0_132.** Could not load the following classes:* com.google.common.hash.Funnel* com.google.common.hash.HashCode* com.google.common.hash.Hasher* com.google.errorprone.annotations.Immutable*/ package com.google.common.hash;import com.google.common.hash.Funnel; import com.google.common.hash.HashCode; import com.google.common.hash.Hasher; import com.google.errorprone.annotations.Immutable; import java.nio.ByteBuffer; import java.nio.charset.Charset;@Immutable public interface HashFunction {public int bits();public HashCode hashLong(long var1);public HashCode hashInt(int var1);public <T> HashCode hashObject(T var1, Funnel<? super T> var2);public HashCode hashUnencodedChars(CharSequence var1);public HashCode hashString(CharSequence var1, Charset var2);public HashCode hashBytes(ByteBuffer var1);public HashCode hashBytes(byte[] var1, int var2, int var3);public HashCode hashBytes(byte[] var1);public Hasher newHasher();public Hasher newHasher(int var1); }Affect(row-cnt:1) cost in 1730 ms.classloader
查看classloader的繼承樹，urls，類加載信息
?
查看其參數(shù)如下
$ help classloaderUSAGE:classloader [-a] [-c <value>] [-h] [-i] [-l] [--load <value>] [-r <value>] [-t]SUMMARY:Show classloader infoEXAMPLES:classloaderclassloader -tclassloader -lclassloader -c 327a647bclassloader -c 327a647b -r META-INF/MANIFEST.MFclassloader -aclassloader -a -c 327a647bclassloader -c 659e0bfd --load demo.MathGameWIKI:https://alibaba.github.io/arthas/classloaderOPTIONS:-a, --all Display all classes loaded by ClassLoader-c, --classloader <value> The hash code of the special ClassLoader-h, --help this help-i, --include-reflection-classloader Include sun.reflect.DelegatingClassLoader-l, --list-classloader Display statistics info by classloader instance--load <value> Use ClassLoader to load class, won't work without -c specified-r, --resource <value> Use ClassLoader to find resources, won't work without -c specified-t, --tree Display ClassLoader tree-t : 把classloader的樹打印出來，也會打印出來粗略的hashcode
-l : 根據(jù)classloader實例的個數(shù)來打印classloader，會打印出來hashcode
-c : 用classloader對應的hashcode 來查看對應的jar urls
查看classloader tree信息
$ classloader -t +-BootstrapClassLoader +-sun.misc.Launcher$ExtClassLoader@6379eb+-com.taobao.arthas.agent.ArthasClassloader@5ab570f5+-sun.misc.Launcher$AppClassLoader@18b4aac2+-com.alibaba.fastjson.util.ASMClassLoader@34c3f8d2+-com.alibaba.fastjson.util.ASMClassLoader@463b35ac+-com.alibaba.jvm.sandbox.agent.SandboxClassLoader@567d299b+-ModuleClassLoader[crc32=3750510264;file=/data/.ewatch/ewatch-install/sandbox/lib/../module/sandbox-mgr-module.jar;]+-ModuleClassLoader[crc32=2030492332;file=/data/.ewatch/ewatch-install/sandbox/ewatch/ewatch-agent-jar-with-dependencies.jar;]+-com.alibaba.jvm.sandbox.core.classloader.ProviderClassLoader@42f93a98 Affect(row-cnt:10) cost in 20 ms.查看URLClassLoader實際的urls
$ classloader -c 5ab570f5 file:/root/.arthas/lib/3.1.1/arthas/arthas-core.jarAffect(row-cnt:1790) cost in 19 ms.使用ClassLoader去查找resource
$ classloader -c 3d4eac69 -r META-INF/MANIFEST.MFjar:file:/System/Library/Java/Extensions/MRJToolkit.jar!/META-INF/MANIFEST.MFjar:file:/private/tmp/arthas-demo.jar!/META-INF/MANIFEST.MFjar:file:/Users/hengyunabc/.arthas/lib/3.0.5/arthas/arthas-agent.jar!/META-INF/MANIFEST.MF也可以嘗試查找類的class文件：
$ classloader -c 1b6d3586 -r java/lang/String.classjar:file:/Library/Java/JavaVirtualMachines/jdk1.8.0_60.jdk/Contents/Home/jre/lib/rt.jar!/java/lang/String.class使用ClassLoader去加載類
$ classloader -c 3d4eac69 --load demo.MathGame load class success.class-info demo.MathGamecode-source /private/tmp/arthas-demo.jarname demo.MathGameisInterface falseisAnnotation falseisEnum falseisAnonymousClass falseisArray falseisLocalClass falseisMemberClass falseisPrimitive falseisSynthetic falsesimple-name MathGamemodifier publicannotationinterfacessuper-class +-java.lang.Objectclass-loader +-sun.misc.Launcher$AppClassLoader@3d4eac69+-sun.misc.Launcher$ExtClassLoader@66350f69classLoaderHash 3d4eac69monitor/watch/trace相關
monitor
對匹配 class-pattern／method-pattern的類、方法的調(diào)用進行監(jiān)控。
monitor 命令是一個非實時返回命令.
實時返回命令是輸入之后立即返回，而非實時返回的命令，則是不斷的等待目標 Java 進程返回信息，直到用戶輸入 Ctrl+C 為止。
服務端是以任務的形式在后臺跑任務，植入的代碼隨著任務的中止而不會被執(zhí)行，所以任務關閉后，不會對原有性能產(chǎn)生太大影響，而且原則上，任何Arthas命令不會引起原有業(yè)務邏輯的改變。
監(jiān)控的維度說明
| timestamp | 時間戳 |
| class | Java類 |
| method | 方法（構造方法、普通方法） |
| total | 調(diào)用次數(shù) |
| success | 成功次數(shù) |
| fail | 失敗次數(shù) |
| rt | 平均RT |
| fail-rate | 失敗率 |
?
$ monitor -c 5 demo.MathGame primeFactors Press Ctrl+C to abort. Affect(class-cnt:1 , method-cnt:1) cost in 94 ms.timestamp class method total success fail avg-rt(ms) fail-rate -----------------------------------------------------------------------------------------------2018-12-03 19:06:38 demo.MathGame primeFactors 5 1 4 1.15 80.00%timestamp class method total success fail avg-rt(ms) fail-rate -----------------------------------------------------------------------------------------------2018-12-03 19:06:43 demo.MathGame primeFactors 5 3 2 42.29 40.00%timestamp class method total success fail avg-rt(ms) fail-rate -----------------------------------------------------------------------------------------------2018-12-03 19:06:48 demo.MathGame primeFactors 5 3 2 67.92 40.00%timestamp class method total success fail avg-rt(ms) fail-rate -----------------------------------------------------------------------------------------------2018-12-03 19:06:53 demo.MathGame primeFactors 5 2 3 0.25 60.00%timestamp class method total success fail avg-rt(ms) fail-rate -----------------------------------------------------------------------------------------------2018-12-03 19:06:58 demo.MathGame primeFactors 1 1 0 0.45 0.00%timestamp class method total success fail avg-rt(ms) fail-rate -----------------------------------------------------------------------------------------------2018-12-03 19:07:03 demo.MathGame primeFactors 2 2 0 3182.72 0.00%watch
查看函數(shù)的參數(shù)、返回值、異常信息，如果有請求觸發(fā)，就回打印對應的數(shù)據(jù)。用法如下
$ help watchUSAGE:watch [-b] [-e] [-x <value>] [-f] [-h] [-n <value>] [-E] [-M <value>] [-s] class-pattern method-pattern express [condition-express]SUMMARY:Display the input/output parameter, return object, and thrown exception of specified method invocationThe express may be one of the following expression (evaluated dynamically):target : the objectclazz : the object's classmethod : the constructor or methodparams : the parameters array of methodparams[0..n] : the element of parameters arrayreturnObj : the returned object of methodthrowExp : the throw exception of methodisReturn : the method ended by returnisThrow : the method ended by throwing exception#cost : the execution time in ms of method invocationExamples:watch -b org.apache.commons.lang.StringUtils isBlank paramswatch -f org.apache.commons.lang.StringUtils isBlank returnObjwatch org.apache.commons.lang.StringUtils isBlank '{params, target, returnObj}' -x 2watch -bf *StringUtils isBlank paramswatch *StringUtils isBlank params[0]watch *StringUtils isBlank params[0] params[0].length==1watch *StringUtils isBlank params '#cost>100'watch -E -b org\.apache\.commons\.lang\.StringUtils isBlank params[0]OPTIONS:-b, --before Watch before invocation-e, --exception Watch after throw exception-x, --expand <value> Expand level of object (1 by default)-f, --finish Watch after invocation, enable by default-h, --help this help-n, --limits <value> Threshold of execution times-E, --regex Enable regular expression to match (wildcard matching by default)-M, --sizeLimit <value> Upper size limit in bytes for the result (10 * 1024 * 1024 by default)-s, --success Watch after successful invocation<class-pattern> The full qualified class name you want to watch<method-pattern> The method name you want to watch<express> the content you want to watch, written by ognl.Examples:paramsparams[0]'params[0]+params[1]''{params[0], target, returnObj}'returnObjthrowExptargetclazzmethod<condition-express> Conditional expression in ognl style, for example:TRUE : 1==1TRUE : trueFALSE : falseTRUE : 'params.length>=0'FALSE : 1==2具體執(zhí)行如下（查看請求參數(shù)）：
$ watch xxx.xxx.xxx.xxx.BerlinService view paramsPress Q or Ctrl+C to abort. Affect(class-cnt:3 , method-cnt:3) cost in 393 ms. ts=2019-05-17 14:43:36; [cost=37.391098ms] result=@Object[][@BerlinRequest[BerlinRequest(activityId=RC_12, userId=309314913, latitude=31.224360913038254, longitude=121.55064392834902, userAgent=Rajax/1 MI_MAX/helium Android/7.0 Display/NRD90M me/8.16.1 Channel/tengxun ID/e75ef7ec-4069-38ee-83c4-51fb7067f3e1; KERNEL_VERSION:3.10.84-perf-gd39c060 API_Level:24 Hardware: Mozilla/5.0 (Linux; Android 7.0; MI MAX Build/NRD90M; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/64.0.3282.137 Mobile Safari/537.36 AliApp(ELMC/8.16.1) TTID/offical WindVane/8.5.0,UT4Aplus/0.2.16, deviceId=null, limit=8, offset=0)], ] ts=2019-05-17 14:43:36; [cost=46.358372ms] result=@Object[][@BerlinRequest[BerlinRequest(activityId=RC_12, userId=309314913, latitude=31.224360913038254, longitude=121.55064392834902, userAgent=Rajax/1 MI_MAX/helium Android/7.0 Display/NRD90M me/8.16.1 Channel/tengxun ID/e75ef7ec-4069-38ee-83c4-51fb7067f3e1; KERNEL_VERSION:3.10.84-perf-gd39c060 API_Level:24 Hardware: Mozilla/5.0 (Linux; Android 7.0; MI MAX Build/NRD90M; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/64.0.3282.137 Mobile Safari/537.36 AliApp(ELMC/8.16.1) TTID/offical WindVane/8.5.0,UT4Aplus/0.2.16, deviceId=null, limit=8, offset=0)], ]查看請求參數(shù)及相應
$ watch xx.xxx.xx.xx.xxx.xx.BerlinService view '{params[0], returnObj}'Press Q or Ctrl+C to abort. Affect(class-cnt:3 , method-cnt:3) cost in 416 ms. ts=2019-05-17 14:52:38; [cost=33.968815ms] result=@ArrayList[@BerlinRequest[BerlinRequest(activityId=RC_12, userId=117043063, latitude=22.682775497436523, longitude=114.04010772705078, userAgent=Rajax/1 Apple/iPhone9,2 iOS/12.2 me/8.16.3 ID/6E92FDB8-FF9F-4F11-BC1A-490E67B39047; IsJailbroken/0 ASI/30F47DE7-0DE5-488E-A479-C94EB9284301 Mozilla/5.0 (iPhone; CPUiPhone OS 12_2 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 AliApp(ELMC/8.16.3) UT4Aplus/0.0.4 WindVane/8.5.0 1242x2208 WK, deviceId=null, limit=8, offset=0)],@BerlinCommonResponse[xx.xxx.xx.xx.xxx.xx.BerlinCommonResponse@4c5df030], ]可以看到，包含了請求及相應數(shù)據(jù)、整體cost-time,不過需要注意的是，這里并沒有打印出所有詳細數(shù)據(jù)。如果需要打印所有數(shù)據(jù)，加入-x參數(shù)表示遍歷深度，可以調(diào)整來打印具體的參數(shù)和結果內(nèi)容。默認-x 的深度為1，可以指定 2 3 等,如下：
$ watch xx.xxx.xx.xx.xxx.xx.BerlinService view '{params, returnObj}' -x 2 ts=2019-05-20 11:12:57; [cost=41.677987ms] result=@ArrayList[@Object[][@BerlinRequest[BerlinRequest(activityId=RC_12, userId=840800602, latitude=36.042474, longitude=103.849928, userAgent=Mozilla/5.0 (Linux; U; Android 8.1.0; zh-CN; DUB-AL00 Build/HUAWEIDUB-AL00) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/57.0.2987.108 UCBrowser/11.8.8.968 UWS/2.13.2.74 Mobile Safari/537.36 UCBS/2.13.2.74_190419112332 NebulaSDK/1.8.100112 Nebula AlipayDefined(nt:4G,ws:360|0|2.0) AliApp(AP/10.1.62.5549) AlipayClient/10.1.62.5549 Language/zh-Hans useStatusBar/true isConcaveScreen/true, deviceId=null, limit=8, offset=0)],],@BerlinCommonResponse[code=@String[200],message=@String[成功],data=@ArrayList[isEmpty=false;size=7],], ]如過需要按照耗時進行過濾，需要加入： '#cost>200' 代表耗時超過200ms的才會打印出來。
watch/stack/trace這個三個命令都支持#cost
trace
方法內(nèi)部調(diào)用路徑，并輸出方法路徑上的每個節(jié)點上耗時
查看help
$ help traceUSAGE:trace [-h] [-j] [-n <value>] [-p <value>] [-E] class-pattern method-pattern [condition-express]SUMMARY:Trace the execution time of specified method invocation.FALSE : falseTRUE : 'params.length>=0'FALSE : 1==2The express may be one of the following expression (evaluated dynamically):target : the objectclazz : the object's classmethod : the constructor or methodparams : the parameters array of methodparams[0..n] : the element of parameters arrayreturnObj : the returned object of methodthrowExp : the throw exception of methodisReturn : the method ended by returnisThrow : the method ended by throwing exception#cost : the execution time in ms of method invocationEXAMPLES:trace org.apache.commons.lang.StringUtils isBlanktrace *StringUtils isBlanktrace *StringUtils isBlank params[0].length==1trace *StringUtils isBlank '#cost>100'trace -E org\\.apache\\.commons\\.lang\\.StringUtils isBlanktrace -E com.test.ClassA|org.test.ClassB method1|method2|method3WIKI:https://alibaba.github.io/arthas/traceOPTIONS:-h, --help this help-j, --jdkMethodSkip skip jdk method trace-n, --limits <value> Threshold of execution times-p, --path <value> path tracing pattern-E, --regex Enable regular expression to match (wildcard matching by default)<class-pattern> Class name pattern, use either '.' or '/' as separator<method-pattern> Method name pattern<condition-express> Conditional expression in ognl style, for example:TRUE : 1==1TRUE : true平時主要使用-j (忽略jdk method trace)、'#cost>10'(過濾耗時時間) -n (執(zhí)行次數(shù))
$ trace xx.xxx.xx.xx.xxx.xx.QueryAction queryByReq -j '#cost>5' -n 5Press Q or Ctrl+C to abort. Affect(class-cnt:1 , method-cnt:1) cost in 781 ms. `---ts=2019-05-20 15:27:10;thread_name=thread-272;id=1fb;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@18b4aac2`---[12.250248ms] xx.xxx.xx.xx.xxx.xx.QueryAction:queryByReq()......stack
輸出當前方法被調(diào)用的調(diào)用路徑
很多時候我們都知道一個方法被執(zhí)行，但這個方法被執(zhí)行的路徑非常多，或者你根本就不知道這個方法是從那里被執(zhí)行了，此時你需要的是 stack 命令。
主要使用-n 命令，用于控制執(zhí)行次數(shù)
stack xx.xxx.xx.xx.xxx.xx.QueryAction queryByReq -n 1tt
先看個例子
$ tt -t xx.xxx.xx.xx.xxx.xx.QueryAction queryByReq -n 5 Press Q or Ctrl+C to abort. Affect(class-cnt:1 , method-cnt:1) cost in 995 ms.IND TIMESTAMP COST( IS- IS OBJECT CLASS METHODEX ms) RET -EXP --------------------------------------------------------------------------------100 2019-05-20 17.52 tru fa 0x7df629 QueryValidSkuAct queryValidSkuActi5 15:41:29 694 e ls 87 ivityAction vityByReqe100 2019-05-20 10.26 tru fa 0x4bb52c QueryValidSkuAct queryValidSkuActi6 15:41:29 7017 e ls 96 ivityAction vityByReqe100 2019-05-20 19.80 tru fa 0x20d351 QueryValidSkuAct queryValidSkuActi7 15:41:29 7279 e ls d3 ivityAction vityByReqe100 2019-05-20 19.84 tru fa 0x286366 QueryValidSkuAct queryValidSkuActi8 15:41:29 4526 e ls b4 ivityAction vityByReqe100 2019-05-20 19.91 tru fa 0x31297b QueryValidSkuAct queryValidSkuActi9 15:41:29 0582 e ls 01 ivityAction vityByReqe Command execution times exceed limit: 5, so command will exit. You can set it with -n option.101 2019-05-20 19.94 tru fa 0x7a3c2f QueryValidSkuAct queryValidSkuActi0 15:41:29 8529 e ls c4 ivityAction vityByReq- 表格字段說明
| INDEX | 時間片段記錄編號，每一個編號代表著一次調(diào)用，后續(xù)tt還有很多命令都是基于此編號指定記錄操作，非常重要。 |
| TIMESTAMP | 方法執(zhí)行的本機時間，記錄了這個時間片段所發(fā)生的本機時間 |
| COST(ms) | 方法執(zhí)行的耗時 |
| IS-RET | 方法是否以正常返回的形式結束 |
| IS-EXP | 方法是否以拋異常的形式結束 |
| OBJECT | 執(zhí)行對象的hashCode()，注意，曾經(jīng)有人誤認為是對象在JVM中的內(nèi)存地址，但很遺憾他不是。但他能幫助你簡單的標記當前執(zhí)行方法的類實體 |
| CLASS | 執(zhí)行的類名 |
| METHOD | 執(zhí)行的方法名 |
-t
tt 命令有很多個主參數(shù)，-t 就是其中之一。這個參數(shù)的表明希望記錄下類 *Test 的 print 方法的每次執(zhí)行情況。
-n 3
當你執(zhí)行一個調(diào)用量不高的方法時可能你還能有足夠的時間用 CTRL+C 中斷 tt 命令記錄的過程，但如果遇到調(diào)用量非常大的方法，瞬間就能將你的 JVM 內(nèi)存撐爆。
此時你可以通過 -n 參數(shù)指定你需要記錄的次數(shù)，當達到記錄次數(shù)時 Arthas 會主動中斷tt命令的記錄過程，避免人工操作無法停止的情況。
檢索調(diào)用記錄
當你用 tt 記錄了一大片的時間片段之后，你希望能從中篩選出自己需要的時間片段，這個時候你就需要對現(xiàn)有記錄進行檢索。
假設我們有這些記錄
$ tt -lINDEX TIMESTAMP COST(ms) IS-RET IS-EXP OBJECT CLASS METHOD -------------------------------------------------------------------------------------------------------------------------------------1000 2018-12-04 11:15:38 1.096236 false true 0x4b67cf4d MathGame primeFactors1001 2018-12-04 11:15:39 0.191848 false true 0x4b67cf4d MathGame primeFactors1002 2018-12-04 11:15:40 0.069523 false true 0x4b67cf4d MathGame primeFactors1003 2018-12-04 11:15:41 0.186073 false true 0x4b67cf4d MathGame primeFactors1004 2018-12-04 11:15:42 17.76437 true false 0x4b67cf4d MathGame primeFactors91005 2018-12-04 11:15:43 0.4776 false true 0x4b67cf4d MathGame primeFactors Affect(row-cnt:6) cost in 4 ms.我需要篩選出 primeFactors 方法的調(diào)用信息
$ tt -s 'method.name=="primeFactors"'INDEX TIMESTAMP COST(ms) IS-RET IS-EXP OBJECT CLASS METHOD -------------------------------------------------------------------------------------------------------------------------------------1000 2018-12-04 11:15:38 1.096236 false true 0x4b67cf4d MathGame primeFactors1001 2018-12-04 11:15:39 0.191848 false true 0x4b67cf4d MathGame primeFactors1002 2018-12-04 11:15:40 0.069523 false true 0x4b67cf4d MathGame primeFactors1003 2018-12-04 11:15:41 0.186073 false true 0x4b67cf4d MathGame primeFactors1004 2018-12-04 11:15:42 17.76437 true false 0x4b67cf4d MathGame primeFactors91005 2018-12-04 11:15:43 0.4776 false true 0x4b67cf4d MathGame primeFactors Affect(row-cnt:6) cost in 607 ms.你需要一個 -s 參數(shù)。同樣的，搜索表達式的核心對象依舊是 Advice 對象。
查看調(diào)用信息
對于具體一個時間片的信息而言，你可以通過 -i 參數(shù)后邊跟著對應的 INDEX 編號查看到他的詳細信息。
$ tt -i 1003INDEX 1003GMT-CREATE 2018-12-04 11:15:41COST(ms) 0.186073OBJECT 0x4b67cf4dCLASS demo.MathGameMETHOD primeFactorsIS-RETURN falseIS-EXCEPTION truePARAMETERS[0] @Integer[-564322413]THROW-EXCEPTION java.lang.IllegalArgumentException: number is: -564322413, need >= 2at demo.MathGame.primeFactors(MathGame.java:46)at demo.MathGame.run(MathGame.java:24)at demo.MathGame.main(MathGame.java:16)Affect(row-cnt:1) cost in 11 ms.重做一次調(diào)用
當你稍稍做了一些調(diào)整之后，你可能需要前端系統(tǒng)重新觸發(fā)一次你的調(diào)用，此時得求爺爺告奶奶的需要前端配合聯(lián)調(diào)的同學再次發(fā)起一次調(diào)用。而有些場景下，這個調(diào)用不是這么好觸發(fā)的。
tt 命令由于保存了當時調(diào)用的所有現(xiàn)場信息，所以我們可以自己主動對一個 INDEX 編號的時間片自主發(fā)起一次調(diào)用，從而解放你的溝通成本。此時你需要 -p 參數(shù)。通過 --replay-times 指定 調(diào)用次數(shù)，通過 --replay-interval 指定多次調(diào)用間隔(單位ms, 默認1000ms)
$ tt -i 1004 -pRE-INDEX 1004GMT-REPLAY 2018-12-04 11:26:00OBJECT 0x4b67cf4dCLASS demo.MathGameMETHOD primeFactorsPARAMETERS[0] @Integer[946738738]IS-RETURN trueIS-EXCEPTION falseCOST(ms) 0.186073RETURN-OBJ @ArrayList[@Integer[2],@Integer[11],@Integer[17],@Integer[2531387],] Time fragment[1004] successfully replayed. Affect(row-cnt:1) cost in 14 ms.你會發(fā)現(xiàn)結果雖然一樣，但調(diào)用的路徑發(fā)生了變化，有原來的程序發(fā)起變成了 Arthas 自己的內(nèi)部線程發(fā)起的調(diào)用了。
-
需要強調(diào)的點
-
ThreadLocal 信息丟失
很多框架偷偷的將一些環(huán)境變量信息塞到了發(fā)起調(diào)用線程的 ThreadLocal 中，由于調(diào)用線程發(fā)生了變化，這些 ThreadLocal 線程信息無法通過 Arthas 保存，所以這些信息將會丟失。
一些常見的 CASE 比如：鷹眼的 TraceId 等。
-
引用的對象
需要強調(diào)的是，tt 命令是將當前環(huán)境的對象引用保存起來，但僅僅也只能保存一個引用而已。如果方法內(nèi)部對入?yún)⑦M行了變更，或者返回的對象經(jīng)過了后續(xù)的處理，那么在 tt 查看的時候?qū)o法看到當時最準確的值。這也是為什么 watch 命令存在的意義。
?
總結
以上是生活随笔為你收集整理的Arthas - 开源 Java 诊断工具的全部內(nèi)容，希望文章能夠幫你解決所遇到的問題。
- 上一篇： 你想要的EXCEL表格操作都在这里怎么在
- 下一篇： Java JVM总结