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

Author: ppkarwasz

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

@@ -147,44 +147,44 @@ public Logger computeIfAbsent(
             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();
         }

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>