Java異常堆棧丟失的現象及解決方法


問題描述

查看線上log時,發現了一些npe異常,但是沒有堆棧信息。

...
java.lang.NullPointerException
...

沒有堆棧信息,也就意味着沒法定位問題代碼,第一反應是查看記日志的代碼(用的logback),確認沒有問題后,開始google和stackOverflow。

結論

一般情況下,當異常發生時,JVM會回溯調用棧,構建異常對象(包含完整的堆棧信息)。但是出於性能考慮,如果某個方法一直拋出同樣的異常,比如npe,JVM會重新編譯該方法(JIT編譯器),然后拋出事先創建好的異常(沒有堆棧信息)。

JDK5.0的發布說明里有相關描述:

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.

https://www.oracle.com/technetwork/java/javase/relnotes-139183.html

復現&解決方案

復現問題

執行如下代碼:

for (int i = 0; i < 200000; i++) {
    try {
        ((String) null).toString();
    } catch (Exception e) {
        int stackTraceLength = e.getStackTrace().length;
        System.out.println(i + ",堆棧長度:" + stackTraceLength);
    }
}

在我的電腦上,循環115716次后,堆棧長度就為0了,即堆棧信息為空,如下:

...
115713,堆棧長度:1
115714,堆棧長度:1
115715,堆棧長度:0
115716,堆棧長度:0
...

所以,驗證了JVM確實會進行一些優化,出現沒有堆棧的異常。

解決方案

  • 通過JVM參數禁用此優化。
    JDK5.0 Release Notes里說的很明確,通過添加JVM參數禁用此優化:-XX:-OmitStackTraceInFastThrow。
  • 查看更早之前的log,直到相關的異常堆棧,解決掉。
    如上文所說,只有某個異常出現了若干次后,才可能觸發優化條件。所以,最初的日志里肯定是有完整的堆棧信息。

如果日志比較少,考慮直接往前追溯log,找到異常堆棧,解決問題。
如果日志比較多,考慮在線上先給JVM增加參數禁用此優化,解決問題后,再移除參數,開啟優化。

最后

以此為假設,在線上往前追溯log,最終在5天前的日志里找到了相關異常的堆棧信息,定位到問題,解決起來就比較簡單了。
本文以流水賬的方式描述了遇到的問題和解決方案,其實還是很多東西值得繼續調研,比如JVM為什么要這個優化,JVM的異常機制是如何運行的,為什么會這么慢,等等。

參考

[1] Hotspot caused exceptions to lose their stack traces in production – and the fix



免責聲明!

本站轉載的文章為個人學習借鑒使用,本站對版權不負任何法律責任。如果侵犯了您的隱私權益,請聯系本站郵箱yoyou2525@163.com刪除。



 
粵ICP備18138465號   © 2018-2025 CODEPRJ.COM