如何看异常堆栈信息

​    接口在线上服务器出现异常的时候，我们第一时间就是去服务器看下log，检查log是否有异常堆栈信息，如果有异常堆栈信息的话，再结合api的access log，是非常容易找出问题所在的，所以我们要学会看异常堆栈信息。异常堆栈信息如何看呢？下面我们一起来看一下。

    下面是一个简单的demo：

   

?

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36

package person.ismallboy.console; ​ import java.io.IOException; ​ public class TestEx {     private void fun1() throws IOException {         throw new IOException("level 1 exception");     } ​     private void fun2() throws IOException {         try {             fun1();             System.out.println("2");         } catch (IOException e) {             throw new IOException("level 2 exception", e);         }     } ​     private void fun3() {         try {             fun2();             System.out.println("3");         } catch (IOException e) {             throw new RuntimeException("level 3 exception", e);         }     } ​     public static void main(String[] args) {         try {             new TestEx().fun3();             System.out.println("0");         } catch (Exception e) {             e.printStackTrace();         }     } }

　　    

    执行上面demo的main函数，输出结果如下：

    

?

1 2 3 4 5 6 7 8 9 10 11 12 13

Connected to the target VM, address: '127.0.0.1:57353', transport: 'socket' java.lang.RuntimeException: level 3 exception   at person.ismallboy.console.TestEx.fun3(TestEx.java:24)   at person.ismallboy.console.TestEx.main(TestEx.java:30) Caused by: java.io.IOException: level 2 exception   at person.ismallboy.console.TestEx.fun2(TestEx.java:15)   at person.ismallboy.console.TestEx.fun3(TestEx.java:21)   ... 1 more Caused by: java.io.IOException: level 1 exception   at person.ismallboy.console.TestEx.fun1(TestEx.java:7)   at person.ismallboy.console.TestEx.fun2(TestEx.java:12)   ... 2 more Disconnected from the target VM, address: '127.0.0.1:57353', transport: 'socket'

　　

    既然是堆栈，那肯定是FILO（先进后出）的，了解过线程堆栈（比如函数调用的时候参数和局部变量的入栈和出栈）的同学应该比较清楚。所以我们看打出来的异常堆栈的顺序，也应该是从下往上看，就是从第12行开始往上看，一直看到第2行，发现第10行才是问题的根源，异常是一层一层地往外抛出，直至抛出到最外层（即没有catch为止）。第2行的RuntimeException只是真正异常的一个外层表现而已，异常的根源还是要看堆栈最底部的信息。本demo异常抛出的流程大概如下：

 

    所以，Caused by(中文是“由...造成的”意思)也就比较好理解了，就是这个异常时由哪里触发的意思。fun3的异常是由fun2的异常触发的，而fun2的异常又是由fun1的异常触发的。

 

    解决了异常堆栈查看顺序的问题，我们细看上面demo打印出来的异常堆栈信息，会发现，打印出来的堆栈信息不完整，比如第8行的“ ... 1 more”和第12行的“... 2 more”，为什么jvm会省略部分堆栈信息呢？下面我们继续探讨一下。

 

    1.为什么有些堆栈信息被隐藏了？... 2 more

    我们来看一下打印异常堆栈信息的远吗，输出函数是

?

1	java.lang.Throwable#printEnclosedStackTrace

　　 

    输出异常堆栈函数源代码如下：

?

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41

/**      * Print our stack trace as an enclosed exception for the specified      * stack trace.      */     private void printEnclosedStackTrace(PrintStreamOrWriter s,                                          StackTraceElement[] enclosingTrace,                                          String caption,                                          String prefix,                                          Set<Throwable> dejaVu) {         assert Thread.holdsLock(s.lock());         if (dejaVu.contains(this)) {             s.println("\t[CIRCULAR REFERENCE:" + this + "]");         } else {             dejaVu.add(this);             // Compute number of frames in common between this and enclosing trace             StackTraceElement[] trace = getOurStackTrace();             int m = trace.length - 1;             int n = enclosingTrace.length - 1;             while (m >= 0 && n >=0 && trace[m].equals(enclosingTrace[n])) {                 m--; n--;             }             int framesInCommon = trace.length - 1 - m; ​             // Print our stack trace             s.println(prefix + caption + this);             for (int i = 0; i <= m; i++)                 s.println(prefix + "\tat " + trace[i]);             if (framesInCommon != 0)                 s.println(prefix + "\t... " + framesInCommon + " more"); ​             // Print suppressed exceptions, if any             for (Throwable se : getSuppressed())                 se.printEnclosedStackTrace(s, trace, SUPPRESSED_CAPTION,                                            prefix +"\t", dejaVu); ​             // Print cause, if any             Throwable ourCause = getCause();             if (ourCause != null)                 ourCause.printEnclosedStackTrace(s, trace, CAUSE_CAPTION, prefix, dejaVu);         }     }

　　

    我们来分析一下这个函数，这里其实是一个回调输出堆栈的过程。我们先来说一下为什么会隐藏部分堆栈，当然是为了提高性能，省略一些不必要的输出啦，输出的内容越多，io耗时越慢嘛。

    其实“... n more”的部分是重复的堆栈部分。我们分析一下上面这个函数“printEnclosedStackTrace”，翻译为“打印封闭堆栈跟踪信息”，“封闭”暂且可以理解为“完整的”，这个函数有两个比较重要的变量，分别是“enclosingTrace”和“trace ”，这两个参数是什么关系呢？其实可以简单理解为“enclosingTrace”是“trace ”的父级堆栈，函数printEnclosedStackTrace中的while循环，就是为倒序找出“enclosingTrace”和“trace ”中从哪一个栈帧开始就不一样了，即“enclosingTrace”和“trace ”是有一部分是一样的（从数组后面倒回来），就是为了算出有多少个栈帧信息是重复可以隐藏的，相同的栈帧就不用重复输出啦。下图就是第12行“... 2 more”隐藏的栈帧信息：

 

    

    按照上面的堆栈输出，第12行“... 2 more”隐藏2行堆栈信息，其实就是第7和第8行的栈帧信息；然后第8行“ ... 1 more”隐藏的1个堆栈信息，其实就是第4行的那个栈帧。这样应该好理解了吧，每个异常都输出一个完整的堆栈信息的话，都是从main函数开始，到当前的函数的所有函数调用的栈帧信息，里面函数的调用栈帧信息都会包括外层的函数调用栈帧信息，所以都输出的话，很多都是重复的，为了提高效率，减少io以及输出的内容太多又杂乱，所以jvm以“... n more”的方式隐藏了重复的部分。

    当然，如果想不隐藏，可以重写java.lang.Throwable#printEnclosedStackTrace，去掉while部分，就可以看到每个异常的完整堆栈信息了，可以参考https://blog.csdn.net/michaelehome/article/details/79484722来验证。

 

参考：

https://www.jianshu.com/p/9f902c5517f8

https://blog.csdn.net/michaelehome/article/details/79484722

 

　　　　　　　　　　　　　　　　　欢迎关注微信公众号“ismallboy”，请扫码并关注以下公众号，并在公众号下面回复“堆栈”，获得本文最新内容。