From 932d115c6695f5bf7900b3089799feb8abe2fd24 Mon Sep 17 00:00:00 2001 From: Joe Pemberton Date: Thu, 18 Sep 2025 16:11:51 -0700 Subject: [PATCH 1/4] Fix: prevent ThrowableStackTraceRenderer from throwing NPEs The `ThrowableStackTraceRenderer` class can throw a `NullPointerException` if the suppressed exceptions associated with the `Throwable` it is rendering are being concurrently mutated. This happens because `ThrowableStackTraceRenderer` invokes `Throwable#getSuppressed()` twice: once in `ThrowableStackTraceRenderer.Context.Metadata#populateMetadata()`, and a second time in `ThrowableStackTraceRenderer#renderThrowable()`, ahead of invoking `ThrowableStackTraceRenderer#renderSuppressed()`. If a racing thread manages to add a new suppressed exception to the being-logged exception between these two invocations, then the `Map` constructed by `populateMetadata()` will contain no mapping for the newly-added suppression, and as a result the dereference performed on line 168 explodes. Note: the unit test I am adding here requires the ability to mock `Throwable#getSuppressed()`. Since this method is `final`, I had to add a dependency on `mockito-inline`, which then required that I fix up some unrelated unit tests that had been relying on the lack of support for mocking `final` methods. This fixes #3929 --- log4j-core-test/pom.xml | 6 ++++ .../db/AbstractDatabaseAppenderTest.java | 10 +++---- .../db/AbstractDatabaseManagerTest.java | 29 ++++++++++++++++++- .../RandomRollingAppenderOnStartupTest.java | 5 +--- .../ThrowableInvertedStackTraceRenderer.java | 6 ++-- .../pattern/ThrowableStackTraceRenderer.java | 27 +++++++++++------ .../3929_ThrowableStackTraceRenderer-npe.xml | 12 ++++++++ 7 files changed, 72 insertions(+), 23 deletions(-) create mode 100644 src/changelog/2.25.1/3929_ThrowableStackTraceRenderer-npe.xml diff --git a/log4j-core-test/pom.xml b/log4j-core-test/pom.xml index 8c8cbc19bbd..13662ae19fe 100644 --- a/log4j-core-test/pom.xml +++ b/log4j-core-test/pom.xml @@ -347,6 +347,12 @@ test + + org.mockito + mockito-inline + test + + org.mockito mockito-junit-jupiter diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/db/AbstractDatabaseAppenderTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/db/AbstractDatabaseAppenderTest.java index fdf2df70843..0ddb7006e4a 100644 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/db/AbstractDatabaseAppenderTest.java +++ b/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); diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/db/AbstractDatabaseManagerTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/db/AbstractDatabaseManagerTest.java index 38fad66231c..a88c78dbbce 100644 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/db/AbstractDatabaseManagerTest.java +++ b/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); diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/rolling/RandomRollingAppenderOnStartupTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/rolling/RandomRollingAppenderOnStartupTest.java index 6ed7c13e945..862e4cb2413 100644 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/rolling/RandomRollingAppenderOnStartupTest.java +++ b/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); } diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableInvertedStackTraceRenderer.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableInvertedStackTraceRenderer.java index 6ad7173462b..f1d26797fa4 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableInvertedStackTraceRenderer.java +++ b/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); } } diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableStackTraceRenderer.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableStackTraceRenderer.java index b16e9b98362..b256f0c5e4d 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableStackTraceRenderer.java +++ b/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 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); } } } diff --git a/src/changelog/2.25.1/3929_ThrowableStackTraceRenderer-npe.xml b/src/changelog/2.25.1/3929_ThrowableStackTraceRenderer-npe.xml new file mode 100644 index 00000000000..18d40364f87 --- /dev/null +++ b/src/changelog/2.25.1/3929_ThrowableStackTraceRenderer-npe.xml @@ -0,0 +1,12 @@ + + + + + Fixes `NullPointerException` thrown by `ThrowableStackTraceRenderer` when suppressed exceptions are mutated concurrently. + + From 26dec017927a15923e2909dcd7bbc11b2fbe3364 Mon Sep 17 00:00:00 2001 From: Joe Pemberton Date: Tue, 30 Sep 2025 15:18:50 -0700 Subject: [PATCH 2/4] Updated PR in response to feedback See conversation: https://github.com/apache/logging-log4j2/pull/3934 --- .../ThrowableStackTraceRendererTest.java | 44 +++++++++++++++++++ .../pattern/ThrowableStackTraceRenderer.java | 6 ++- .../3929_ThrowableStackTraceRenderer-npe.xml | 1 + 3 files changed, 50 insertions(+), 1 deletion(-) create mode 100644 log4j-core-test/src/test/java/org/apache/logging/log4j/core/pattern/ThrowableStackTraceRendererTest.java diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/pattern/ThrowableStackTraceRendererTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/pattern/ThrowableStackTraceRendererTest.java new file mode 100644 index 00000000000..8ebfe8da371 --- /dev/null +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/pattern/ThrowableStackTraceRendererTest.java @@ -0,0 +1,44 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to you under the Apache License, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package org.apache.logging.log4j.core.pattern; + +import static org.mockito.Mockito.doReturn; +import static org.mockito.Mockito.spy; + +import java.util.Collections; +import org.junit.jupiter.api.Test; + +class ThrowableStackTraceRendererTest { + + @Test + void handlesConcurrentlyMutatedSuppressions() { + final Throwable suppressed1 = new Throwable("suppressed1"); + final Throwable suppressed2 = new Throwable("suppressed2"); + final Throwable throwable = spy(new Throwable("throwable")); + final ThrowableRenderer renderer = + new ThrowableStackTraceRenderer<>(Collections.emptyList(), Integer.MAX_VALUE); + // returning suppressed exception arrays of different lengths on each invocation to getSuppressed() emulates + // the behavior experienced by ThrowableStackTraceRenderer when rendering a Throwable whose suppressed + // exceptions are being concurrently mutated by another thread. + doReturn(new Throwable[] {suppressed1}) + .doReturn(new Throwable[] {suppressed1, suppressed2}) + .when(throwable) + .getSuppressed(); + // should not throw NPE + renderer.renderThrowable(new StringBuilder(), throwable, "\n"); + } +} diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableStackTraceRenderer.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableStackTraceRenderer.java index b256f0c5e4d..301f6efccec 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableStackTraceRenderer.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableStackTraceRenderer.java @@ -269,7 +269,11 @@ static final class Metadata { final int stackLength; /** - * The suppressed exceptions attached to this {@link Throwable} + * The suppressed exceptions attached to this {@link Throwable}. + * This needs to be captured separately since {@link Throwable#getSuppressed()} can change. + * + * @see #3929 + * @see #3934 */ final Throwable[] suppressed; diff --git a/src/changelog/2.25.1/3929_ThrowableStackTraceRenderer-npe.xml b/src/changelog/2.25.1/3929_ThrowableStackTraceRenderer-npe.xml index 18d40364f87..10284802659 100644 --- a/src/changelog/2.25.1/3929_ThrowableStackTraceRenderer-npe.xml +++ b/src/changelog/2.25.1/3929_ThrowableStackTraceRenderer-npe.xml @@ -6,6 +6,7 @@ https://logging.apache.org/xml/ns/log4j-changelog-0.xsd" type="fixed"> + Fixes `NullPointerException` thrown by `ThrowableStackTraceRenderer` when suppressed exceptions are mutated concurrently. From 0ba25694d606f4ff483ae2b8717d5773b6f99dbc Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Volkan=20Yaz=C4=B1c=C4=B1?= Date: Fri, 3 Oct 2025 14:15:27 +0200 Subject: [PATCH 3/4] Extend `ThrowablePatternConverterTest` --- .../ThrowablePatternConverterTest.java | 63 +++++++++++++++++++ 1 file changed, 63 insertions(+) diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/pattern/ThrowablePatternConverterTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/pattern/ThrowablePatternConverterTest.java index 24230dd23b9..d9d1d5dc9bb 100644 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/pattern/ThrowablePatternConverterTest.java +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/pattern/ThrowablePatternConverterTest.java @@ -26,7 +26,12 @@ import java.nio.charset.Charset; import java.nio.charset.StandardCharsets; import java.util.List; +import java.util.concurrent.CountDownLatch; +import java.util.concurrent.ExecutorService; +import java.util.concurrent.Executors; +import java.util.concurrent.locks.LockSupport; import java.util.stream.Collectors; +import java.util.stream.IntStream; import java.util.stream.Stream; import org.apache.logging.log4j.Level; import org.apache.logging.log4j.core.LogEvent; @@ -34,6 +39,7 @@ import org.apache.logging.log4j.core.layout.PatternLayout; import org.jspecify.annotations.Nullable; import org.junit.jupiter.api.Nested; +import org.junit.jupiter.api.RepeatedTest; import org.junit.jupiter.api.Test; import org.junit.jupiter.params.ParameterizedTest; import org.junit.jupiter.params.provider.MethodSource; @@ -435,6 +441,63 @@ private static String normalizeStackTrace(final String stackTrace, final String // We replace the `~[?:1.8.0_422]` suffix of such classes with `~[?:0]`. .replaceAll(" ~\\[\\?:[^]]+](\\Q" + conversionEnding + "\\E|$)", " ~[?:0]$1"); } + + @RepeatedTest(10) + @Issue("https://github.com/apache/logging-log4j2/issues/3929") + void concurrent_suppressed_mutation_should_not_cause_failure() throws Exception { + + // Test constants + final int threadCount = Math.max(8, Runtime.getRuntime().availableProcessors()); + final ExecutorService executor = Executors.newFixedThreadPool(threadCount); + final Exception exception = new Exception(); + final CountDownLatch startLatch = + new CountDownLatch(threadCount + /* the main thread invoking the rendering: */ 1); + final int exceptionPerThreadCount = 100; + + // Schedule threads that will start adding suppressed exceptions with the start signal + for (int threadIndex = 0; threadIndex < threadCount; threadIndex++) { + final int threadIndex_ = threadIndex; + executor.submit(() -> { + try { + List exceptions = IntStream.range(0, exceptionPerThreadCount) + .mapToObj(exceptionIndex -> new Exception(threadIndex_ + "-" + exceptionIndex)) + .collect(Collectors.toList()); + startLatch.countDown(); + startLatch.await(); + for (int exceptionIndex = 0; exceptionIndex < exceptionPerThreadCount; exceptionIndex++) { + exception.addSuppressed(exceptions.get(exceptionIndex)); + // Give some time slack to increase randomness + LockSupport.parkNanos(1); + } + } catch (InterruptedException ignored) { + // Restore the interrupt + Thread.currentThread().interrupt(); + } + }); + } + + // Create the formatter + final List patternFormatters = PATTERN_PARSER.parse(patternPrefix, false, true, true); + assertThat(patternFormatters).hasSize(1); + final PatternFormatter patternFormatter = patternFormatters.get(0); + + // Create the log event and the layout buffer + final LogEvent logEvent = Log4jLogEvent.newBuilder() + .setThrown(exception) + .setLevel(LEVEL) + .build(); + final StringBuilder buffer = new StringBuilder(16384); + + // Trigger the start latch and format the exception + startLatch.countDown(); + startLatch.await(); + for (int i = 0; i < 1_000_000; i++) { + // Give some time slack to increase randomness + LockSupport.parkNanos(1); + patternFormatter.format(logEvent, buffer); + buffer.setLength(0); + } + } } static String convert(final String pattern) { From 625393881a68db3fe5f5e864a29cd2ae8f2c3a5d Mon Sep 17 00:00:00 2001 From: Joe Pemberton Date: Fri, 3 Oct 2025 09:12:15 -0700 Subject: [PATCH 4/4] Remove mockito-inline and related changes; add race test. --- log4j-core-test/pom.xml | 6 --- .../db/AbstractDatabaseAppenderTest.java | 10 +++-- .../db/AbstractDatabaseManagerTest.java | 29 +----------- .../RandomRollingAppenderOnStartupTest.java | 5 ++- .../ThrowablePatternConverterTest.java | 6 ++- .../ThrowableStackTraceRendererTest.java | 44 ------------------- 6 files changed, 16 insertions(+), 84 deletions(-) delete mode 100644 log4j-core-test/src/test/java/org/apache/logging/log4j/core/pattern/ThrowableStackTraceRendererTest.java diff --git a/log4j-core-test/pom.xml b/log4j-core-test/pom.xml index 13662ae19fe..8c8cbc19bbd 100644 --- a/log4j-core-test/pom.xml +++ b/log4j-core-test/pom.xml @@ -347,12 +347,6 @@ test - - org.mockito - mockito-inline - test - - org.mockito mockito-junit-jupiter diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/db/AbstractDatabaseAppenderTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/db/AbstractDatabaseAppenderTest.java index 0ddb7006e4a..fdf2df70843 100644 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/db/AbstractDatabaseAppenderTest.java +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/db/AbstractDatabaseAppenderTest.java @@ -72,11 +72,13 @@ public void testAppend() { final LogEvent event2 = mock(LogEvent.class); appender.append(event1); - then(manager).should().write(same(event1), isNull()); + then(manager).should().isBuffered(); + then(manager).should().writeThrough(same(event1), isNull()); reset(manager); appender.append(event2); - then(manager).should().write(same(event2), isNull()); + then(manager).should().isBuffered(); + then(manager).should().writeThrough(same(event2), isNull()); reset(manager); } @@ -106,7 +108,7 @@ public void testReplaceManager() throws Exception { final LocalAbstractDatabaseManager newManager = mock(LocalAbstractDatabaseManager.class); appender.replaceManager(newManager); then(manager).should().close(); - then(newManager).should().startup(); + then(newManager).should().startupInternal(); appender.stop(); then(newManager).should().stop(0L, TimeUnit.MILLISECONDS); @@ -117,7 +119,7 @@ public void testStartAndStop() throws Exception { setUp("name"); appender.start(); - then(manager).should().startup(); + then(manager).should().startupInternal(); appender.stop(); then(manager).should().stop(0L, TimeUnit.MILLISECONDS); diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/db/AbstractDatabaseManagerTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/db/AbstractDatabaseManagerTest.java index a88c78dbbce..38fad66231c 100644 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/db/AbstractDatabaseManagerTest.java +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/db/AbstractDatabaseManagerTest.java @@ -86,7 +86,6 @@ 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(); @@ -96,7 +95,6 @@ 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(); @@ -106,7 +104,6 @@ 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(); @@ -136,23 +133,14 @@ 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); @@ -183,20 +171,13 @@ 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); - 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()); @@ -226,22 +207,14 @@ 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); diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/rolling/RandomRollingAppenderOnStartupTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/rolling/RandomRollingAppenderOnStartupTest.java index 862e4cb2413..6ed7c13e945 100644 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/rolling/RandomRollingAppenderOnStartupTest.java +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/rolling/RandomRollingAppenderOnStartupTest.java @@ -86,7 +86,10 @@ public static void afterClass() throws Exception { size = Files.size(path); } else { final long fileSize = Files.size(path); - assertEquals("Expected size: " + size + " Size of " + path + ": " + fileSize, size, fileSize); + assertEquals( + "Expected size: " + size + " Size of " + path.getFileName() + ": " + fileSize, + size, + fileSize); } Files.delete(path); } diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/pattern/ThrowablePatternConverterTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/pattern/ThrowablePatternConverterTest.java index d9d1d5dc9bb..c893947423c 100644 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/pattern/ThrowablePatternConverterTest.java +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/pattern/ThrowablePatternConverterTest.java @@ -29,6 +29,7 @@ import java.util.concurrent.CountDownLatch; import java.util.concurrent.ExecutorService; import java.util.concurrent.Executors; +import java.util.concurrent.atomic.AtomicInteger; import java.util.concurrent.locks.LockSupport; import java.util.stream.Collectors; import java.util.stream.IntStream; @@ -453,6 +454,7 @@ void concurrent_suppressed_mutation_should_not_cause_failure() throws Exception final CountDownLatch startLatch = new CountDownLatch(threadCount + /* the main thread invoking the rendering: */ 1); final int exceptionPerThreadCount = 100; + final AtomicInteger runningThreadCountRef = new AtomicInteger(threadCount); // Schedule threads that will start adding suppressed exceptions with the start signal for (int threadIndex = 0; threadIndex < threadCount; threadIndex++) { @@ -472,6 +474,8 @@ void concurrent_suppressed_mutation_should_not_cause_failure() throws Exception } catch (InterruptedException ignored) { // Restore the interrupt Thread.currentThread().interrupt(); + } finally { + runningThreadCountRef.decrementAndGet(); } }); } @@ -491,7 +495,7 @@ void concurrent_suppressed_mutation_should_not_cause_failure() throws Exception // Trigger the start latch and format the exception startLatch.countDown(); startLatch.await(); - for (int i = 0; i < 1_000_000; i++) { + while (runningThreadCountRef.get() > 0) { // Give some time slack to increase randomness LockSupport.parkNanos(1); patternFormatter.format(logEvent, buffer); diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/pattern/ThrowableStackTraceRendererTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/pattern/ThrowableStackTraceRendererTest.java deleted file mode 100644 index 8ebfe8da371..00000000000 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/pattern/ThrowableStackTraceRendererTest.java +++ /dev/null @@ -1,44 +0,0 @@ -/* - * Licensed to the Apache Software Foundation (ASF) under one or more - * contributor license agreements. See the NOTICE file distributed with - * this work for additional information regarding copyright ownership. - * The ASF licenses this file to you under the Apache License, Version 2.0 - * (the "License"); you may not use this file except in compliance with - * the License. You may obtain a copy of the License at - * - * http://www.apache.org/licenses/LICENSE-2.0 - * - * Unless required by applicable law or agreed to in writing, software - * distributed under the License is distributed on an "AS IS" BASIS, - * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. - * See the License for the specific language governing permissions and - * limitations under the License. - */ -package org.apache.logging.log4j.core.pattern; - -import static org.mockito.Mockito.doReturn; -import static org.mockito.Mockito.spy; - -import java.util.Collections; -import org.junit.jupiter.api.Test; - -class ThrowableStackTraceRendererTest { - - @Test - void handlesConcurrentlyMutatedSuppressions() { - final Throwable suppressed1 = new Throwable("suppressed1"); - final Throwable suppressed2 = new Throwable("suppressed2"); - final Throwable throwable = spy(new Throwable("throwable")); - final ThrowableRenderer renderer = - new ThrowableStackTraceRenderer<>(Collections.emptyList(), Integer.MAX_VALUE); - // returning suppressed exception arrays of different lengths on each invocation to getSuppressed() emulates - // the behavior experienced by ThrowableStackTraceRenderer when rendering a Throwable whose suppressed - // exceptions are being concurrently mutated by another thread. - doReturn(new Throwable[] {suppressed1}) - .doReturn(new Throwable[] {suppressed1, suppressed2}) - .when(throwable) - .getSuppressed(); - // should not throw NPE - renderer.renderThrowable(new StringBuilder(), throwable, "\n"); - } -}