This is an automated email from the ASF dual-hosted git repository. pkarwasz pushed a commit to branch fix/3399_create_logger_no_lock in repository https://gitbox.apache.org/repos/asf/logging-log4j2.git
commit 3a4a37dcf6a163ce977771f314af4140f91b5ca0 Author: Piotr P. Karwasz <[email protected]> AuthorDate: Tue Jan 28 08:38:23 2025 +0100 Minimize lock usage in `InternalLoggerRegistry` It has been reported that holding a lock on `InternalLoggerRegistry` during the creation of a logger can cause performance loss and deadlocks. The logger constructor can trigger property lookups and other pluggable operations, we don't entirely control. The fix to #3252 only covered one of these cases. This change moves the instantiation of new `Logger`s outside the write lock. While in some cases, this will cause multiple instantiations of loggers with the same parameters, all such loggers are functionally equivalent. On the other hand, the change allows the creation of different loggers in parallel. Closes #3399 --- .../core/util/internal/InternalLoggerRegistry.java | 68 +++++++++++----------- src/changelog/.2.x.x/3399_logger_registry.xml | 10 ++++ 2 files changed, 44 insertions(+), 34 deletions(-) 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 59df674961..12927a37d3 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 @@ -147,44 +147,44 @@ public final class InternalLoggerRegistry { return logger; } + // Creating a logger is expensive and might cause lookups and locks, possibly deadlocks: + // https://github.com/apache/logging-log4j2/issues/3252 + // https://github.com/apache/logging-log4j2/issues/3399 + // + // Creating loggers without a lock, allows multiple threads to create loggers in parallel, which also + // improves performance. + // Since all loggers with the same parameters are equivalent, we can safely return the logger from the + // thread that finishes first. + Logger newLogger = loggerSupplier.apply(name, messageFactory); + + // Report name and message factory mismatch if there are any + final String loggerName = newLogger.getName(); + final MessageFactory loggerMessageFactory = newLogger.getMessageFactory(); + if (!loggerName.equals(name) || !loggerMessageFactory.equals(messageFactory)) { + StatusLogger.getLogger() + .error( + "Newly registered logger with name `{}` and message factory `{}`, is requested to be associated with a different name `{}` or message factory `{}`.\n" + + "Effectively the message factory of the logger will be used and the other one will be ignored.\n" + + "This generally hints a problem at the logger context implementation.\n" + + "Please report this using the Log4j project issue tracker.", + loggerName, + loggerMessageFactory, + name, + messageFactory); + } + // Write lock slow path: Insert the logger writeLock.lock(); try { - // See if the logger is created by another thread in the meantime - final Map<String, WeakReference<Logger>> loggerRefByName = - loggerRefByNameByMessageFactory.computeIfAbsent(messageFactory, ignored -> new HashMap<>()); - WeakReference<Logger> loggerRef = loggerRefByName.get(name); - if (loggerRef != null && (logger = loggerRef.get()) != null) { - return logger; - } - - // Create the logger - logger = loggerSupplier.apply(name, messageFactory); - - // Report name and message factory mismatch if there are any - final String loggerName = logger.getName(); - final MessageFactory loggerMessageFactory = logger.getMessageFactory(); - if (!loggerMessageFactory.equals(messageFactory)) { - StatusLogger.getLogger() - .error( - "Newly registered logger with name `{}` and message factory `{}`, is requested to be associated with a different name `{}` or message factory `{}`.\n" - + "Effectively the message factory of the logger will be used and the other one will be ignored.\n" - + "This generally hints a problem at the logger context implementation.\n" - + "Please report this using the Log4j project issue tracker.", - loggerName, - loggerMessageFactory, - name, - messageFactory); - // Register logger under alternative keys - loggerRefByNameByMessageFactory - .computeIfAbsent(loggerMessageFactory, ignored -> new HashMap<>()) - .putIfAbsent(loggerName, new WeakReference<>(logger)); - } - - // Insert the logger - loggerRefByName.put(name, new WeakReference<>(logger)); - return logger; + Logger currentLogger = loggerRefByNameByMessageFactory + .computeIfAbsent(messageFactory, ignored -> new HashMap<>()) + .computeIfAbsent(name, ignored -> new WeakReference<>(newLogger)) + .get(); + // Null check, in the rare case a GC occurs between: + // * new WeakReference (last reference to `newLogger`) + // * WeakReference.get() + return currentLogger == null ? newLogger : currentLogger; } finally { writeLock.unlock(); } diff --git a/src/changelog/.2.x.x/3399_logger_registry.xml b/src/changelog/.2.x.x/3399_logger_registry.xml new file mode 100644 index 0000000000..0eb56f1a64 --- /dev/null +++ b/src/changelog/.2.x.x/3399_logger_registry.xml @@ -0,0 +1,10 @@ +<?xml version="1.0" encoding="UTF-8"?> +<entry xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"; + xmlns="https://logging.apache.org/xml/ns"; + xsi:schemaLocation="https://logging.apache.org/xml/ns https://logging.apache.org/xml/ns/log4j-changelog-0.xsd"; + type="fixed"> + <issue id="3399" link="https://github.com/apache/logging-log4j2/issues/3399"/> + <description format="asciidoc"> + Minimize lock usage in `InternalLoggerRegistry`. + </description> +</entry>
