周五在公司搭好的ELK上查看日志,组长让看看其中NullPointerException出现很多的原因。
通过NullPointerException搜索,点看其中一个查看,发现异常的信息就一行java.lang.NullPointerException,并没有堆栈信息。
看了几个都没有,然后翻代码看记日志的地方,调用了日志基础工程的一个方法,异常对象通过封装传了进去,其中异常信息属性取值用的是Throwables.getStackTraceAsString(e),这是guava包提供的方法,点进去看是取了所有堆栈信息的。
那么问题来了,为什么堆栈信息没显示出来呢?
百度了下,关键字:NullPointerException 没有堆栈
找到类似的问题,发现是JVM虚拟机对异常信息进行了优化,当相同异常出现很多次,会认为它是热点异常,忽略掉异常堆栈信息;通过增加JVM参数:-XX:-OmitStackTraceInFastThrow可解决。
而项目工程里那个异常,产生来源是一个storm计算过程,它每天会进行很多次,因此很可能就是这个原因。
于是修改storm启动脚本,增加此JVM参数:-XX:-OmitStackTraceInFastThrow。重新提交topology到storm,很快能查看到最新的NullPointerException日志,看异常堆栈信息已完整输出,能够定位到具体代码行了。
本机写了个简单程序测试,循环很多次调用产生NullPointerException的方法,只打印最后一次异常:
1 package com.cdfive.learn.guava; 2 3 import com.google.common.base.Throwables; 4 5 /** 6 * 堆栈信息丢失测试 7 * -XX:-OmitStackTraceInFastThrow 8 * @author five 9 * @date 2018-05-27 10 */ 11 public class ThrowablesTest { 12 public static void main(String[] args) { 13 int max = 100; 14 // int max = 10000;// jvm参数增加-XX:-OmitStackTraceInFastThrow,否则只输出java.lang.NullPointerException,没有堆栈信息 15 for (int i = 1; i <= max; i++) { 16 try { 17 npeMethod(); 18 } catch (NullPointerException e) { 19 if (i == max) { 20 System.out.println(Throwables.getStackTraceAsString(e)); 21 } 22 } 23 } 24 } 25 26 public static void npeMethod() { 27 String s = null; 28 s = s.substring(0); 29 } 30 }
当max=100时,数量较少,能输出完整的异常堆栈:
java.lang.NullPointerException
at com.cdfive.learn.guava.ThrowablesTest.npeMethod(ThrowablesTest.java:28)
at com.cdfive.learn.guava.ThrowablesTest.main(ThrowablesTest.java:17)
当 max=10000时,输出结果中堆栈丢失了:
java.lang.NullPointerException
在JVM启动参数中增加:-XX:-OmitStackTraceInFastThrow后,又能够输出完整的异常堆栈了。
-----------------------------------------------------------------------------------------------------------------------------------
参考:
JVM参数分享 OmitStackTraceInFastThrow https://www.jianshu.com/p/e87d166380eb
https://blog.csdn.net/shfqbluestone/article/details/70978852
https://blog.csdn.net/taotao4/article/details/43918131