JAVA栈异常_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.

复现&解决方案

复现问题

执行如下代码：

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的异常机制是如何运行的，为什么会这么慢，等等。

参考