You are viewing a plain text version of this content. The canonical link for it is here.
Posted to notifications@logging.apache.org by "Volkan Yazici (Jira)" <ji...@apache.org> on 2021/10/26 06:54:00 UTC
[jira] [Closed] (LOG4J2-3165) Custom line separator for throwable
breaks formatting
[ https://issues.apache.org/jira/browse/LOG4J2-3165?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Volkan Yazici closed LOG4J2-3165.
---------------------------------
Resolution: Cannot Reproduce
> Custom line separator for throwable breaks formatting
> -----------------------------------------------------
>
> Key: LOG4J2-3165
> URL: https://issues.apache.org/jira/browse/LOG4J2-3165
> Project: Log4j 2
> Issue Type: Bug
> Components: Configuration, Core, Pattern Converters
> Affects Versions: 2.14.1
> Environment: Spring Boot 2.5.4
> Log4j2 2.14.1
> Reporter: Mikhail Dobrinin
> Assignee: Volkan Yazici
> Priority: Critical
>
> The following log pattern used to work great for rewriting exception stack traces.
> {code:java}
> %m%throwable{separator(\r)}%n
> {code}
> I am configuring it in Spring Boot 2 using application.yaml.
> {code:java}
> logging:
> pattern:
> console: "%m%throwable{separator(\r)}%n"
> {code}
> And the exception is being logged like this -
> {code:java}
> log.error("Error message: []", ex);
> {code}
> h2. Expected Behavior (worked in 2.13.3)
> The full exception should be logged. Or at least most of the exception according to default limits present in ThrowableFormatOptions.
> The exception should look like this
> {code:java}
> Error message: [] org.springframework.web.client.HttpClientErrorException$NotFound: 404 : []
> at org.springframework.web.client.HttpClientErrorException.create(HttpClientErrorException.java:113)
> at org.springframework.web.client.DefaultResponseErrorHandler.handleError(DefaultResponseErrorHandler.java:186)
> at org.springframework.web.client.DefaultResponseErrorHandler.handleError(DefaultResponseErrorHandler.java:125)
> at org.springframework.web.client.ResponseErrorHandler.handleError(ResponseErrorHandler.java:63)
> at org.springframework.web.client.RestTemplate.handleResponse(RestTemplate.java:819)
> at org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:777)
> at org.springframework.web.client.RestTemplate.execute(RestTemplate.java:732)
> at org.springframework.web.client.RestTemplate.exchange(RestTemplate.java:612)
> at com.company.utils.AttachmentDownloader.findFileMetadata(AttachmentDownloader.java:152)
> at com.company.utils.AttachmentDownloader.downloadAttachments(AttachmentDownloader.java:85)
> at com.company.services.ServiceRequestService.downloadAndGetAttachments(ServiceRequestService.java:164)
> at com.company.services.ServiceRequestService.lambda$submitRequest$1(ServiceRequestService.java:159)
> at com.company.models.ServiceRequest.also(ServiceRequest.java:113)
> at com.company.services.ServiceRequestService.submitRequest(ServiceRequestService.java:147)
> at com.company.services.ServiceRequestService$$FastClassBySpringCGLIB$$d0dcd3fb.invoke(<generated>)
> at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
> at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:779)
> at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
> at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750)
> at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:123)
> at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:388)
> at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119)
> at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
> at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750)
> at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:692)
> at com.company.services.ServiceRequestService$$EnhancerBySpringCGLIB$$b01821d0.submitRequest(<generated>)
> at com.company.api.ServiceRequestsController.submit(ServiceRequestsController.java:76)
> at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.base/java.lang.reflect.Method.invoke(Method.java:566)
> at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:197)
> at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:141)
> at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:106)
> at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:895)
> at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:808)
> at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
> at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1064)
> at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:963)
> at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006)
> at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:909)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:681)
> at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:764)
> at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:227)
> at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
> at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
> at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
> at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
> at com.company.common.CommonHeadersFilter.doFilterInternal(CommonHeadersFilter.java:47)
> at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
> at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
> at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
> at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100)
> at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
> at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
> at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
> at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93)
> at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
> at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
> at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
> at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.doFilterInternal(WebMvcMetricsFilter.java:96)
> at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
> at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
> at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
> at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201)
> at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
> at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
> at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
> at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:197)
> at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97)
> at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:542)
> at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:135)
> at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
> at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78)
> at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:357)
> at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:382)
> at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
> at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:893)
> at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1726)
> at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
> at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191)
> at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
> at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
> at java.base/java.lang.Thread.run(Thread.java:834)
> {code}
> h2. Current Behavior (broken in 2.14.1)
> The exception is truncated to a single line in my environment.
> {code:java}
> at java.base/java.lang.Thread.run(Thread.java:834)
> {code}
> h2. Theory
> I think it has something to do with the custom separator being set to \r in version 2.14.1. If I remove that part then the exception is logged as expected again.
> {code}
> logging:
> pattern:
> console: "%m%throwable{}%n"
> {code}
> I stepped through some of the Log4j2 code and I can see that the full stack trace is present through most of the processing.
> * Full exception printed to buffer in org.apache.logging.log4j.core.pattern.Throwable
> * PatternConverter#formatOption().
> * Full exception still in buffer after next and final formatter runs (LineSeparatorPatternConverter) in file PatternLayout.
> * Then some kind of encoding logic happens and what is printed to Console is the truncated exception.
--
This message was sent by Atlassian Jira
(v8.3.4#803005)