Minimize lock usage in InternalLoggerRegistry (apache#3418)

Co-authored-by: Volkan Yazıcı <[email protected]>

Author: ppkarwasz

log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/InternalLoggerRegistry.java

@@ -22,7 +22,6 @@
 import java.util.Collection;
 import java.util.HashMap;
 import java.util.Map;
-import java.util.Optional;
 import java.util.WeakHashMap;
 import java.util.concurrent.locks.Lock;
 import java.util.concurrent.locks.ReadWriteLock;
@@ -31,17 +30,20 @@
 import java.util.stream.Collectors;
 import java.util.stream.Stream;
 import org.apache.logging.log4j.core.Logger;
+import org.apache.logging.log4j.core.LoggerContext;
 import org.apache.logging.log4j.message.MessageFactory;
 import org.apache.logging.log4j.status.StatusLogger;
 import org.jspecify.annotations.NullMarked;
 import org.jspecify.annotations.Nullable;
 
 /**
- * Convenience class used by {@link org.apache.logging.log4j.core.LoggerContext}
+ * A registry of {@link Logger}s namespaced by name and message factory.
+ * This class is internally used by {@link LoggerContext}.
  * <p>
- *   We don't use {@link org.apache.logging.log4j.spi.LoggerRegistry} from the Log4j API to keep Log4j Core independent
- *   from the version of the Log4j API at runtime.
+ * We don't use {@linkplain org.apache.logging.log4j.spi.LoggerRegistry the registry from Log4j API} to keep Log4j Core independent from the version of Log4j API at runtime.
+ * This also allows Log4j Core to evolve independently from Log4j API.
  * </p>
+ *
  * @since 2.25.0
  */
 @NullMarked
@@ -70,11 +72,15 @@ public InternalLoggerRegistry() {}
         requireNonNull(messageFactory, "messageFactory");
         readLock.lock();
         try {
-            return Optional.of(loggerRefByNameByMessageFactory)
-                    .map(loggerRefByNameByMessageFactory -> loggerRefByNameByMessageFactory.get(messageFactory))
-                    .map(loggerRefByName -> loggerRefByName.get(name))
-                    .map(WeakReference::get)
-                    .orElse(null);
+            final Map<String, WeakReference<Logger>> loggerRefByName =
+                    loggerRefByNameByMessageFactory.get(messageFactory);
+            if (loggerRefByName != null) {
+                final WeakReference<Logger> loggerRef = loggerRefByName.get(name);
+                if (loggerRef != null) {
+                    return loggerRef.get();
+                }
+            }
+            return null;
         } finally {
             readLock.unlock();
         }
@@ -147,43 +153,51 @@ public Logger computeIfAbsent(
             return logger;
         }
 
+        // Intentionally moving the logger creation outside the write lock, because:
+        //
+        // - Logger instantiation is expensive (causes contention on the write-lock)
+        //
+        // - User code might have circular code paths, though through different threads.
+        //   Consider `T1[ILR:computeIfAbsent] -> ... -> T1[Logger::new] -> ... -> T2[ILR::computeIfAbsent]`.
+        //   Hence, having logger instantiation while holding a write lock might cause 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;
+            Map<String, WeakReference<Logger>> loggerRefByName = loggerRefByNameByMessageFactory.get(messageFactory);
+            // noinspection Java8MapApi (avoid the allocation of lambda passed to `Map::computeIfAbsent`)
+            if (loggerRefByName == null) {
+                loggerRefByNameByMessageFactory.put(messageFactory, loggerRefByName = new HashMap<>());
             }
-
-            // 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));
+            final WeakReference<Logger> loggerRef = loggerRefByName.get(name);
+            if (loggerRef == null || (logger = loggerRef.get()) == null) {
+                loggerRefByName.put(name, new WeakReference<>(logger = newLogger));
             }
-
-            // Insert the logger
-            loggerRefByName.put(name, new WeakReference<>(logger));
             return logger;
         } finally {
             writeLock.unlock();

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>