Fix: prevent ThrowableStackTraceRenderer from throwing NPEs

log4j-core-test/pom.xml

@@ -347,6 +347,12 @@
       <scope>test</scope>
     </dependency>
 
+    <dependency>
+      <groupId>org.mockito</groupId>
+      <artifactId>mockito-inline</artifactId>
+      <scope>test</scope>
+    </dependency>
+
     <dependency>
       <groupId>org.mockito</groupId>
       <artifactId>mockito-junit-jupiter</artifactId>

log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/db/AbstractDatabaseAppenderTest.java

@@ -72,13 +72,11 @@ public void testAppend() {
         final LogEvent event2 = mock(LogEvent.class);
 
         appender.append(event1);
-        then(manager).should().isBuffered();
-        then(manager).should().writeThrough(same(event1), isNull());
+        then(manager).should().write(same(event1), isNull());
         reset(manager);
 
         appender.append(event2);
-        then(manager).should().isBuffered();
-        then(manager).should().writeThrough(same(event2), isNull());
+        then(manager).should().write(same(event2), isNull());
         reset(manager);
     }
 
@@ -108,7 +106,7 @@ public void testReplaceManager() throws Exception {
         final LocalAbstractDatabaseManager newManager = mock(LocalAbstractDatabaseManager.class);
         appender.replaceManager(newManager);
         then(manager).should().close();
-        then(newManager).should().startupInternal();
+        then(newManager).should().startup();
 
         appender.stop();
         then(newManager).should().stop(0L, TimeUnit.MILLISECONDS);
@@ -119,7 +117,7 @@ public void testStartAndStop() throws Exception {
         setUp("name");
 
         appender.start();
-        then(manager).should().startupInternal();
+        then(manager).should().startup();
 
         appender.stop();
         then(manager).should().stop(0L, TimeUnit.MILLISECONDS);

log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/db/AbstractDatabaseManagerTest.java

@@ -86,6 +86,7 @@ void testBuffering01() throws Exception {
         reset(manager);
 
         manager.write(event1, null);
+        then(manager).should().write(same(event1), isNull());
         then(manager).should().writeThrough(same(event1), isNull());
         then(manager).should().connectAndStart();
         then(manager).should().isBuffered();
@@ -95,6 +96,7 @@ void testBuffering01() throws Exception {
         reset(manager);
 
         manager.write(event2, null);
+        then(manager).should().write(same(event2), isNull());
         then(manager).should().writeThrough(same(event2), isNull());
         then(manager).should().connectAndStart();
         then(manager).should().isBuffered();
@@ -104,6 +106,7 @@ void testBuffering01() throws Exception {
         reset(manager);
 
         manager.write(event3, null);
+        then(manager).should().write(same(event3), isNull());
         then(manager).should().writeThrough(same(event3), isNull());
         then(manager).should().connectAndStart();
         then(manager).should().isBuffered();
@@ -133,14 +136,23 @@ void testBuffering02() throws Exception {
         when(event4.toImmutable()).thenReturn(event4copy);
 
         manager.startup();
+        then(manager).should().startup();
+        then(manager).should().isRunning();
         then(manager).should().startupInternal();
 
         manager.write(event1, null);
+        then(manager).should().write(event1, null);
         manager.write(event2, null);
+        then(manager).should().write(event2, null);
         manager.write(event3, null);
+        then(manager).should().write(event3, null);
         manager.write(event4, null);
+        then(manager).should().write(event4, null);
 
         then(manager).should().connectAndStart();
+
+        then(manager).should().flush();
+        verify(manager, times(2)).isRunning();
         verify(manager, times(5)).isBuffered(); // 4 + 1 in flush()
         then(manager).should().writeInternal(same(event1copy), isNull());
         then(manager).should().buffer(event1);
@@ -171,13 +183,20 @@ void testBuffering03() throws Exception {
         when(event3.toImmutable()).thenReturn(event3copy);
 
         manager.startup();
+        then(manager).should().startup();
+        then(manager).should().isRunning();
         then(manager).should().startupInternal();
 
         manager.write(event1, null);
+        then(manager).should().write(same(event1), isNull());
         manager.write(event2, null);
+        then(manager).should().write(same(event2), isNull());
         manager.write(event3, null);
-        manager.flush();
+        then(manager).should().write(same(event3), isNull());
 
+        manager.flush();
+        then(manager).should().flush();
+        verify(manager, times(2)).isRunning();
         then(manager).should().connectAndStart();
         verify(manager, times(4)).isBuffered();
         then(manager).should().writeInternal(same(event1copy), isNull());
@@ -207,14 +226,22 @@ void testBuffering04() throws Exception {
         when(event3.toImmutable()).thenReturn(event3copy);
 
         manager.startup();
+        then(manager).should().startup();
+        then(manager).should().isRunning();
         then(manager).should().startupInternal();
 
         manager.write(event1, null);
+        then(manager).should().write(same(event1), isNull());
         manager.write(event2, null);
+        then(manager).should().write(same(event2), isNull());
         manager.write(event3, null);
+        then(manager).should().write(same(event3), isNull());
         manager.shutdown();
+        then(manager).should().shutdown();
+        then(manager).should().flush();
 
         then(manager).should().connectAndStart();
+        verify(manager, times(3)).isRunning();
         verify(manager, times(4)).isBuffered();
         then(manager).should().writeInternal(same(event1copy), isNull());
         then(manager).should().buffer(event1);

log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/rolling/RandomRollingAppenderOnStartupTest.java

@@ -86,10 +86,7 @@ public static void afterClass() throws Exception {
                     size = Files.size(path);
                 } else {
                     final long fileSize = Files.size(path);
-                    assertEquals(
-                            "Expected size: " + size + " Size of " + path.getFileName() + ": " + fileSize,
-                            size,
-                            fileSize);
+                    assertEquals("Expected size: " + size + " Size of " + path + ": " + fileSize, size, fileSize);
                 }
                 Files.delete(path);
             }

log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableInvertedStackTraceRenderer.java

@@ -60,6 +60,7 @@ private void renderThrowable(
             buffer.append(']');
             buffer.append(lineSeparator);
         } else {
+            final Context.Metadata metadata = context.metadataByThrowable.get(throwable);
             lineCapacityAcquired = renderCause(
                     buffer,
                     throwable.getCause(),
@@ -73,9 +74,8 @@ private void renderThrowable(
             }
             renderThrowableMessage(buffer, throwable);
             buffer.append(lineSeparator);
-            renderStackTraceElements(buffer, throwable, context, prefix, lineSeparator);
-            renderSuppressed(
-                    buffer, throwable.getSuppressed(), context, visitedThrowables, prefix + '\t', lineSeparator);
+            renderStackTraceElements(buffer, throwable, context, metadata, prefix, lineSeparator);
+            renderSuppressed(buffer, metadata.suppressed, context, visitedThrowables, prefix + '\t', lineSeparator);
         }
     }
 

log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableStackTraceRenderer.java

@@ -95,11 +95,11 @@ private void renderThrowable(
             buffer.append(']');
             buffer.append(lineSeparator);
         } else {
+            final Context.Metadata metadata = context.metadataByThrowable.get(throwable);
             renderThrowableMessage(buffer, throwable);
             buffer.append(lineSeparator);
-            renderStackTraceElements(buffer, throwable, context, prefix, lineSeparator);
-            renderSuppressed(
-                    buffer, throwable.getSuppressed(), context, visitedThrowables, prefix + '\t', lineSeparator);
+            renderStackTraceElements(buffer, throwable, context, metadata, prefix, lineSeparator);
+            renderSuppressed(buffer, metadata.suppressed, context, visitedThrowables, prefix + '\t', lineSeparator);
             renderCause(buffer, throwable.getCause(), context, visitedThrowables, prefix, lineSeparator);
         }
     }
@@ -150,10 +150,10 @@ final void renderStackTraceElements(
             final StringBuilder buffer,
             final Throwable throwable,
             final C context,
+            final Context.Metadata metadata,
             final String prefix,
             final String lineSeparator) {
         context.ignoredStackTraceElementCount = 0;
-        final Context.Metadata metadata = context.metadataByThrowable.get(throwable);
         final StackTraceElement[] stackTraceElements = throwable.getStackTrace();
         for (int i = 0; i < metadata.stackLength; i++) {
             renderStackTraceElement(buffer, stackTraceElements[i], context, prefix, lineSeparator);
@@ -268,9 +268,15 @@ static final class Metadata {
              */
             final int stackLength;
 
-            private Metadata(final int commonElementCount, final int stackLength) {
+            /**
+             * The suppressed exceptions attached to this {@link Throwable}
+             */
+            final Throwable[] suppressed;
+
+            private Metadata(final int commonElementCount, final int stackLength, final Throwable[] suppressed) {
                 this.commonElementCount = commonElementCount;
                 this.stackLength = stackLength;
+                this.suppressed = suppressed;
             }
 
             static Map<Throwable, Metadata> ofThrowable(final Throwable throwable) {
@@ -288,11 +294,12 @@ private static void populateMetadata(
                 // Populate metadata of the current throwable
                 @Nullable
                 final StackTraceElement[] rootTrace = parentThrowable == null ? null : parentThrowable.getStackTrace();
-                final Metadata metadata = populateMetadata(rootTrace, throwable.getStackTrace());
+                final Metadata metadata =
+                        populateMetadata(rootTrace, throwable.getStackTrace(), throwable.getSuppressed());
                 metadataByThrowable.put(throwable, metadata);
 
                 // Populate metadata of suppressed exceptions
-                for (final Throwable suppressed : throwable.getSuppressed()) {
+                for (final Throwable suppressed : metadata.suppressed) {
                     if (!visitedThrowables.contains(suppressed)) {
                         visitedThrowables.add(suppressed);
                         populateMetadata(metadataByThrowable, visitedThrowables, throwable, suppressed);
@@ -308,7 +315,9 @@ private static void populateMetadata(
             }
 
             private static Metadata populateMetadata(
-                    @Nullable final StackTraceElement[] parentTrace, final StackTraceElement[] currentTrace) {
+                    @Nullable final StackTraceElement[] parentTrace,
+                    final StackTraceElement[] currentTrace,
+                    final Throwable[] suppressed) {
                 int commonElementCount;
                 int stackLength;
                 if (parentTrace != null) {
@@ -326,7 +335,7 @@ private static Metadata populateMetadata(
                     commonElementCount = 0;
                     stackLength = currentTrace.length;
                 }
-                return new Metadata(commonElementCount, stackLength);
+                return new Metadata(commonElementCount, stackLength, suppressed);
             }
         }
     }

src/changelog/2.25.1/3929_ThrowableStackTraceRenderer-npe.xml

@@ -0,0 +1,12 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<entry xmlns="https://logging.apache.org/xml/ns"
+       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
+       xsi:schemaLocation="
+           https://logging.apache.org/xml/ns
+           https://logging.apache.org/xml/ns/log4j-changelog-0.xsd"
+       type="fixed">
+  <issue id="3929" link="https://github.com/apache/logging-log4j2/issues/3929"/>
+  <description format="asciidoc">
+    Fixes `NullPointerException` thrown by `ThrowableStackTraceRenderer` when suppressed exceptions are mutated concurrently.
+  </description>
+</entry>