Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Minimize lock usage in InternalLoggerRegistry #3418

Open
wants to merge 4 commits into
base: 2.24.x
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -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
Expand Down Expand Up @@ -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();
}
Expand Down Expand Up @@ -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);
vy marked this conversation as resolved.
Show resolved Hide resolved

// 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()
vy marked this conversation as resolved.
Show resolved Hide resolved
.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`)
vy marked this conversation as resolved.
Show resolved Hide resolved
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();
Expand Down
10 changes: 10 additions & 0 deletions src/changelog/.2.x.x/3399_logger_registry.xml
Original file line number Diff line number Diff line change
@@ -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>
Loading