arthas系列文章
- OGNL语法规范
- 消失的堆栈
- Arthas原理系列(一)：利用JVM的attach机制实现一个极简的watch命令
- Arthas原理系列(二)：总体架构和项目入口
- Arthas原理系列(三)：服务端启动流程
- Arthas原理系列(四)：字节码插装让一切变得有可能
前言
这周的某天突然爆出线上查询卖家订单异常的报警，因为这个接口量比较大，赶紧排查马上介入看了下，找到日志后发现这个接口的实现抛了NPE，但是在日志里看不到堆栈。因为封网的时间已经很长了，应该不是发布导致的。但无论如何，要先定位到抛NPE的地方，才能知道是哪里出了问题
消失的堆栈
我们用下面的代码来做一次测试
public class DemoApplication {
public static void main(String[] args) {
// SpringApplication.run(DemoApplication.class, args);
for (int i = 0; i < Integer.MAX_VALUE; i++) {
System.out.println("times:" + i + " , result:" + testExceptionTrunc());
}
}
public static boolean testExceptionTrunc() {
try {
// 人工构造异常抛出的场景
((Object)null).getClass();
} catch (Exception e) {
if (e.getStackTrace().length == 0) {
try {
// 堆栈消失的时候当前线程休眠5秒，便于观察
Thread.sleep(5000);
} catch (InterruptedException interruptedException) {
// do nothing
}
return true;
}
}
return false;
}
}
这段代码的运行结果是：(
)可以看到，在我的机器上循环到底13441次的时候堆栈丢失了，注意这个值可能在不同的机器上是不同的。
Java的即时编译(JIT)
之所以会有这样的运行结果，是因为Java有JIT(Just In Time)的编译机制，如下图所示
为了实现WORA (Write once, run anywhere)Java会先将源代码编译成字节码，然后在运行时再转换为机器码，虽然提升了通用性，但是字节码转换为机器码的速度会直接影响到整个Java程序的运行速度，因此JVM在实现的时候会将一些热点代码直接编译成Native Code，运行时省去了从字节码转化这一步，以此达到提升性能的目的，整个Java代码运行时的流程可以总结成下面这张图：
那什么样的代码才算是热点代码呢？有两种情况：
-
被多次调用的方法
-
被多次调用的循环体
上面的测试方法体因为一直在被循环调，被判定成了热点代码，从而直接编译为Native Code，因此丢失了堆栈
利用Arthas观察丢失的堆栈
假如我们继续运行上面的示例代码，等到这段代码被即时编译导致堆栈丢失后启动arthas，并用watch命令观察示例方法，会发现一个有趣的现象：
watch com.idealism.demo.DemoApplication testExceptionTrunc '{returnObj, throwExp}'
丢失的堆栈又回来了!后面的文章我们会讲到arthas的原理，这里我们稍微提一下，arthas使用字节码增强技术，在应用程序的字节码中注入新的字节码，这就破坏了原来的热点代码结构，原先的方法体不再被JIT编译器执行，所以我们看到的就是消失的堆栈又回来了。如果我们继续观察，等到被arthas注入的字节码又被判定为热点代码后，堆栈就又消失了，如下图所示：
注意这张图中的执行次数是已经到了25W,并非开始的那段热点代码导致的。如果当时事出突然，或者短时间内难以拼接出观察表达式，可以用Arthas提供的另一个命令：tt对前面的示例稍加修改，让testExceptionTrunc抛出异常来示例tt命令
public class DemoApplication {
public static void main(String[] args) {
// SpringApplication.run(DemoApplication.class, args);
for (int i = 0; i < Integer.MAX_VALUE; i++) {
try {
System.out.println("times:" + i + " , result:" + testExceptionTrunc());
} catch (Exception e) {
// do nothing
// we has Arthas to record everything
}
}
}
public static boolean testExceptionTrunc() {
try {
// 人工构造异常抛出的场景
((Object)null).getClass();
} catch (Exception e) {
if (e.getStackTrace().length == 0) {
try {
// 堆栈消失的时候当前线程休眠5秒，便于观察
Thread.sleep(5000);
} catch (InterruptedException interruptedException) {
// do nothing
}
// return true;
}
throw e;
}
return false;
}
}
-
首先利用`tt -t`命令记录下方法的执行
tt -t com.idealism.demo.DemoApplication testExceptionTrunc
可以用-n指定记录的条数
-
再用`tt -l`查看所有的记录条数
[arthas@24869]$ tt -l
INDEX TIMESTAMP COST(ms) IS-RET IS-EXP OBJECT CLASS METHOD
--------------------------------------------------------------------------------------------------------------------------------------------------------------
1000 2020-10-31 23:25:22 1.3506 false true NULL DemoApplication testExceptionTrunc
1001 2020-10-31 23:25:22 0.167257 false true NULL DemoApplication testExceptionTrunc
1002 2020-10-31 23:25:22 0.094215 false true NULL DemoApplication testExceptionTrunc
1003 2020-10-31 23:25:22 0.132743 false true NULL DemoApplication testExceptionTrunc
1004 2020-10-31 23:25:22 0.1103 false true NULL DemoApplication testExceptionTrunc
1005 2020-10-31 23:25:22 0.095003 false true NULL DemoApplication testExceptionTrunc
1006 2020-10-31 23:25:22 0.115417 false true NULL DemoApplication testExceptionTrunc
1007 2020-10-31 23:25:22 0.082682 false true NULL DemoApplication testExceptionTrunc
1008 2020-10-31 23:25:22 0.058998 false true NULL DemoApplication testExceptionTrunc
1009 2020-10-31 23:25:22 0.066754 false true NULL DemoApplication testExceptionTrunc
1010 2020-10-31 23:25:22 0.064382 false true NULL DemoApplication testExceptionTrunc
1011 2020-10-31 23:25:22 0.056279 false true NULL DemoApplication testExceptionTrunc
1012 2020-10-31 23:25:22 0.054421 false true NULL DemoApplication testExceptionTrunc
-
最后用`tt - i`查看调用时的上下文
[arthas@24869]$ tt -i 1099
INDEX 1099
GMT-CREATE 2020-10-31 23:25:22
COST(ms) 0.044543
OBJECT NULL
CLASS com.idealism.demo.DemoApplication
METHOD testExceptionTrunc
IS-RETURN false
IS-EXCEPTION true
THROW-EXCEPTION java.lang.NullPointerException
at com.idealism.demo.DemoApplication.testExceptionTrunc(DemoApplication.java:24)
at com.idealism.demo.DemoApplication.main(DemoApplication.java:13)
Affect(row-cnt:1) cost in 7 ms.
到这里我们就能看到抛NPE的堆栈了 使用tt命令需要注意，tt命令中保存了所有对象的引用，因为这些引用在程序的运行过程中会被修改，所以会出现还原历史调用上下文不准确的问题，这也是watch命令存在的意义，更多Arthas的用法请参考官方文档。
扫描二维码关注公众号，获取今年最新面试资料和电子书文档
