You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@logging.apache.org by pk...@apache.org on 2025/01/28 07:38:45 UTC
(logging-log4j2) branch fix/3399_create_logger_no_lock created (now 3a4a37dcf6)
This is an automated email from the ASF dual-hosted git repository.
pkarwasz pushed a change to branch fix/3399_create_logger_no_lock
in repository https://gitbox.apache.org/repos/asf/logging-log4j2.git
at 3a4a37dcf6 Minimize lock usage in `InternalLoggerRegistry`
This branch includes the following new commits:
new 3a4a37dcf6 Minimize lock usage in `InternalLoggerRegistry`
The 1 revisions listed above as "new" are entirely new to this
repository and will be described in separate emails. The revisions
listed as "add" were already present in the repository and have only
been added to this reference.
(logging-log4j2) 01/01: Minimize lock usage in `InternalLoggerRegistry`
Posted by pk...@apache.org.
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 <pi...@karwasz.org>
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>