生产的异常堆栈信息丢失，只显示了异常名称？带你一探究竟

    今天运营那边反馈说有个功能一直弹出500的弹框，我看了下，是后台的接口报500了，于是立即上生产服务器看了下，发现这个接口有时候确实报了很多exception，找了其中一个exception的log来看，怎么那么奇怪，log中打出来的堆栈竟然看不出是哪里的业务代码报出来的（其实这个问题之前也有遇到过，只是之前没太在意），于是决定一探究竟。

    首先来看下我看到的log是这样的：

2020-04-19 11:11:02.066 ERROR [xxx,,,] 19571 --- [XNIO-5 task-70] io.undertow.request                      : UT005023: Exception handling request to /internal/newscontent
​
org.springframework.web.util.NestedServletException: Request processing failed; nested exception is java.lang.NullPointerException
        at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:982)
        at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:861)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:687)
        at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:846)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
        at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:85)
        at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:129)
        at org.springframework.boot.web.filter.ApplicationContextHeaderFilter.doFilterInternal(ApplicationContextHeaderFilter.java:55)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
        at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
        at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
        at org.springframework.cloud.sleuth.instrument.web.TraceFilter.doFilter(TraceFilter.java:156)
        at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
        at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
        at org.springframework.boot.actuate.trace.WebRequestTraceFilter.doFilterInternal(WebRequestTraceFilter.java:105)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
        at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
        at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
        at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
        at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
        at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
        at org.springframework.web.filter.HttpPutFormContentFilter.doFilterInternal(HttpPutFormContentFilter.java:87)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
        at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
        at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
        at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:77)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
        at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
        at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
        at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:197)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
        at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
        at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
        at org.springframework.boot.actuate.autoconfigure.MetricsFilter.doFilterInternal(MetricsFilter.java:107)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
        at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
        at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
        at io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:84)
        at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
        at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
        at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:131)
        at io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
        at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
        at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
        at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
        at io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60)
        at io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77)
        at io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)
        at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
        at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
        at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:285)
        at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:264)
        at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)
        at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:175)
        at io.undertow.server.Connectors.executeRootHandler(Connectors.java:202)
        at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:802)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.NullPointerException: null

　　

    Caused by下面怎么没有了？不用怀疑，下面就真的是没有的，不是我贴漏代码了，为什么呢？于是我在本地打开debug模式，链接到生产环境debug一下，发现本地是可以正常打印出完成的堆栈信息的，就是Cause by下面还有详细的堆栈信息的，本地打印出来的堆栈信息如下：

