Arthas排查命令实时操作程序代码的总结分享
日常开发中，总会遇到一些莫名其妙的问题，这些问题在服务器上出现的概率可能很低，本地环境难以复现，这个时候阿里开源的Arthas就派上用场了,可以基于实时运行的应用进行排查，不必每次打日志，重启等掉头发的操作；
以下是一些个人觉得比较常用的场景及命令分享给大家。
@[toc]
1. 调用静态方法
比如调用Hutool的SpringUtil的getActiveProfile方法来查看当前环境配置
ognl -x 3 @cn.hutool.extra.spring.SpringUtil@getActiveProfile()
如果出现类找不到等等异常的，请按照以下步骤：
查找类的唯一标记HASH码
# 先查看类是否已经加载完毕
sc -d cn.hutool.extra.spring.SpringUtil
# 然后找到 classLoaderHash 1be6f5c3 这个值
ognl -c 1be6f5c3 @cn.hutool.extra.spring.SpringUtil@getActiveProfile()
# 得到结果 : @String[dev]
2. 获取Spring中IOC容器，并且为所欲为
我想知道SpringBoot中的yml中的spring.profiles.active属性配置
# 查找到对应的类的唯一标记HASH码
ognl -c 1be6f5c3 '#springContext=@cn.hutool.extra.spring.SpringUtil@applicationContext,#springContext.getEnvironment().getProperty("spring.profiles.active")'
#springContext=@cn.hutool.extra.spring.SpringUtil@applicationContext,#springContext.getEnvironment().getProperty("spring.profiles.active")
名词释义
cn.hutool.extra.spring.SpringUtil: 类的全路径，将工厂构建成一个静态工具类。
applicationContext: 表示类的属性
springContext : 表示定义的新变量，在这里面的意义表示Spring的工厂的变量
springContext.getEnvironment().getProperty("spring.profiles.active") : 表示调用了Spring工厂中的getEnvironment方法;
如果你对ognl命令不熟悉，那么可以安装一个IDEA插件
Arthas Idea Plugin，通过这个插件可以选择方法然后生成特定的命令直接在命令行中运行
3. 服务加载包不一致的情况
由于现在的服务都是需要依赖一些第三方的jar包，但是第三方的jar会带来一些其他的依赖，特定的版本号不一致都会导致出现问题。
之前还遇到过window开发运行是好的，但是放到linux服务器上启动就不行。
这个时候我们希望查看服务器的某个类到底是出自哪个版本的jar包，
这个时候sc命令就非常好的解决了这个问题
[arthas@1794]$ sc -d com.dianping.cat.message.io.DefaultMessageQueue
class-info com.dianping.cat.message.io.DefaultMessageQueue
code-source /data/tomcat/tomcat-cat/webapps/cat/WEB-INF/lib/cat-client-3.0.0.jar
name com.dianping.cat.message.io.DefaultMessageQueue
isInterface false
isAnnotation false
isEnum false
isAnonymousClass false
isArray false
isLocalClass false
isMemberClass false
isPrimitive false
isSynthetic false
simple-name DefaultMessageQueue
modifier public
annotation
interfaces com.dianping.cat.message.spi.MessageQueue
super-class +-java.lang.Object
class-loader +-ParallelWebappClassLoader
context: cat
delegate: false
----------> Parent Classloader:
java.net.URLClassLoader@63961c42
+-java.net.URLClassLoader@63961c42
+-sun.misc.Launcher$AppClassLoader@5c647e05
+-sun.misc.Launcher$ExtClassLoader@3a03464
classLoaderHash 26d4a70e
Affect(row-cnt:1) cost in 60 ms.
4. 反编译服务器上的代码
你是否有遇到过服务器发版，可能在集群情况下，一个服务要经过很多台服务器重启，然后某台服务可能没发好的情况，又没有足够的证据是发版引起的？
这个时候可以通过jad命令去查看当前应用进程中的特定代码:
jad 你想查看的类
[arthas@12870]$ jad com.xxx.xxx.xxx.xxx.AuthCacheUtil
ClassLoader:
+-org.springframework.boot.loader.LaunchedURLClassLoader@5674cd4d
+-sun.misc.Launcher$AppClassLoader@70dea4e
+-sun.misc.Launcher$ExtClassLoader@7516e4e5
Location:
file:/elab/spring-boot/elab-marketing-analyse-1.0.0.jar!/BOOT-INF/classes!/
package com.elab.marketing.analyse.cache;
@Component
@Order(value=1)
public class AuthCacheUtil
implements CommandLineRunner {
private static final Logger log = LoggerFactory.getLogger(AuthCacheUtil.class);
private static CacheUtil authCache;
public static void putValue(String key, Object value) {
/*37*/ authCache.putValue(key, value);
}
public void run(String ... strings) throws Exception {
/*28*/ log.info("================== AuthCache is ready! ==================");
authCache = new CacheUtil((long)UserAuthCache.USER_AUTH_INFO_SIZE.intValue(), (long)UserAuthCache.USER_AUTH_INFO_TIME.intValue());
}
public static Object getValue(String key, Callable callable) throws Exception {
/*33*/ return authCache.getValue(key, callable);
}
}
Affect(row-cnt:1) cost in 987 ms.
5. 排查特定日志的打印链路栈
比如随着系统越来越大，某些日志老是打印一些乱七八糟的值，而且打印的非常频繁，和预期的日志内容不一致，需要排查上游是如何产生的？
比如我们可以在测试环境，修改特定的类，比如logback的实现类，如果你不清楚的话，重写JDK的StringBuilder的toString()方法也行，因为java中的字符串拼接都是通过StringBuilder来完成的;
比如修改成:
@Override
public String toString() {
// Create a copy, don't share the array
String result = new String(value, 0, count);
if(result.contains("No credential found")) {
System.err.println(result);
// 如果你有链路日志系统的话,这里可以考虑打印日志编号,
// 可以让参数看的更详细
new Throwable().printStackTrace();
}
return result;
}
然后重新编译修改过的StringBuilder
javac StringBuilder.java
启动应用后，在奇怪日志输出之前，先使用arthas attach应用，再redefine StringBuilder:
$ redefine /tmp/StringBuilder.class
redefine success, size: 1
然后默默的等待报错查看日志即可看到执行的线程栈;
建议还是在测试环境或者其他环境执行即可，生产环境慎重；
6. 谁调用了特定的方法?
比如线上发生了大量Full GC ，造成的原因可能是触发了System.gc()这个时候你可能不清楚到底是哪里调用过这个玩意？
第一步，由于java.lang.System是JDK自带的类，Arthas默认关闭了对JDK类的自带类的增强，需要通过options命令打开。
$ options unsafe true
NAME BEFORE-VALUE AFTER-VALUE
-----------------------------------
unsafe false true
第二步，使用stack命令，观察谁调用了java.lang.System#gc
$ stack java.lang.System gc
Press Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 81 ms.
stack java.lang.System gc
// 等待结果反馈即可
7. 某个方法时快时慢?
相信你可能遇到过这样的问题,某个方法在本地执行的时候特别快，但是一到服务器上，有时候快，有时候慢的很，导致的原因可能有很多：入参，出参，特定的逻辑等等。你想看看慢的方法执行的方法栈是什么样子。
trace --skipJDKMethod false demo.MathGame run
Press Q or Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 60 ms.
`---ts=2019-12-04 00:44:41;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@3d4eac69
`---[1.357742ms] demo.MathGame:run()
+---[0.028624ms] java.util.Random:nextInt() #23
+---[0.045534ms] demo.MathGame:primeFactors() #24 [throws Exception]
+---[0.005372ms] java.lang.StringBuilder:<init>() #28
+---[0.012257ms] java.lang.Integer:valueOf() #28
+---[0.234537ms] java.lang.String:format() #28
+---[min=0.004539ms,max=0.005778ms,total=0.010317ms,count=2] java.lang.StringBuilder:append() #28
+---[0.013777ms] java.lang.Exception:getMessage() #28
+---[0.004935ms] java.lang.StringBuilder:toString() #28
`---[0.06941ms] java.io.PrintStream:println() #28
--skipJDKMethod false 代表展示JDK层面的方法栈
8. 刚上线某个方法，它的具体调用情况是怎么样的？
比如刚上线一个秒杀活动，你不知道这一时刻到底调用的线程有多少？能不能抗住？线程池够用吗？
monitor 命令可以很好的监控,实时情况下的方法调用情况.
$ 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%
