如何找到打印 StackTrace 的位置?

问题描述

我们有一些使用 Spring REST 端点的移动应用程序。由于一些有问题的应用程序,我们在服务器上看到 ClientAbortException 的出现。现在的问题是,这不是通过可配置的日志记录机制记录的——但显然只是写入控制台,导致各种问题。

鉴于下面的堆栈跟踪,它甚至不包含我们自己的代码,我如何找出打印此异常的位置?我已经尝试过以下操作:

  1. 我为 Spring 添加一个特定的错误处理程序。这是因为调用错误处理程序,但仍然会打印堆栈跟踪。
  @ExceptionHandler(ClientAbortException.class)
  @ResponseStatus(HttpStatus.SERVICE_UNAVAILABLE)
  public Object exceptionHandler(ClientAbortException exc) {
    return null; //socket is closed,cannot return any response
  }
  1. 我尝试在各种 Throwable.printstacktrace 方法中设置断点。似乎没有人被调用

  2. 我通过委托模式实现了自定义 PrintStream,并使用 System.setErr(debuggablePrintStream);System.setout(debuggablePrintStream); 进行设置。同样,似乎没有调用各种 println 方法

因此,除了直接使用某些最终类的 Java Agent to manipulate the bytecode 之外,我没有其他选择。那么我最好从哪里开始?

这是不断充斥我们控制台的令人讨厌的堆栈跟踪:

