前幾天有同學找我查一個空指針問題，Java 打印日志時，異常堆棧信息被吞了，導致定位不到出問題的地方。

現象

捕獲異常打印日志的代碼類似這樣：

try {
    // ...
} catch (Exception e) {
    log.error("系統異常 customerCode:{},data:{}", customerCode, data, e);
    // ...
}

查到的日志是這樣的：

2023-06-26 11:11:11.111 ERROR 1 --- [pool-1-thread-1] c.mazhuang.service.impl.TestServiceImpl  : 系統異常 customerCode:123,data:{"name":"mazhuang","age":18}
java.lang.NullPointerException: null

異常堆棧丟了。

分析

在之前的一篇文章里已經驗證過這種寫法是可以正常打印異常和堆棧信息的：AI 自動補全的這句日志能正常打印嗎？

再三確認代碼寫法沒問題，納悶之下只好搜索了一下關鍵詞「Java異常堆棧丟失」，發現了這篇文章：Java異常堆棧丟失的現象及解決方法，這里面提到的問題與我們遇到的一樣，而且給出了 Oracle 官方文檔里的相關說明：

https://www.oracle.com/java/technologies/javase/release-notes-introduction.html

The compiler in the server VM now provides correct stack backtraces for all “cold” built-in exceptions. For performance purposes, when such an exception is thrown a few times, the method may be recompiled. After recompilation, the compiler may choose a faster tactic using preallocated exceptions that do not provide a stack trace. To disable completely the use of preallocated exceptions, use this new flag: -XX:-OmitStackTraceInFastThrow.

大致意思就是說，為了提高性能，JVM 會針對一些內建異常進行優化，在這些異常被某方法多次拋出時，JVM 可能會重編譯該方法，這時候就可能會使用不提供堆棧信息的預分配異常。如果想要完全禁用預分配異常，可以使用 -XX:-OmitStackTraceInFastThrow 參數。

了解到這個信息后，翻了翻從服務上次發版以來的這條日志，果然最早的十幾次打印是有異常堆棧的，后面就沒有了。

解決方案

回溯歷史日志，找到正常打印的堆棧信息，定位和解決問題；

也可以考慮在 JVM 參數里加上 -XX:-OmitStackTraceInFastThrow 參數，禁用優化；

本地復現

在本地寫一個簡單的程序復現一下：

public class StackTraceInFastThrowDemo {
    public static void main(String[] args) {
        int count = 0;
        boolean flag = true;
        while (flag) {
            try {
                count++;
                npeTest(null);
            } catch (Exception e) {
                int stackTraceLength = e.getStackTrace().length;
                System.out.printf("count: %d, stacktrace length: %d%n", count, stackTraceLength);
                if (stackTraceLength == 0) {
                    flag = false;
                }
            }
        }
    }

    public static void npeTest(Integer i) {
        System.out.println(i.toString());
    }
}

不添加 -XX:-OmitStackTraceInFastThrow 作為 JVM 參數時，運行結果如下：

...
count: 5783, stacktrace length: 2
count: 5784, stacktrace length: 2
count: 5785, stacktrace length: 0

Process finished with exit code 0

在我本機一般運行五六千次后，會出現異常堆棧丟失的情況。

添加 -XX:-OmitStackTraceInFastThrow 作為 JVM 參數時，運行結果如下：

...
count: 3146938, stacktrace length: 2
count: 3146939, stacktrace length: 2
count: 3146940, stacktrace length: 
Process finished with exit code 137 (interrupted by signal 9: SIGKILL)

運行了幾百萬次也不會出現異常堆棧丟失的情況，手動終止程序。

完整源碼見：https://github.com/mzlogin/java-notes/blob/master/src/org/mazhuang/StackTraceInFastThrowDemo.java