2020-04-19 22:12:33.241 ERROR [xxx,,,] 19408 --- [  XNIO-5 task-2] io.undertow.request                      : UT005023: Exception handling request to /internal/newscontent
​
org.springframework.web.util.NestedServletException: Request processing failed; nested exception is java.lang.NullPointerException
  at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:982)
  at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:861)
  at javax.servlet.http.HttpServlet.service(HttpServlet.java:687)
  at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:846)
  at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
  at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:85)
  at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:129)
  at org.springframework.boot.web.filter.ApplicationContextHeaderFilter.doFilterInternal(ApplicationContextHeaderFilter.java:55)
  at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
  at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
  at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
  at org.springframework.cloud.sleuth.instrument.web.TraceFilter.doFilter(TraceFilter.java:156)
  at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
  at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
  at org.springframework.boot.actuate.trace.WebRequestTraceFilter.doFilterInternal(WebRequestTraceFilter.java:105)
  at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
  at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
  at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
  at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99)
  at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
  at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
  at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
  at org.springframework.web.filter.HttpPutFormContentFilter.doFilterInternal(HttpPutFormContentFilter.java:87)
  at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
  at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
  at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
  at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:77)
  at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
  at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
  at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
  at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:197)
  at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
  at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
  at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
  at org.springframework.boot.actuate.autoconfigure.MetricsFilter.doFilterInternal(MetricsFilter.java:107)
  at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
  at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
  at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
  at io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:84)
  at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
  at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
  at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:131)
  at io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
  at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
  at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
  at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
  at io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60)
  at io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77)
  at io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)
  at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
  at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
  at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:285)
  at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:264)
  at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)
  at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:175)
  at io.undertow.server.Connectors.executeRootHandler(Connectors.java:202)
  at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:802)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
  at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.NullPointerException: null
  at xxx.NewsResponse.<init>(NewsResponse.java:105)
  at xxx.controller.internal.InternalNewsContentController.getNewsContent(InternalNewsContentController.java:90)
  at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
  at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
  at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
  at java.lang.reflect.Method.invoke(Method.java:498)
  at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:221)
  at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:136)
  at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:114)
  at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:827)
  at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:738)
  at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:85)
  at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:963)
  at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:897)
  at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:970)
  ... 59 common frames omitted

　　

    看到上面的堆栈信息，就知道异常是在类NewsResponse的第105行报出来的，并且这个函数的上一个调用链是类InternalNewsContentController的第90行，清晰明了，根据这个堆栈信息，直接看代码，就找出了问题所在，是什么问题，本文不纠结。然后我们来看下，为什么本地有有Caused by后面的完整堆栈信息，而生产上没呢？这就是本文探讨的主题之一，为什么有些异常堆栈信息丢失了，只显示了异常名称呢？

    这里先给出结果，这是因为jvm针对异常做的Fast Throw优化，可以通过参数'-XX:-OmitStackTraceInFastThrow'进行配置。为什么叫“优化”呢？是因为Fast Throw优化可以提高运行速度，这种异常抛出速度非常快，不需要在堆里分配内存，也不需要构造完整的异常栈信息。另外这种优化手段，可以类比集合的'fast-fail'机制（fast-fail机制这里不展开讲，之后专门开一篇文章说这个主题）。

    这种Fast Throw机制，其实就是同一个exception在同一个位置抛出了很多次之后，jvm就不再输出详细的堆栈了，而是直接抛出一个预先就分配好异常信息。这个可以在oracle官网上查到相关的信息（https://www.oracle.com/technetwork/java/javase/relnotes-139183.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.

 

里面提到的a few times，我并没有去详细探究（有知道的朋友，可以留言告知一下，谢谢），说明一开始还是有详细堆栈的，于是我定位到生产环境今天这个exception出现的第一个位置，发现前面2个exception，Caused by后面确实是有详细的堆栈信息的，从第3个exception开始不再显示Caused by后面详细的堆栈信息了（不确定few times是否等于2，看了网上一些大神的测试，并不是等于2的）。

    所以如果下次再遇到异常的堆栈信息丢失的情况，不用再惊讶，往前找一下，就能找到详细的异常堆栈信息了。当然，如果对这个异常堆栈信息耿耿于怀，可以通过程序启动的时候，加上jvm参数-XX:-OmitStackTraceInFastThrow，然后就不会再出现这种异常堆栈丢失情况了。但是个人觉得，这既然是jvm默认的行为，并且是为了提高速度而专门做了这个fast-flow的设计，肯定是有一定的道理的，一般保持这种默认的行为就行了。

    至于隐藏了堆栈信息的相关的源码的JVM源码的graphKit.cpp文件中，可以在文章（https://www.jianshu.com/p/cc1bd35466cb）中查看相关信息。

    针对上面贴出来的堆栈信息，应该看Caused by下面的信息，还是看顶部的堆栈信息呢？他们之间有什么关联呢？下一篇教你阅读异常堆栈信息，敬请期待~

 

参考：

https://www.jianshu.com/p/cc1bd35466cb

 

　　　　　　　　　　　　　　　　　　　　　 　欢迎关注微信公众号“ismallboy”，请扫码并关注以下公众号，并在公众号下面回复“堆栈”，获得本文最新内容。