From bad8b56fed8e50413ce61a246f78ec60dd2f5ab7 Mon Sep 17 00:00:00 2001 From: "Piotr P. Karwasz" Date: Sun, 24 Nov 2024 12:10:15 +0100 Subject: [PATCH] Fix `ConcurrentModificationException` in `updateLoggers()` The `InternalLoggerRegistry` implementation introduced in version `2.24.2` did not return a copy of the registry, when `InternalLoggerRegistry.getLoggers()` was called. This could lead to a `ConcurrentModificationException` if a thread creates a new logger, while another thread calls `LoggerContext.updateLoggers()`. Closes #3234 --- .../logging/log4j/spi/LoggerRegistry.java | 16 ++++---- .../logging/log4j/core/LoggerContextTest.java | 38 +++++++++++++++++++ .../logging/log4j/core/LoggerContext.java | 3 +- .../util/internal/InternalLoggerRegistry.java | 10 ++++- .../3234_concurrent-logger-modification.xml | 10 +++++ 5 files changed, 65 insertions(+), 12 deletions(-) create mode 100644 src/changelog/.2.x.x/3234_concurrent-logger-modification.xml diff --git a/log4j-api/src/main/java/org/apache/logging/log4j/spi/LoggerRegistry.java b/log4j-api/src/main/java/org/apache/logging/log4j/spi/LoggerRegistry.java index f7646b02730..87cee471135 100644 --- a/log4j-api/src/main/java/org/apache/logging/log4j/spi/LoggerRegistry.java +++ b/log4j-api/src/main/java/org/apache/logging/log4j/spi/LoggerRegistry.java @@ -18,7 +18,6 @@ import static java.util.Objects.requireNonNull; -import java.util.ArrayList; import java.util.Collection; import java.util.Collections; import java.util.HashMap; @@ -28,6 +27,7 @@ import java.util.concurrent.locks.Lock; import java.util.concurrent.locks.ReadWriteLock; import java.util.concurrent.locks.ReentrantReadWriteLock; +import java.util.stream.Collectors; import org.apache.logging.log4j.Logger; import org.apache.logging.log4j.message.MessageFactory; import org.apache.logging.log4j.message.ParameterizedMessageFactory; @@ -158,19 +158,19 @@ public LoggerRegistry(final MapFactory mapFactory) { } public Collection getLoggers() { - return getLoggers(new ArrayList<>()); - } - - public Collection getLoggers(final Collection destination) { - requireNonNull(destination, "destination"); readLock.lock(); try { - loggerByMessageFactoryByName.values().stream() + return loggerByMessageFactoryByName.values().stream() .flatMap(loggerByMessageFactory -> loggerByMessageFactory.values().stream()) - .forEach(destination::add); + .collect(Collectors.toList()); } finally { readLock.unlock(); } + } + + public Collection getLoggers(final Collection destination) { + requireNonNull(destination, "destination"); + destination.addAll(getLoggers()); return destination; } diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/LoggerContextTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/LoggerContextTest.java index 0538b632d10..e14bc11a2eb 100644 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/LoggerContextTest.java +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/LoggerContextTest.java @@ -19,13 +19,23 @@ import static org.assertj.core.api.Assertions.assertThat; import static org.mockito.Mockito.mock; +import java.util.Collection; +import java.util.concurrent.ExecutorService; +import java.util.concurrent.Executors; +import java.util.concurrent.Future; +import java.util.stream.Collectors; +import java.util.stream.IntStream; import org.apache.logging.log4j.message.MessageFactory; import org.apache.logging.log4j.message.MessageFactory2; +import org.junit.jupiter.api.Assertions; import org.junit.jupiter.api.Test; import org.junit.jupiter.api.TestInfo; class LoggerContextTest { + private static final int LOGGER_COUNT = 1024; + private static final int CONCURRENCY_LEVEL = 16; + @Test void newInstance_should_honor_name_and_message_factory(final TestInfo testInfo) { final String testName = testInfo.getDisplayName(); @@ -37,4 +47,32 @@ void newInstance_should_honor_name_and_message_factory(final TestInfo testInfo) assertThat((MessageFactory) logger.getMessageFactory()).isSameAs(messageFactory); } } + + @Test + void getLoggers_can_be_updated_concurrently(final TestInfo testInfo) { + final String testName = testInfo.getDisplayName(); + final ExecutorService executorService = Executors.newFixedThreadPool(CONCURRENCY_LEVEL); + try (LoggerContext loggerContext = new LoggerContext(testName)) { + // Create a logger + Collection> tasks = IntStream.range(0, CONCURRENCY_LEVEL) + .mapToObj(i -> executorService.submit(() -> { + // Iterates over loggers + loggerContext.updateLoggers(); + // Create some loggers + for (int j = 0; j < LOGGER_COUNT; j++) { + loggerContext.getLogger(testName + "-" + i + "-" + j); + } + // Iterate over loggers again + loggerContext.updateLoggers(); + })) + .collect(Collectors.toList()); + Assertions.assertDoesNotThrow(() -> { + for (Future task : tasks) { + task.get(); + } + }); + } finally { + executorService.shutdown(); + } + } } diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/LoggerContext.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/LoggerContext.java index d084fd24843..e0b88a75d6e 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/LoggerContext.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/LoggerContext.java @@ -33,7 +33,6 @@ import java.util.concurrent.TimeUnit; import java.util.concurrent.locks.Lock; import java.util.concurrent.locks.ReentrantLock; -import java.util.stream.Collectors; import org.apache.logging.log4j.LogManager; import org.apache.logging.log4j.core.config.Configuration; import org.apache.logging.log4j.core.config.ConfigurationFactory; @@ -513,7 +512,7 @@ public Logger getLogger(final String name) { * @return a collection of the current loggers. */ public Collection getLoggers() { - return loggerRegistry.getLoggers().collect(Collectors.toList()); + return loggerRegistry.getLoggers(); } /** diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/InternalLoggerRegistry.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/InternalLoggerRegistry.java index 5aec88f599d..59df6749612 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/InternalLoggerRegistry.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/InternalLoggerRegistry.java @@ -19,6 +19,7 @@ import static java.util.Objects.requireNonNull; import java.lang.ref.WeakReference; +import java.util.Collection; import java.util.HashMap; import java.util.Map; import java.util.Optional; @@ -27,6 +28,7 @@ import java.util.concurrent.locks.ReadWriteLock; import java.util.concurrent.locks.ReentrantReadWriteLock; import java.util.function.BiFunction; +import java.util.stream.Collectors; import java.util.stream.Stream; import org.apache.logging.log4j.core.Logger; import org.apache.logging.log4j.message.MessageFactory; @@ -78,15 +80,19 @@ public InternalLoggerRegistry() {} } } - public Stream getLoggers() { + public Collection getLoggers() { readLock.lock(); try { + // Return a new collection to allow concurrent iteration over the loggers + // + // https://github.com/apache/logging-log4j2/issues/3234 return loggerRefByNameByMessageFactory.values().stream() .flatMap(loggerRefByName -> loggerRefByName.values().stream()) .flatMap(loggerRef -> { @Nullable Logger logger = loggerRef.get(); return logger != null ? Stream.of(logger) : Stream.empty(); - }); + }) + .collect(Collectors.toList()); } finally { readLock.unlock(); } diff --git a/src/changelog/.2.x.x/3234_concurrent-logger-modification.xml b/src/changelog/.2.x.x/3234_concurrent-logger-modification.xml new file mode 100644 index 00000000000..7e3f86bb66e --- /dev/null +++ b/src/changelog/.2.x.x/3234_concurrent-logger-modification.xml @@ -0,0 +1,10 @@ + + + + + Fix `ConcurrentModificationException`, if multiple threads iterate over the loggers at the same time. + +