Lost stack trace when exception is handelled with @ControllerAdvice annotated class

Question

I have a spring REST application. I throw all the exceptions from controller and handle them at a common place, a class named ExceptionHandlerControllerAdvice annotated with @ControllerAdvice. There I have multiple methods annotated with @ExceptionHandler to handle each type of exception. In these methods I send custom error json response. Before sending the this error json to the consumer, I exception's stack trace in logs. See Code-

@ControllerAdvice
public class ExceptionHandlerControllerAdvice {

    private static Logger logger = LoggerFactory.getLogger(ExceptionHandlerControllerAdvice.class);

    @ExceptionHandler(value = { Exception1.class })
    public @ResponseBody ResponseEntity<ErrorMessage> Exception1Handler(HttpServletRequest request, Exception1 e) {
        logger.error("error message {}. Details:", e.getMessage(), e.fillInStackTrace());
        return new ResponseEntity<ErrorMessage>(new ErrorMessageBO(e.getErrorCode(), e.getMessage()), HttpStatus.OK);
    }

    @ExceptionHandler(value = { Exception2.class })
    public @ResponseBody ResponseEntity<ErrorMessage> Exception2Handler(HttpServletRequest request, Exception2 e) {
        logger.error("error message {}. Details:", e.getMessage(), e.fillInStackTrace());
        return new ResponseEntity<ErrorMessage>(new ErrorMessageBO(e.getErrorCode(), e.getMessage()), HttpStatus.OK);
    }
}

The problem is that I am losing actual stack trace which tells me exactly where the exception originated from. Anybody familiar with the problem?
[Edit] See logs.

ERROR 2017-06-20 13:29:03,784 [http-bio-8080-exec-3] ExceptionHandlerControllerAdvice.runtimeExceptionHandler(28) | error message null. Details:
java.lang.NullPointerException: null
    at com.abc.products.hotel.advice.ExceptionHandlerControllerAdvice.runtimeExceptionHandler(ExceptionHandlerControllerAdvice.java:28) [classes/:na]
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_45]
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_45]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_45]
    at java.lang.reflect.Method.invoke(Method.java:497) ~[na:1.8.0_45]
    at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:221) [spring-web-4.3.1.RELEASE.jar:4.3.1.RELEASE]
    at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:136) [spring-web-4.3.1.RELEASE.jar:4.3.1.RELEASE]
    at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:114) [spring-webmvc-4.3.1.RELEASE.jar:4.3.1.RELEASE]
    at org.springframework.web.servlet.mvc.method.annotation.ExceptionHandlerExceptionResolver.doResolveHandlerMethodException(ExceptionHandlerExceptionResolver.java:379) [spring-webmvc-4.3.1.RELEASE.jar:4.3.1.RELEASE]
    at org.springframework.web.servlet.handler.AbstractHandlerMethodExceptionResolver.doResolveException(AbstractHandlerMethodExceptionResolver.java:59) [spring-webmvc-4.3.1.RELEASE.jar:4.3.1.RELEASE]
    at org.springframework.web.servlet.handler.AbstractHandlerExceptionResolver.resolveException(AbstractHandlerExceptionResolver.java:136) [spring-webmvc-4.3.1.RELEASE.jar:4.3.1.RELEASE]
    at org.springframework.web.servlet.handler.HandlerExceptionResolverComposite.resolveException(HandlerExceptionResolverComposite.java:74) [spring-webmvc-4.3.1.RELEASE.jar:4.3.1.RELEASE]
    at org.springframework.web.servlet.DispatcherServlet.processHandlerException(DispatcherServlet.java:1193) [spring-webmvc-4.3.1.RELEASE.jar:4.3.1.RELEASE]
    at org.springframework.web.servlet.DispatcherServlet.processDispatchResult(DispatcherServlet.java:1030) [spring-webmvc-4.3.1.RELEASE.jar:4.3.1.RELEASE]
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:980) [spring-webmvc-4.3.1.RELEASE.jar:4.3.1.RELEASE]
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:897) [spring-webmvc-4.3.1.RELEASE.jar:4.3.1.RELEASE]
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:970) [spring-webmvc-4.3.1.RELEASE.jar:4.3.1.RELEASE]
    at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:861) [spring-webmvc-4.3.1.RELEASE.jar:4.3.1.RELEASE]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:624) [servlet-api.jar:na]
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:846) [spring-webmvc-4.3.1.RELEASE.jar:4.3.1.RELEASE]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:731) [servlet-api.jar:na]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303) [catalina.jar:7.0.65]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) [catalina.jar:7.0.65]
    at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:197) [spring-web-4.3.1.RELEASE.jar:4.3.1.RELEASE]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) [spring-web-4.3.1.RELEASE.jar:4.3.1.RELEASE]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241) [catalina.jar:7.0.65]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) [catalina.jar:7.0.65]
    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52) [tomcat7-websocket.jar:7.0.65]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241) [catalina.jar:7.0.65]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) [catalina.jar:7.0.65]
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220) [catalina.jar:7.0.65]
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122) [catalina.jar:7.0.65]
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:505) [catalina.jar:7.0.65]
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:170) [catalina.jar:7.0.65]
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103) [catalina.jar:7.0.65]
    at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:956) [catalina.jar:7.0.65]
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116) [catalina.jar:7.0.65]
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:423) [catalina.jar:7.0.65]
    at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1079) [tomcat-coyote.jar:7.0.65]
    at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:625) [tomcat-coyote.jar:7.0.65]
    at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316) [tomcat-coyote.jar:7.0.65]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_45]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_45]
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-coyote.jar:7.0.65]
    at java.lang.Thread.run(Thread.java:745) [na:1.8.0_45]

Which logger framework are you using? If this is slf4j, why aren't you just logging the exception object itself? (Note that you may be overwriting the stack trace explicitly.) — chrylis -cautiouslyoptimistic-, Jun 20 '17 at 08:19
I'm using slf4j. I've updated my question with the logs. Can you please check once? I suspect Spring is overwriting the stack trace. — Arjit, Jun 20 '17 at 08:29
I tried logging the object itself and it worked. Thanks @chrylis — Arjit, Jun 20 '17 at 08:43

score 1 · Accepted Answer · answered Jun 20 '17 at 09:01

From your log formatting, it looks like you're using slf4j. The API's warn and error methods are frequently used to log exceptions, and slf4j provides specific warn(String message, Throwable t) overrides that can use exception-specific formatting in logger implementations (e.g., print the message and the first N lines of the stack trace). Since these messages should almost never be suppressed, you don't lose anything from not parameterizing the message string. Just write logger.warn("message", ex);.

As to why you had the problem in the first place, you should have used getStackTrace() instead of fillInStackTrace().

Lost stack trace when exception is handelled with @ControllerAdvice annotated class

1 Answers1