Use ShortenedThrowableConverter in logback config

.gitignore

@@ -153,6 +153,10 @@ local.properties
 
 # Spring Boot Tooling
 .sts4-cache/
+
+# PMD Plugin
+.pmd
+.ruleset
 ### End of Eclipse
 
 # Covers JetBrains IDEs: IntelliJ, RubyMine, PhpStorm, AppCode, PyCharm, CLion, Android Studio and WebStorm
@@ -178,4 +182,4 @@ nbdist/
 *.ntvs*
 *.njsproj
 *.sln
-*.sw?
+*.sw?

refarch-backend/src/main/resources/logback-spring.xml

@@ -50,32 +50,17 @@
 
     <springProfile name="json-logging">
 
-        <!-- Log appender -->
         <appender name="JSON_STDOUT" class="ch.qos.logback.core.ConsoleAppender">
-            <encoder class="net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder">
-                <providers>
-                    <!-- provides the fields in the configured pattern -->
-                    <pattern>
-                        <!-- the pattern that defines what to include -->
-                        <pattern>
-                            {
-                                "timestamp" : "%date{yyyy-MM-dd'T'HH:mm:ss.SSS}",
-                                "appName" : "${springAppName}",
-                                "TraceId" : "%mdc{traceId}",
-                                "SpanId" : "%mdc{spanId}",
-                                "X-Span-Export" : "%mdc{X-Span-Export}",
-                                "thread" : "%thread",
-                                "level" : "%level",
-                                "logger": "%logger",
-                                "location" : {
-                                    "fileName" : "%file",
-                                    "line" : "%line"
-                                },
-                                "message": "%message"
-                            }
-                        </pattern>
-                    </pattern>
-                </providers>
+            <encoder class="net.logstash.logback.encoder.LogstashEncoder">
+                <throwableConverter
+                    class="net.logstash.logback.stacktrace.ShortenedThrowableConverter">
+                    <!-- default max size of one log line in docker is 16kb - UTF8 ~ 1 Character = 1 Byte -->
+                    <!-- therefore limit stack_traces to a maximum of 8192 characters (to leave room for the rest of the message) -->
+                    <maxLength>8192</maxLength>
+                    <exclude>sun\.reflect\..*\.invoke.*</exclude>
+                    <exclude>net\.sf\.cglib\.proxy\.MethodProxy\.invoke</exclude>
+                    <rootCauseFirst>true</rootCauseFirst>
+                </throwableConverter>
             </encoder>
         </appender>
 

refarch-backend/src/test/java/de/muenchen/refarch/TestConstants.java

@@ -9,13 +9,15 @@
 import org.springframework.hateoas.RepresentationModel;
 
 @NoArgsConstructor(access = AccessLevel.PRIVATE)
