Varun, would you mind sharing the logger line causing this problem, please?
That is, is it *logger.error("foo", exception)* or *logger.error(exception)*?
Would you share the "exception" too?Assuming you can reproduce this locally, the best way to debug this is to put a breakpoint into both of the following methods in *JsonTemplateLayout* class: public String toSerializable(final LogEvent event) public void encode(final LogEvent event, final ByteBufferDestination destination) And step into *eventResolver.resolve(event, jsonWriter)* calls over there. I can think of two ways to approach this. 1) You either provide us sufficient materials to reproduce the case on our end. 2) Or I can schedule a video call with you and there we try to debug it together. As you might imagine, my preference would be the first option. Let me know which suits you best. On Fri, Dec 11, 2020 at 10:17 PM Varun Thacker <va...@vthacker.in> wrote: > Hello Volkan, > > Thanks for writing the test case. > > So when I run the test case I am seeing what you see as well. Additionally > I checked out the `rel/2.14.0` tag and still wasn't able to reproduce the > problem. > > I then thought of simplifying my log4j2.xml file and removed some Rewrite > filters, changed async logging to sync logging and still see the same thing > - the whole stack trace in the "message" field. > > Next thing I tried was making sure all the remaining log4j2 dependencies > are on 2.14 - ( log4j-1.2-api , log4j-api , log4j-core and > log4j-slf4j-impl ) . They were on 2.11 - Still saw the same problem > > I then tried using the default layout that comes packaged with the JAR ( > file > < > https://github.com/apache/logging-log4j2/blob/rel/2.14.0/log4j-layout-template-json/src/main/resources/LogstashJsonEventLayoutV1.json > > > ) by configuring the template to be *( <JsonTemplateLayout > eventTemplateUri="classpath:LogstashJsonEventLayoutV1.json"/> )* and still > hit the same issue > > Not sure how to debug next. I could have sworn I had gotten it to work with > your https://github.com/vy/log4j2-logstash-layout project and only when I > saw the notice on the github repo that the project moved to apache that I > started to try JsonTemplateLayout > > The fact that in the log lines I am not seeing the `root_cause` key not > even show up even with null means something is still broken with the setup. > I'd previosuly see it being populated with root_cause:null with your > logstash layout project when I had it configured via *"error.root_cause": > "${json:exceptionRootCause:message}"* > > > > > > On Fri, Dec 11, 2020 at 4:43 AM Volkan Yazıcı <volkan.yaz...@gmail.com> > wrote: > > > Hello Varun, > > > > Thanks for the detailed report. Though I still fail to reproduce the > issue. > > > > "message" resolver doesn't have an "includeStackTrace" configuration > > option, though I can see where you are coming from. It is unfortunately a > > leftover in the documentation. I will fix it in the manual. Your usage > > of stackTraceEnabled="true" is correct. > > > > To reproduce your case, I have implemented a test as follows: > > > > @Test > > void varun() { > > > > // Create the layout. > > JsonTemplateLayout layout = JsonTemplateLayout > > .newBuilder() > > .setConfiguration(new DefaultConfiguration()) > > .setEventTemplateUri("classpath:varun.json") > > .setStackTraceEnabled(true) > > .build(); > > > > // Create the log event. > > SimpleMessage message = new SimpleMessage("foo"); > > Exception thrown = new RuntimeException("bar"); > > LogEvent logEvent = Log4jLogEvent > > .newBuilder() > > > > > .setLoggerName("org.apache.logging.log4j.layout.template.json.JsonTemplateLayoutTest") > > .setMessage(message) > > .setThrown(thrown) > > .build(); > > > > String serializedLogEvent = layout.toSerializable(logEvent); > > > > } > > > > where varun.json is the template I have copied from your Gist. When I > put a > > breakpoint at the method closing curly brace, my IDE debugger shows the > > following content for "serializedLogEvent": > > > > { > > "@timestamp": "2020-12-11T12:27:13.599Z", > > "level": "OFF", > > "message": "foo", > > "thread": "ForkJoinPool-1-worker-1", > > "stack": null, > > "error.type": "java.lang.RuntimeException", > > "error.message": "bar", > > "root_cause": "java.lang.RuntimeException: bar\n\tat > > > > > org.apache.logging.log4j.layout.template.json.JsonTemplateLayoutTest.varun(JsonTemplateLayoutTest.java:2131)\n\tat > > sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)\n\tat > > > > > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)\n\tat > > > > > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)\n\tat > > java.lang.reflect.Method.invoke(Method.java:498)\n\tat > > > > > org.junit.platform.commons.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:688)\n\tat > > > > > org.junit.jupiter.engine.execution.MethodInvocation.proceed(MethodInvocation.java:60)\n\tat > > > > > org.junit.jupiter.engine.execution.InvocationInterceptorChain$ValidatingInvocation.proceed(InvocationInterceptorChain.java:131)\n\tat > > > > > org.junit.jupiter.engine.extension.TimeoutExtension.intercept(TimeoutExtension.java:149)\n\tat > > > > > org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestableMethod(TimeoutExtension.java:140)\n\tat > > > > > org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestMethod(TimeoutExtension.java:84)\n\tat > > > > > org.junit.jupiter.engine.execution.ExecutableInvoker$ReflectiveInterceptorCall.lambda$ofVoidMethod$0(ExecutableInvoker.java:115)\n\tat > > > > > org.junit.jupiter.engine.execution.ExecutableInvoker.lambda$invoke$0(ExecutableInvoker.java:105)\n\tat > > > > > org.junit.jupiter.engine.execution.InvocationInterceptorChain$InterceptedInvocation.proceed(InvocationInterceptorChain.java:106)\n\tat > > > > > org.junit.jupiter.engine.execution.InvocationInterceptorChain.proceed(InvocationInterceptorChain.java:64)\n\tat > > > > > org.junit.jupiter.engine.execution.InvocationInterceptorChain.chainAndInvoke(InvocationInterceptorChain.java:45)\n\tat > > > > > org.junit.jupiter.engine.execution.InvocationInterceptorChain.invoke(InvocationInterceptorChain.java:37)\n\tat > > > > > org.junit.jupiter.engine.execution.ExecutableInvoker.invoke(ExecutableInvoker.java:104)\n\tat > > > > > org.junit.jupiter.engine.execution.ExecutableInvoker.invoke(ExecutableInvoker.java:98)\n\tat > > > > > org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$invokeTestMethod$6(TestMethodTestDescriptor.java:210)\n\tat > > > > > org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)\n\tat > > > > > org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.invokeTestMethod(TestMethodTestDescriptor.java:206)\n\tat > > > > > org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:131)\n\tat > > > > > org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:65)\n\tat > > > > > org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:139)\n\tat > > > > > org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)\n\tat > > > > > org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:129)\n\tat > > > > > org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)\n\tat > > > > > org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:127)\n\tat > > > > > org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)\n\tat > > > > > org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:126)\n\tat > > > > > org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:84)\n\tat > > > > > org.junit.platform.engine.support.hierarchical.ForkJoinPoolHierarchicalTestExecutorService$ExclusiveTask.compute(ForkJoinPoolHierarchicalTestExecutorService.java:185)\n\tat > > > > > org.junit.platform.engine.support.hierarchical.ForkJoinPoolHierarchicalTestExecutorService.invokeAll(ForkJoinPoolHierarchicalTestExecutorService.java:129)\n\tat > > > > > org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:143)\n\tat > > > > > org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)\n\tat > > > > > org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:129)\n\tat > > > > > org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)\n\tat > > > > > org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:127)\n\tat > > > > > org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)\n\tat > > > > > org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:126)\n\tat > > > > > org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:84)\n\tat > > > > > org.junit.platform.engine.support.hierarchical.ForkJoinPoolHierarchicalTestExecutorService$ExclusiveTask.compute(ForkJoinPoolHierarchicalTestExecutorService.java:185)\n\tat > > > > > org.junit.platform.engine.support.hierarchical.ForkJoinPoolHierarchicalTestExecutorService.invokeAll(ForkJoinPoolHierarchicalTestExecutorService.java:129)\n\tat > > > > > org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:143)\n\tat > > > > > org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)\n\tat > > > > > org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:129)\n\tat > > > > > org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)\n\tat > > > > > org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:127)\n\tat > > > > > org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)\n\tat > > > > > org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:126)\n\tat > > > > > org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:84)\n\tat > > > > > org.junit.platform.engine.support.hierarchical.ForkJoinPoolHierarchicalTestExecutorService$ExclusiveTask.compute(ForkJoinPoolHierarchicalTestExecutorService.java:185)\n\tat > > java.util.concurrent.RecursiveAction.exec(RecursiveAction.java:189)\n\tat > > java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:289)\n\tat > > > > > java.util.concurrent.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1056)\n\tat > > java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1692)\n\tat > > > > > java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:157)\n" > > } > > > > Hence, this looks pretty legitimate to me. > > > > Would you mind sharing the updated version of the JUnit test I showed > above > > to reproduce your case, please? If not, would you at least show me the > line > > where/how you call the logger? > > > > Kind regards. > > > > On Fri, Dec 11, 2020 at 3:09 AM Varun Thacker <va...@vthacker.in> wrote: > > > > > I'm trying to use JSON Template Layout and can't figure out why is the > > > "message" field contain the full stack trace and why aren't some > > exception > > > resolvers working. They are probably connected. Adding > > > "includeStackTrace": false to the message resolver didn't help. > > > > > > I've attached my log output, the layout config and the JSON Template > > Layout > > > from the log4j2 file here - > > > https://gist.github.com/vthacker/1e129b739f171ac277926f3f62e4d559 > > > > > > What I was trying to achieve was > > > > > > 1. Don't log the entire stack trace in the "message" field > > > 2. Populate the message with with just the exception message. Right > > now > > > it's part of "exception.message" but still not getting populated > > > 3. Log only the "root_cause" part of the exception in a separate > field > > > > > > > > > My primary motivation for this is stack traces get quite large and > > > downstream systems that ingest these logs try to cap the log size and > > some > > > stack traces get truncated . Hence only log the root cause and the > error > > > message > > > > > >
