arthas学习
启动arthas：
wget https://alibaba.github.io/arthas/arthas-boot.jar
使用aliyun的镜像：java -jar arthas-boot.jar --repo-mirror aliyun --use-http
命令：
查看dashboard
通过thread命令来获取到arthas-demo进程的Main Class
thread 1会打印线程ID 1的栈，通常是main函数的线程。
$ thread 1 | grep 'main('
at demo.MathGame.main(MathGame.java:17)
通过jad来反编绎Main Class
$ jad demo.MathGame
watch命令
通过watch命令来查看demo.MathGame#primeFactors函数的返回值
$ watch demo.MathGame primeFactors returnObj
观察方法出参和返回值
$ watch demo.MathGame primeFactors "{params,returnObj}" -x 2
观察方法入参
$ watch demo.MathGame primeFactors "{params,returnObj}" -x 2 -b
条件限制 - #只有满足条件的调用，才会有响应
$ watch demo.MathGame primeFactors "{params[0],target}" "params[0]<0"
观察异常信息的例子
$ watch demo.MathGame primeFactors "{params[0],throwExp}" -e -x 2
按照耗时进行过滤 - #cost>200(单位是ms)
#watch/stack/trace这个三个命令都支持#cost
$ watch demo.MathGame primeFactors '{params, returnObj}' '#cost>200' -x 2
观察当前对象中的属性
$ watch demo.MathGame primeFactors 'target'
使用target.field_name访问当前对象的某个属性
$ watch demo.MathGame primeFactors 'target.illegalArgumentCount'
观察类中所有抛出异常的方法信息
$ watch com.example.UserService * -e -x 2 '{params,throwExp}'
同时观察方法调用前和方法返回后
#参数里-n 2，表示只执行两次
#结果的输出顺序和事件发生的先后顺序一致，和命令中 -s -b 的顺序无关
#-x表示遍历深度，可以调整来打印具体的参数和结果内容，默认值是1
$ watch demo.MathGame primeFactors "{params,target,returnObj}" -x 2 -b -s -n 2
特别说明
- watch 命令定义了4个观察事件点，即 -b 方法调用前，-e 方法异常后，-s 方法返回后，-f 方法结束后
- 4个观察事件点 -b、-e、-s 默认关闭，-f 默认打开，当指定观察点被打开后，在相应事件点会对观察表达式进行求值并输出
- 这里要注意方法入参和方法出参的区别，有可能在中间被修改导致前后不一致，除了 -b 事件点 params 代表方法入参外，其余事件都代表方法出参
- 当使用 -b 时，由于观察事件点是在方法调用前，此时返回值或异常均不存在
观察表达式的构成主要由 ognl 表达式组成，所以你可以这样写"{params,returnObj}"，只要是一个合法的 ognl 表达式，都能被正常支持。观察的维度也比较多，主要体现在参数 advice 的数据结构上。Advice 参数最主要是封装了通知节点的所有信息。
用法：https://alibaba.github.io/arthas/advice-class.html
如果只是退出当前的连接，可以用quit或者exit命令。Attach到目标进程上的arthas还会继续运行，端口会保持开放，下次连接时可以直接连接上。
如果想完全退出arthas，可以执行shutdown命令。
jvm相关
- dashboard——当前系统的实时数据面板
- thread——查看当前 JVM 的线程堆栈信息
- jvm——查看当前 JVM 的信息
- sysprop——查看和修改JVM的系统属性
- sysenv——查看JVM的环境变量
- getstatic——查看类的静态属性
- New! ognl——执行ognl表达式
mc 编译指令
Memory Compiler/内存编绎器，编绎.java文件生成.class。
mc /tmp/Test.java
可以通过-c参数指定classloader：
mc -c 327a647b /tmp/Test.java
可以通过-d命令指定输出目录：
mc -d /tmp/output /tmp/ClassA.java /tmp/ClassB.java
编绎生成.class文件之后，可以结合redefine命令实现热更新代码
动态增加日志 redefine
在Arthas里，可以通过redefine命令来达到线上不重启，动态更新代码的效果
添加日志，本地编绎后，把.class文件传到线上服务器，然后用redefine命令来更新代码
$ redefine -p /tmp/UserServiceImpl.class
redefine success, size: 1
记录调用
$ tt -t com.example.webtest.controller.testController testResult
Press Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 12 ms.
INDEX TIMESTAMP COST(ms) IS-RET IS-EXP OBJECT CLASS METHOD
----------------------------------------------------------------------------------------------------------------------------------------------------------
1002 2019-02-12 16:14:25 0.367999 true false 0x6ad213f7 testController testResult
命令参数解析
-t
tt 命令有很多个主参数，-t 就是其中之一。这个参数的表明希望记录下类 *Test 的 print 方法的每次执行情况。
-n 3
当你执行一个调用量不高的方法时可能你还能有足够的时间用 CTRL+C 中断 tt 命令记录的过程，但如果遇到调用量非常大的方法，瞬间就能将你的 JVM 内存撑爆。
此时你可以通过 -n 参数指定你需要记录的次数，当达到记录次数时 Arthas 会主动中断tt命令的记录过程，避免人工操作无法停止的情况。
解决方法重载
tt -t *Test print params[0].length==1
通过制定参数个数的形式解决不同的方法签名，如果参数个数一样，你还可以这样写
tt -t *Test print 'params[1] instanceof Integer'
解决指定参数
tt -t *Test print params[0].mobile=="13989838402"
查看检索到的记录
tt -l
查看调用具体信息
tt -i 1003
对于具体一个时间片的信息而言，你可以通过 -i 参数后边跟着对应的 INDEX 编号查看到他的详细信息
回放调用
tt -i 1004 -p
$ tt -i 1004 -p
RE-INDEX 1004
GMT-REPLAY 2018-12-04 11:26:00
OBJECT 0x4b67cf4d
CLASS demo.MathGame
METHOD primeFactors
PARAMETERS[0] @Integer[946738738]
IS-RETURN true
IS-EXCEPTION false
RETURN-OBJ @ArrayList[
@Integer[2],
@Integer[11],
@Integer[17],
@Integer[2531387],
]
Time fragment[1004] successfully replayed.
Affect(row-cnt:1) cost in 14 ms.
tt 命令由于保存了当时调用的所有现场信息，所以我们可以自己主动对一个 INDEX 编号的时间片自主发起一次调用，从而解放你的沟通成本。此时你需要 -p 参数。
需要强调的点
- ThreadLocal 信息丢失
很多框架偷偷的将一些环境变量信息塞到了发起调用线程的 ThreadLocal 中，由于调用线程发生了变化，这些 ThreadLocal 线程信息无法通过 Arthas 保存，所以这些信息将会丢失。
一些常见的 CASE 比如：鹰眼的 TraceId 等。 - 引用的对象
需要强调的是，tt 命令是将当前环境的对象引用保存起来，但仅仅也只能保存一个引用而已。如果方法内部对入参进行了变更，或者返回的对象经过了后续的处理，那么在 tt 查看的时候将无法看到当时最准确的值。这也是为什么 watch 命令存在的意义。
获取Spring context
除了上面介绍的一些排查技巧，下面分享一个获取Spring Context，然后“为所欲为”的例子。
在Dubbo里有一个扩展com.alibaba.dubbo.config.spring.extension.SpringExtensionFactory，把Spring Context保存到了里面。
因此，我们可以通过ognl命令获取到。
$ ognl '#context=@com.alibaba.dubbo.config.spring.extension.SpringExtensionFactory@contexts.iterator.next, #context.getBean("userServiceImpl").findUser(1)'
@User[
id=@Integer[1],
name=@String[Deanna Borer],
]
SpringExtensionFactory@contexts.iterator.next 获取到SpringExtensionFactory里保存的spring context对象
#context.getBean("userServiceImpl").findUser(1) 获取到userServiceImpl再执行一次调用
Dubbo运行时有哪些Filter? 耗时是多少?
trace函数
-j 过滤掉jdk的函数
$ trace -j demo.MathGame run
Press Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 31 ms.
`---ts=2018-12-04 01:09:14;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@3d4eac69
`---[5.190646ms] demo.MathGame:run()
+---[4.465779ms] demo.MathGame:primeFactors()
`---[0.375324ms] demo.MathGame:print()
据调用耗时过滤
trace demo.MathGame run '#cost > 10'
$ trace com.alibaba.dubbo.rpc.Filter *
Press Ctrl+C to abort.
Affect(class-cnt:19 , method-cnt:59) cost in 1441 ms.
`---ts=2018-12-05 19:07:26;thread_name=DubboServerHandler-30.5.125.152:20880-thread-10;id=3e;is_daemon=true;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@5c647e05
`---[8.435844ms] com.alibaba.dubbo.rpc.filter.EchoFilter:invoke()
+---[0.124572ms] com.alibaba.dubbo.rpc.Invocation:getMethodName()
+---[0.065123ms] java.lang.String:equals()
`---[7.762928ms] com.alibaba.dubbo.rpc.Invoker:invoke()
`---[7.494124ms] com.alibaba.dubbo.rpc.filter.ClassLoaderFilter:invoke()
+---[min=0.00355ms,max=0.049922ms,total=0.057637ms,count=3] java.lang.Thread:currentThread()
+---[0.0126ms] java.lang.Thread:getContextClassLoader()
+---[0.02188ms] com.alibaba.dubbo.rpc.Invoker:getInterface()
+---[0.004115ms] java.lang.Class:getClassLoader()
+---[min=0.003906ms,max=0.014058ms,total=0.017964ms,count=2] java.lang.Thread:setContextClassLoader()
`---[7.033486ms] com.alibaba.dubbo.rpc.Invoker:invoke()
`---[6.869488ms] com.alibaba.dubbo.rpc.filter.GenericFilter:invoke()
+---[0.01481ms] com.alibaba.dubbo.rpc.Invocation:getMethodName()
动态修改Dubbo的logger级别
在排查问题时，需要查看到更多的信息，如果可以把logger级别修改为DEBUG，就非常有帮助。
ognl是apache开源的一个轻量级表达式引擎。下面通过Arthas里的ognl命令来动态修改logger级别。
首先获取Dubbo里TraceFilter的一个logger对象，看下它的实现类，可以发现是log4j
$ ognl '@com.alibaba.dubbo.rpc.protocol.dubbo.filter.TraceFilter@logger.logger'
@Log4jLogger[
FQCN=@String[com.alibaba.dubbo.common.logger.support.FailsafeLogger],
logger=@Logger[org.apache.log4j.Logger@2f19bdcf],
]
再用sc命令来查看具体从哪个jar包里加载的
$ sc -d org.apache.log4j.Logger
class-info org.apache.log4j.Logger
code-source /Users/hengyunabc/.m2/repository/org/slf4j/log4j-over-slf4j/1.7.25/log4j-over-slf4j-1.7.25.jar
name org.apache.log4j.Logger
isInterface false
isAnnotation false
isEnum false
isAnonymousClass false
isArray false
isLocalClass false
isMemberClass false
isPrimitive false
isSynthetic false
simple-name Logger
modifier public
annotation
interfaces
super-class +-org.apache.log4j.Category
+-java.lang.Object
class-loader +-sun.misc.Launcher$AppClassLoader@5c647e05
+-sun.misc.Launcher$ExtClassLoader@59878d35
classLoaderHash 5c647e05
Affect(row-cnt:1) cost in 126 ms.
可以看到log4j是通过slf4j代理的。
那么通过org.slf4j.LoggerFactory获取root logger，再修改它的level：
$ ognl '@org.slf4j.LoggerFactory@getLogger("root").setLevel(@ch.qos.logback.classic.Level@DEBUG)'
null
$ ognl '@org.slf4j.LoggerFactory@getLogger("root").getLevel().toString()'
@String[DEBUG]
sc命令
“Search-Class” 的简写，这个命令能搜索出所有已经加载到 JVM 中的 Class 信息
打印类的详细信息
sc -d com.example.webtest.controller.testController
打印出类的Field信息
sc -d -f demo.MathGame
ognl
https://commons.apache.org/proper/commons-ognl/language-guide.html
$ ognl '#value1=@System@getProperty("java.home"), #value2=@System@getProperty("java.runtime.name"), {#value1, #value2}'
@ArrayList[
@String[/opt/java/8.0.181-zulu/jre],
@String[OpenJDK Runtime Environment],
]