-@SuppressWarnings("PMD.TestClassWithoutTestCases")
+@SuppressWarnings({ "PMD.TestClassWithoutTestCases", "PMD.DataClass" })
 public final class TestConstants {
 
     public static final String SPRING_TEST_PROFILE = "test";
 
     public static final String SPRING_NO_SECURITY_PROFILE = "no-security";
 
+    public static final String SPRING_JSON_LOGGING_PROFILE = "json-logging";
+
     public static final String TESTCONTAINERS_POSTGRES_IMAGE = "postgres:16.0-alpine3.18";
 
     @NoArgsConstructor

refarch-backend/src/test/java/de/muenchen/refarch/configuration/LogbackJsonLoggingConfigurationTest.java

@@ -0,0 +1,116 @@
+package de.muenchen.refarch.configuration;
+
+import static de.muenchen.refarch.TestConstants.SPRING_JSON_LOGGING_PROFILE;
+import static org.assertj.core.api.Assertions.assertThat;
+
+import java.io.PrintWriter;
+import java.io.StringWriter;
+import java.util.Arrays;
+import java.util.regex.Matcher;
+import java.util.regex.Pattern;
+
+import org.apache.commons.lang3.StringUtils;
+import org.assertj.core.data.Percentage;
+import org.junit.jupiter.api.AfterEach;
+import org.junit.jupiter.api.Assertions;
+import org.junit.jupiter.api.BeforeEach;
+import org.junit.jupiter.api.Test;
+import org.junit.jupiter.api.extension.ExtendWith;
+import org.slf4j.MDC;
+import org.springframework.boot.test.context.SpringBootTest;
+import org.springframework.boot.test.context.SpringBootTest.WebEnvironment;
+import org.springframework.boot.test.system.CapturedOutput;
+import org.springframework.boot.test.system.OutputCaptureExtension;
+import org.springframework.context.annotation.Configuration;
+import org.springframework.test.annotation.DirtiesContext;
+import org.springframework.test.context.ActiveProfiles;
+
+import lombok.extern.slf4j.Slf4j;
+
+@SpringBootTest(webEnvironment = WebEnvironment.NONE)
+@ActiveProfiles(SPRING_JSON_LOGGING_PROFILE)
+@ExtendWith(OutputCaptureExtension.class)
+@Slf4j
+@DirtiesContext // force logback config reset after test
+class LogbackJsonLoggingConfigurationTest {
+
+    private static final String EXCEPTION_MESSAGE = "EXC_MESSAGE";
+    private static final Pattern STACKTRACE_PATTERN = Pattern.compile("stack_trace\":\"([^\"]*)\"");
+
+    private Throwable exception;
+
+    @Configuration
+    @SuppressWarnings("PMD.TestClassWithoutTestCases")
+    /* default */ static class TestConfiguration {
+    }
+
+    @BeforeEach
+    void setup() {
+        // prepare an exception with huge stacktrace contents
+        exception = genExceptionStack(new IllegalArgumentException("rootcause"), 40);
+        // make sure generated stacktrace is long enough to test shortening
+        final StringWriter sw = new StringWriter();
+        final PrintWriter pw = new PrintWriter(sw);
+        exception.printStackTrace(pw);
+        final String untouchedStacktrace = sw.toString();
+        assertThat(untouchedStacktrace.length()).isGreaterThan(16_000);
+    }
+
+    @AfterEach
+    void tearDown() {
+        // make sure MDC is clean after tests
+        MDC.clear();
+    }
+
+    @Test
+    void putsMdcInJson(final CapturedOutput output) {
+        MDC.put("traceId", "myTraceId");
+        MDC.put("spanId", "mySpanId");
+        final String message = "my message";
+        log.info(message);
+
+        final String line = findLogmessageInOutput(output, message);
+
+        assertThat(line).contains("myTraceId").contains("mySpanId");
+    }
+
+    @Test
+    void jsonPrintsRootCauseOfStacktraceFirst(final CapturedOutput output) {
+        log.error(EXCEPTION_MESSAGE, exception);
+
+        final String line = findLogmessageInOutput(output, EXCEPTION_MESSAGE);
+
+        assertThat(line.indexOf("rootcause")).isLessThan(line.indexOf("stackmessage-#1"));
+    }
+
+    @Test
+    void shortensLengthOfStacktrace(final CapturedOutput output) {
+        log.error(EXCEPTION_MESSAGE, exception);
+
+        final String line = findLogmessageInOutput(output, EXCEPTION_MESSAGE);
+
+        final Matcher matcher = STACKTRACE_PATTERN.matcher(line);
+        if (matcher.find()) {
+            final String group = matcher.group(1);
+            // apparently ShortenedThrowableConverter is not a 100% accurate with "maxLength" - but that is fine
+            assertThat(group.length()).isCloseTo(8_192, Percentage.withPercentage(10.0d));
+        } else {
+            Assertions.fail("Expected to find a stack_trace element in JSON structure, but was not present.");
+        }
+    }
+
+    private String findLogmessageInOutput(final CapturedOutput output, final String expected) {
+        final String fullOutput = output.getOut();
+        return Arrays.stream(fullOutput.split("\n"))
+                .filter(s -> s.contains(expected))
+                .findFirst().orElseThrow();
+    }
+
+    private static Throwable genExceptionStack(final Throwable root, final int index) {
+        if (index > 0) {
+            return new IllegalArgumentException("stackmessage-#%d: (%s)".formatted(index, StringUtils.repeat("abcd ", 20)), genExceptionStack(root, index - 1));
+        } else {
+            return root;
+        }
+    }
+}

refarch-eai/pom.xml

@@ -99,6 +99,11 @@
             <artifactId>spring-boot-starter-test</artifactId>
             <scope>test</scope>
         </dependency>
+        <dependency>
+            <groupId>org.apache.commons</groupId>
+            <artifactId>commons-lang3</artifactId>
+            <scope>test</scope>
+        </dependency>
 
         <!-- Logging -->
         <dependency>
@@ -216,6 +221,7 @@
                     <targetJdk>${java.version}</targetJdk>
                     <printFailingErrors>true</printFailingErrors>
                     <linkXRef>false</linkXRef>
+                    <includeTests>true</includeTests>
                     <excludeRoots>
                         <excludeRoot>target/generated-sources</excludeRoot>
                         <excludeRoot>target/generated-test-sources</excludeRoot>

refarch-eai/src/main/resources/logback-spring.xml

@@ -50,32 +50,17 @@
 
     <springProfile name="json-logging">
 
-        <!-- Log appender -->
         <appender name="JSON_STDOUT" class="ch.qos.logback.core.ConsoleAppender">
-            <encoder class="net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder">
-                <providers>
-                    <!-- provides the fields in the configured pattern -->
-                    <pattern>
-                        <!-- the pattern that defines what to include -->
-                        <pattern>
-                            {
-                                "timestamp" : "%date{yyyy-MM-dd'T'HH:mm:ss.SSS}",
-                                "appName" : "${springAppName}",
-                                "TraceId" : "%mdc{traceId}",
-                                "SpanId" : "%mdc{spanId}",
-                                "X-Span-Export" : "%mdc{X-Span-Export}",
-                                "thread" : "%thread",
-                                "level" : "%level",
-                                "logger": "%logger",
-                                "location" : {
-                                    "fileName" : "%file",
-                                    "line" : "%line"
-                                },
-                                "message": "%message"
-                            }
-                        </pattern>
-                    </pattern>
-                </providers>
+            <encoder class="net.logstash.logback.encoder.LogstashEncoder">
+                <throwableConverter
+                    class="net.logstash.logback.stacktrace.ShortenedThrowableConverter">
+                    <!-- default max size of one log line in docker is 16kb - UTF8 ~ 1 Character = 1 Byte -->
+                    <!-- therefore limit stack_traces to a maximum of 8192 characters (to leave room for the rest of the message) -->
+                    <maxLength>8192</maxLength>
+                    <exclude>sun\.reflect\..*\.invoke.*</exclude>
+                    <exclude>net\.sf\.cglib\.proxy\.MethodProxy\.invoke</exclude>
+                    <rootCauseFirst>true</rootCauseFirst>
+                </throwableConverter>
             </encoder>
         </appender>
 

refarch-eai/src/test/java/de/muenchen/refarch/EaiTest.java

@@ -18,7 +18,7 @@
  **/
 @SpringBootTest
 @CamelSpringBootTest
-@ActiveProfiles("test")
+@ActiveProfiles(TestConstants.SPRING_TEST_PROFILE)
 class EaiTest {
 
     @SuppressWarnings("unused") // field is auto-injected by camel
@@ -31,7 +31,7 @@ class EaiTest {
 
     @Test
     void sendToMockTest() throws InterruptedException {
-        var message = "Hello Test !";
+        final String message = "Hello Test !";
         output.expectedMessageCount(1);
 
         producer.sendBody(message);

refarch-eai/src/test/java/de/muenchen/refarch/TestConstants.java

@@ -0,0 +1,14 @@
+package de.muenchen.refarch;
+
+import lombok.AccessLevel;
+import lombok.NoArgsConstructor;
+
+@SuppressWarnings("PMD.TestClassWithoutTestCases")
+@NoArgsConstructor(access = AccessLevel.PRIVATE)
+public final class TestConstants {
+
+    public static final String SPRING_TEST_PROFILE = "test";
+
+    public static final String SPRING_JSON_LOGGING_PROFILE = "json-logging";
+
+}