[
https://issues.apache.org/jira/browse/LOG4J2-3165?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17433151#comment-17433151
]
Mikhail Dobrinin commented on LOG4J2-3165:
------------------------------------------
[~vy] Sorry let me clarify. I agree with the current tests it shows that
behavior has stayed the same between versions. I would need to do more
investigation in my projects to see why it's working in one and not the other.
However, I believe the demonstrated behavior is wrong in both cases. The \r
character is a valid line ending (default in MacOS). It is also a suggested way
to configure Log4j2 when output goes to AWS CloudWatch as this doesn't cause
line breaks and keeps exception messages together.
So I posted results from two different cases where custom separator is used -
one for \r and one for \n. The current tests do demonstrate on both Log4J
versions that the exception is mangled and lines are lost when using \r
separator. Can we use this ticket for that concern?
> 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)
