你真的会看异常堆栈信息么

接口在线上服务器出现异常的时候 , 我们第一时间就是去服务器看下log , 检查log是否有异常堆栈信息 , 如果有异常堆栈信息的话 , 再结合api的access log , 是非常容易找出问题所在的 , 所以我们要学会看异常堆栈信息 。异常堆栈信息如何看呢?下面我们一起来看一下 。
下面是一个简单的demo:
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函数 , 输出结果如下:
Connected to the target VM, address: '127.0.0.1:57353', transport: 'socket'java.lang.RuntimeException: level 3 exceptionat person.ismallboy.console.TestEx.fun3(TestEx.java:24)at person.ismallboy.console.TestEx.main(TestEx.java:30)Caused by: java.io.IOException: level 2 exceptionat person.ismallboy.console.TestEx.fun2(TestEx.java:15)at person.ismallboy.console.TestEx.fun3(TestEx.java:21)... 1 moreCaused by: java.io.IOException: level 1 exceptionat person.ismallboy.console.TestEx.fun1(TestEx.java:7)at person.ismallboy.console.TestEx.fun2(TestEx.java:12)... 2 moreDisconnected 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
我们来看一下打印异常堆栈信息的源码 , 输出函数是
java.lang.Throwable#printEnclosedStackTrace输出异常堆栈函数源代码如下:
/*** 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 traceStackTraceElement[] 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 traces.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 anyfor (Throwable se : getSuppressed())se.printEnclosedStackTrace(s, trace, SUPPRESSED_CAPTION,prefix +"t", dejaVu);// Print cause, if anyThrowable ourCause = getCause();if (ourCause != null)ourCause.printEnclosedStackTrace(s, trace, CAUSE_CAPTION, prefix, dejaVu);}}我们来分析一下这个函数 , 这里其实是一个回调输出堆栈的过程 。我们先来说一下为什么会隐藏部分堆栈 , 当然是为了提高性能 , 省略一些不必要的输出啦 , 输出的内容越多 , io耗时越慢嘛 。


推荐阅读