org.apache.catalina.connector.ClientAbortException: java.io.IOException: Connection reset by peer
    at org.apache.catalina.connector.OutputBuffer.doFlush(OutputBuffer.java:309) ~[tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.catalina.connector.OutputBuffer.flush(OutputBuffer.java:272) ~[tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.catalina.connector.CoyoteOutputStream.flush(CoyoteOutputStream.java:118) ~[tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.springframework.security.web.util.OnCommittedResponseWrapper$SaveContextServletoutputStream.flush(OnCommittedResponseWrapper.java:523) ~[spring-security-web-5.4.5.jar!/:5.4.5]
    at org.springframework.security.web.util.OnCommittedResponseWrapper$SaveContextServletoutputStream.flush(OnCommittedResponseWrapper.java:523) ~[spring-security-web-5.4.5.jar!/:5.4.5]
    at java.io.FilterOutputStream.flush(FilterOutputStream.java:153) ~[?:?]
    at com.fasterxml.jackson.core.json.UTF8JsonGenerator.flush(UTF8JsonGenerator.java:1178) ~[jackson-core-2.11.4.jar!/:2.11.4]
    at com.fasterxml.jackson.databind.ObjectWriter.writeValue(ObjectWriter.java:1008) ~[jackson-databind-2.11.4.jar!/:2.11.4]
    at org.springframework.http.converter.json.AbstractJackson2HttpMessageConverter.writeInternal(AbstractJackson2HttpMessageConverter.java:452) ~[spring-web-5.3.4.jar!/:5.3.4]
    at org.springframework.http.converter.AbstractGenericHttpMessageConverter.write(AbstractGenericHttpMessageConverter.java:104) ~[spring-web-5.3.4.jar!/:5.3.4]
    at org.springframework.web.servlet.mvc.method.annotation.AbstractMessageConverterMethodProcessor.writeWithMessageConverters(AbstractMessageConverterMethodProcessor.java:277) ~[spring-webmvc-5.3.4.jar!/:5.3.4]
    at org.springframework.web.servlet.mvc.method.annotation.httpentityMethodProcessor.handleReturnValue(httpentityMethodProcessor.java:219) ~[spring-webmvc-5.3.4.jar!/:5.3.4]
    at org.springframework.web.method.support.HandlerMethodReturnValueHandlerComposite.handleReturnValue(HandlerMethodReturnValueHandlerComposite.java:78) ~[spring-web-5.3.4.jar!/:5.3.4]
    at org.springframework.web.servlet.mvc.method.annotation.ServletinvocableHandlerMethod.invokeAndHandle(ServletinvocableHandlerMethod.java:124) ~[spring-webmvc-5.3.4.jar!/:5.3.4]
    at org.springframework.web.servlet.mvc.method.annotation.ExceptionHandlerExceptionResolver.doResolveHandlerMethodException(ExceptionHandlerExceptionResolver.java:428) [spring-webmvc-5.3.4.jar!/:5.3.4]
    at org.springframework.web.servlet.handler.AbstractHandlerMethodExceptionResolver.doResolveException(AbstractHandlerMethodExceptionResolver.java:75) [spring-webmvc-5.3.4.jar!/:5.3.4]
    at org.springframework.web.servlet.handler.AbstractHandlerExceptionResolver.resolveException(AbstractHandlerExceptionResolver.java:141) [spring-webmvc-5.3.4.jar!/:5.3.4]
    at org.springframework.web.servlet.handler.HandlerExceptionResolverComposite.resolveException(HandlerExceptionResolverComposite.java:80) [spring-webmvc-5.3.4.jar!/:5.3.4]
    at org.springframework.web.servlet.dispatcherServlet.processHandlerException(dispatcherServlet.java:1320) [spring-webmvc-5.3.4.jar!/:5.3.4]
    at org.springframework.web.servlet.dispatcherServlet.processdispatchResult(dispatcherServlet.java:1131) [spring-webmvc-5.3.4.jar!/:5.3.4]
    at org.springframework.web.servlet.dispatcherServlet.dodispatch(dispatcherServlet.java:1077) [spring-webmvc-5.3.4.jar!/:5.3.4]
    at org.springframework.web.servlet.dispatcherServlet.doService(dispatcherServlet.java:962) [spring-webmvc-5.3.4.jar!/:5.3.4]
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006) [spring-webmvc-5.3.4.jar!/:5.3.4]
    at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:909) [spring-webmvc-5.3.4.jar!/:5.3.4]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:652) [tomcat-embed-core-9.0.43.jar!/:4.0.FR]
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883) [spring-webmvc-5.3.4.jar!/:5.3.4]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:733) [tomcat-embed-core-9.0.43.jar!/:4.0.FR]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:227) [tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) [tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:327) [spring-security-web-5.4.5.jar!/:5.4.5]
    at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:115) [spring-security-web-5.4.5.jar!/:5.4.5]
    at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:81) [spring-security-web-5.4.5.jar!/:5.4.5]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336) [spring-security-web-5.4.5.jar!/:5.4.5]
    at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:119) [spring-security-web-5.4.5.jar!/:5.4.5]
    at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:113) [spring-security-web-5.4.5.jar!/:5.4.5]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336) [spring-security-web-5.4.5.jar!/:5.4.5]
    at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:126) [spring-security-web-5.4.5.jar!/:5.4.5]
    at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:81) [spring-security-web-5.4.5.jar!/:5.4.5]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336) [spring-security-web-5.4.5.jar!/:5.4.5]
    at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:105) [spring-security-web-5.4.5.jar!/:5.4.5]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336) [spring-security-web-5.4.5.jar!/:5.4.5]
    at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:149) [spring-security-web-5.4.5.jar!/:5.4.5]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336) [spring-security-web-5.4.5.jar!/:5.4.5]
    at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:63) [spring-security-web-5.4.5.jar!/:5.4.5]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336) [spring-security-web-5.4.5.jar!/:5.4.5]
    at org.springframework.security.web.authentication.logout.logoutFilter.doFilter(logoutFilter.java:103) [spring-security-web-5.4.5.jar!/:5.4.5]
    at org.springframework.security.web.authentication.logout.logoutFilter.doFilter(logoutFilter.java:89) [spring-security-web-5.4.5.jar!/:5.4.5]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336) [spring-security-web-5.4.5.jar!/:5.4.5]
    at org.springframework.security.web.header.HeaderWriterFilter.doHeadersAfter(HeaderWriterFilter.java:90) [spring-security-web-5.4.5.jar!/:5.4.5]
    at org.springframework.security.web.header.HeaderWriterFilter.doFilterInternal(HeaderWriterFilter.java:75) [spring-security-web-5.4.5.jar!/:5.4.5]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) [spring-web-5.3.4.jar!/:5.3.4]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336) [spring-security-web-5.4.5.jar!/:5.4.5]
    at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:110) [spring-security-web-5.4.5.jar!/:5.4.5]
    at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:80) [spring-security-web-5.4.5.jar!/:5.4.5]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336) [spring-security-web-5.4.5.jar!/:5.4.5]
    at org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:55) [spring-security-web-5.4.5.jar!/:5.4.5]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) [spring-web-5.3.4.jar!/:5.3.4]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336) [spring-security-web-5.4.5.jar!/:5.4.5]
    at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:211) [spring-security-web-5.4.5.jar!/:5.4.5]
    at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:183) [spring-security-web-5.4.5.jar!/:5.4.5]
    at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:358) [spring-web-5.3.4.jar!/:5.3.4]
    at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:271) [spring-web-5.3.4.jar!/:5.3.4]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) [tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) [tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100) [spring-web-5.3.4.jar!/:5.3.4]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) [spring-web-5.3.4.jar!/:5.3.4]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) [tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) [tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93) [spring-web-5.3.4.jar!/:5.3.4]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) [spring-web-5.3.4.jar!/:5.3.4]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) [tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) [tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.springframework.boot.actuate.metrics.web.servlet.WebMvcmetricsFilter.doFilterInternal(WebMvcmetricsFilter.java:93) [spring-boot-actuator-2.4.3.jar!/:2.4.3]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) [spring-web-5.3.4.jar!/:5.3.4]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) [tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) [tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201) [spring-web-5.3.4.jar!/:5.3.4]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) [spring-web-5.3.4.jar!/:5.3.4]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) [tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) [tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202) [tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97) [tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:542) [tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:143) [tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) [tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78) [tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:764) [tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:346) [tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:374) [tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) [tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:887) [tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1684) [tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.tomcat.util.net.socketProcessorBase.run(SocketProcessorBase.java:49) [tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at java.lang.Thread.run(Thread.java:834) [?:?]
Caused by: java.io.IOException: Connection reset by peer
    at sun.nio.ch.FiledispatcherImpl.write0(Native Method) ~[?:?]
    at sun.nio.ch.socketdispatcher.write(Socketdispatcher.java:47) ~[?:?]
    at sun.nio.ch.IoUtil.writeFromNativeBuffer(IoUtil.java:113) ~[?:?]
    at sun.nio.ch.IoUtil.write(IoUtil.java:79) ~[?:?]
    at sun.nio.ch.IoUtil.write(IoUtil.java:50) ~[?:?]
    at sun.nio.ch.socketChannelImpl.write(SocketChannelImpl.java:466) ~[?:?]
    at org.apache.tomcat.util.net.SecureNioChannel.flush(SecureNioChannel.java:150) ~[tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.tomcat.util.net.SecureNioChannel.write(SecureNioChannel.java:836) ~[tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.tomcat.util.net.NioBlockingSelector.write(NioBlockingSelector.java:101) ~[tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.tomcat.util.net.NioSelectorPool.write(NioSelectorPool.java:152) ~[tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper.doWrite(NioEndpoint.java:1344) ~[tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.tomcat.util.net.socketWrapperBase.doWrite(SocketWrapperBase.java:764) ~[tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.tomcat.util.net.socketWrapperBase.flushBlocking(SocketWrapperBase.java:717) ~[tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.tomcat.util.net.socketWrapperBase.flush(SocketWrapperBase.java:707) ~[tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.coyote.http11.Http11OutputBuffer$SocketoutputBuffer.flush(Http11OutputBuffer.java:572) ~[tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.coyote.http11.filters.ChunkedOutputFilter.flush(ChunkedOutputFilter.java:157) ~[tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.coyote.http11.Http11OutputBuffer.flush(Http11OutputBuffer.java:220) ~[tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.coyote.http11.Http11Processor.flush(Http11Processor.java:1195) ~[tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.coyote.AbstractProcessor.action(AbstractProcessor.java:402) ~[tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.coyote.Response.action(Response.java:209) ~[tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.catalina.connector.OutputBuffer.doFlush(OutputBuffer.java:305) ~[tomcat-embed-core-9.0.43.jar!/:9.0.43]
    ... 96 more

澄清:我不想知道它是在哪里提出的,我想知道它来自哪里,即它在哪里印刷。

解决方法

经过大量调试后,我能够找到有问题的位置。基本上,我为找到问题所做的只是:

  1. 在引发异常的地方放置一个断点。
  2. 使用调试器逐步执行代码并观察控制台,直到记录错误为止。
  3. 记录错误后,在记录错误之前的最后一个执行的语句放置一个断点,然后在那里重新启动调试。然后单步进入语句的相应代码,继续2。

罪魁祸首是使用不同的日志框架 (JUL) 将异常记录在网络逻辑的深处,这弄乱了我们的日志配置。显然,%rException configuration 不能很好地处理通过 log4j-JUL 适配器传递的异常......