接口在線上服務器出現異常的時候，我們第一時間就是去服務器看下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 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.為什么有些堆棧信息被隱藏了？... 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 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行“
按照上面的堆棧輸出，第12行“
當然，如果想不隱藏，可以重寫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”，請掃碼並關注以下公眾號，並在公眾號下面回復“堆棧”，獲得本文最新內容。
