Skip to content

Commit

Permalink
Removes weak references from LoggerRepository (#3199)
Browse files Browse the repository at this point in the history
Removes weak references to `Logger`s in `LoggerRepository`.
The usage of weak references in `LoggerRepository` might cause `null` to be returned by `LogManager.getLogger()` of all Log4j Core versions up to `2.24.1`.
Versions of Log4j API up to `2.24.0` did hold **hard** references to all the registered loggers, so the change will not alter the previous behavior.

This PR also inverts the order of the `String` and `MessageFactory` keys to the `LoggerRepository` multi-map to limit the number of internal maps. The external map is a `WeakHashMap` to allow logger-specific message factories to be GC-ed.

Closes #3143.
  • Loading branch information
ppkarwasz authored Nov 15, 2024
1 parent 3646eb6 commit 20035c4
Show file tree
Hide file tree
Showing 10 changed files with 317 additions and 110 deletions.
Original file line number Diff line number Diff line change
@@ -0,0 +1,64 @@
/*
* Licensed to the Apache Software Foundation (ASF) under one or more
* contributor license agreements. See the NOTICE file distributed with
* this work for additional information regarding copyright ownership.
* The ASF licenses this file to you under the Apache License, Version 2.0
* (the "License"); you may not use this file except in compliance with
* the License. You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
package org.apache.logging.log4j.spi;

import static org.assertj.core.api.Assertions.assertThat;

import java.lang.ref.WeakReference;
import java.util.stream.Stream;
import org.apache.logging.log4j.message.MessageFactory;
import org.apache.logging.log4j.message.ParameterizedMessageFactory;
import org.apache.logging.log4j.message.ReusableMessageFactory;
import org.apache.logging.log4j.test.TestLogger;
import org.jspecify.annotations.Nullable;
import org.junit.jupiter.params.ParameterizedTest;
import org.junit.jupiter.params.provider.MethodSource;

class LoggerRegistryTest {

private static final String LOGGER_NAME = LoggerRegistryTest.class.getName();

static Stream<@Nullable MessageFactory> doesNotLoseLoggerReferences() {
return Stream.of(
ParameterizedMessageFactory.INSTANCE,
ReusableMessageFactory.INSTANCE,
new ParameterizedMessageFactory(),
null);
}

/**
* @see <a href="https://github.com/apache/logging-log4j2/issues/3143>Issue #3143</a>
*/
@ParameterizedTest
@MethodSource
void doesNotLoseLoggerReferences(@Nullable MessageFactory messageFactory) {
LoggerRegistry<TestLogger> loggerRegistry = new LoggerRegistry<>();
TestLogger logger = new TestLogger(LOGGER_NAME, messageFactory);
WeakReference<TestLogger> loggerRef = new WeakReference<>(logger);
// Register logger
loggerRegistry.putIfAbsent(LOGGER_NAME, messageFactory, logger);
// The JIT compiler/optimizer might figure out by himself the `logger` and `messageFactory` are no longer used:
// https://shipilev.net/jvm/anatomy-quarks/8-local-var-reachability/
// We help him with the task though.
logger = null;
// Trigger a GC run
System.gc();
// Check if the logger is still there
assertThat(loggerRef.get()).isNotNull();
assertThat(loggerRegistry.getLogger(LOGGER_NAME, messageFactory)).isInstanceOf(TestLogger.class);
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -102,7 +102,13 @@ public ExtendedLogger getLogger(final String name) {
public ExtendedLogger getLogger(final String name, @Nullable final MessageFactory messageFactory) {
final MessageFactory effectiveMessageFactory =
messageFactory != null ? messageFactory : DEFAULT_MESSAGE_FACTORY;
return loggerRegistry.computeIfAbsent(name, effectiveMessageFactory, this::createLogger);
final ExtendedLogger oldLogger = loggerRegistry.getLogger(name, effectiveMessageFactory);
if (oldLogger != null) {
return oldLogger;
}
final ExtendedLogger newLogger = createLogger(name, effectiveMessageFactory);
loggerRegistry.putIfAbsent(name, effectiveMessageFactory, newLogger);
return loggerRegistry.getLogger(name, effectiveMessageFactory);
}

private ExtendedLogger createLogger(final String name, @Nullable final MessageFactory messageFactory) {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -18,22 +18,18 @@

import static java.util.Objects.requireNonNull;

import java.lang.ref.WeakReference;
import java.util.ArrayList;
import java.util.Collection;
import java.util.Collections;
import java.util.HashMap;
import java.util.Map;
import java.util.Objects;
import java.util.WeakHashMap;
import java.util.concurrent.ConcurrentHashMap;
import java.util.concurrent.locks.Lock;
import java.util.concurrent.locks.ReadWriteLock;
import java.util.concurrent.locks.ReentrantReadWriteLock;
import java.util.function.BiFunction;
import org.apache.logging.log4j.message.MessageFactory;
import org.apache.logging.log4j.message.ParameterizedMessageFactory;
import org.apache.logging.log4j.status.StatusLogger;
import org.jspecify.annotations.NullMarked;
import org.jspecify.annotations.Nullable;

Expand All @@ -43,7 +39,7 @@
@NullMarked
public class LoggerRegistry<T extends ExtendedLogger> {

private final Map<String, Map<MessageFactory, WeakReference<T>>> loggerRefByMessageFactoryByName = new HashMap<>();
private final Map<String, Map<MessageFactory, T>> loggerByMessageFactoryByName = new HashMap<>();

private final ReadWriteLock lock = new ReentrantReadWriteLock();

Expand Down Expand Up @@ -143,7 +139,7 @@ public LoggerRegistry(@Nullable final MapFactory<T> mapFactory) {
* Use {@link #getLogger(String, MessageFactory)} instead.
*/
@Deprecated
public T getLogger(final String name) {
public @Nullable T getLogger(final String name) {
requireNonNull(name, "name");
return getLogger(name, null);
}
Expand All @@ -160,39 +156,29 @@ public T getLogger(final String name) {
* @param messageFactory a message factory
* @return the logger associated with the given name and message factory
*/
public T getLogger(final String name, @Nullable final MessageFactory messageFactory) {
public @Nullable T getLogger(final String name, @Nullable final MessageFactory messageFactory) {
requireNonNull(name, "name");
readLock.lock();
try {
final Map<MessageFactory, WeakReference<T>> loggerRefByMessageFactory =
loggerRefByMessageFactoryByName.get(name);
if (loggerRefByMessageFactory == null) {
return null;
}
final @Nullable Map<MessageFactory, T> loggerByMessageFactory = loggerByMessageFactoryByName.get(name);
final MessageFactory effectiveMessageFactory =
messageFactory != null ? messageFactory : ParameterizedMessageFactory.INSTANCE;
final WeakReference<T> loggerRef = loggerRefByMessageFactory.get(effectiveMessageFactory);
if (loggerRef == null) {
return null;
}
return loggerRef.get();
return loggerByMessageFactory == null ? null : loggerByMessageFactory.get(effectiveMessageFactory);
} finally {
readLock.unlock();
}
}

public Collection<T> getLoggers() {
return getLoggers(new ArrayList<T>());
return getLoggers(new ArrayList<>());
}

public Collection<T> getLoggers(final Collection<T> destination) {
requireNonNull(destination, "destination");
readLock.lock();
try {
loggerRefByMessageFactoryByName.values().stream()
.flatMap(loggerRefByMessageFactory ->
loggerRefByMessageFactory.values().stream().map(WeakReference::get))
.filter(Objects::nonNull)
loggerByMessageFactoryByName.values().stream()
.flatMap(loggerByMessageFactory -> loggerByMessageFactory.values().stream())
.forEach(destination::add);
} finally {
readLock.unlock();
Expand All @@ -215,7 +201,7 @@ public Collection<T> getLoggers(final Collection<T> destination) {
@Deprecated
public boolean hasLogger(final String name) {
requireNonNull(name, "name");
final T logger = getLogger(name);
final @Nullable T logger = getLogger(name);
return logger != null;
}

Expand All @@ -234,7 +220,7 @@ public boolean hasLogger(final String name) {
*/
public boolean hasLogger(final String name, @Nullable final MessageFactory messageFactory) {
requireNonNull(name, "name");
final T logger = getLogger(name, messageFactory);
final @Nullable T logger = getLogger(name, messageFactory);
return logger != null;
}

Expand All @@ -251,7 +237,7 @@ public boolean hasLogger(final String name, final Class<? extends MessageFactory
requireNonNull(messageFactoryClass, "messageFactoryClass");
readLock.lock();
try {
return loggerRefByMessageFactoryByName.getOrDefault(name, Collections.emptyMap()).keySet().stream()
return loggerByMessageFactoryByName.getOrDefault(name, Collections.emptyMap()).keySet().stream()
.anyMatch(messageFactory -> messageFactoryClass.equals(messageFactory.getClass()));
} finally {
readLock.unlock();
Expand All @@ -262,91 +248,30 @@ public boolean hasLogger(final String name, final Class<? extends MessageFactory
* Registers the provided logger.
* <b>Logger name and message factory parameters are ignored</b>, those will be obtained from the logger instead.
*
* @param name ignored – kept for backward compatibility
* @param messageFactory ignored – kept for backward compatibility
* @param name a logger name
* @param messageFactory a message factory
* @param logger a logger instance
* @deprecated As of version {@code 2.25.0}, planned to be removed!
* Use {@link #computeIfAbsent(String, MessageFactory, BiFunction)} instead.
*/
@Deprecated
public void putIfAbsent(
@Nullable final String name, @Nullable final MessageFactory messageFactory, final T logger) {
public void putIfAbsent(final String name, @Nullable final MessageFactory messageFactory, final T logger) {

// Check arguments
requireNonNull(name, "name");
requireNonNull(logger, "logger");

// Insert the logger
writeLock.lock();
try {
final String loggerName = logger.getName();
final Map<MessageFactory, WeakReference<T>> loggerRefByMessageFactory =
loggerRefByMessageFactoryByName.computeIfAbsent(
loggerName, this::createLoggerRefByMessageFactoryMap);
final MessageFactory loggerMessageFactory = logger.getMessageFactory();
final WeakReference<T> loggerRef = loggerRefByMessageFactory.get(loggerMessageFactory);
if (loggerRef == null || loggerRef.get() == null) {
loggerRefByMessageFactory.put(loggerMessageFactory, new WeakReference<>(logger));
}
} finally {
writeLock.unlock();
}
}

public T computeIfAbsent(
final String name,
final MessageFactory messageFactory,
final BiFunction<String, MessageFactory, T> loggerSupplier) {

// Check arguments
requireNonNull(name, "name");
requireNonNull(messageFactory, "messageFactory");
requireNonNull(loggerSupplier, "loggerSupplier");

// Read lock fast path: See if logger already exists
T logger = getLogger(name, messageFactory);
if (logger != null) {
return logger;
}

// Write lock slow path: Insert the logger
writeLock.lock();
try {

// See if the logger is created by another thread in the meantime
final Map<MessageFactory, WeakReference<T>> loggerRefByMessageFactory =
loggerRefByMessageFactoryByName.computeIfAbsent(name, this::createLoggerRefByMessageFactoryMap);
final WeakReference<T> loggerRef;
if ((loggerRef = loggerRefByMessageFactory.get(messageFactory)) != null
&& (logger = loggerRef.get()) != null) {
return logger;
}

// Create the logger
logger = loggerSupplier.apply(name, messageFactory);

// Report message factory mismatches, if there is any
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 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.",
name,
loggerMessageFactory,
messageFactory);
}

// Insert the logger
loggerRefByMessageFactory.put(loggerMessageFactory, new WeakReference<>(logger));
return logger;
final MessageFactory effectiveMessageFactory =
messageFactory != null ? messageFactory : ParameterizedMessageFactory.INSTANCE;
loggerByMessageFactoryByName
.computeIfAbsent(name, this::createLoggerRefByMessageFactoryMap)
.putIfAbsent(effectiveMessageFactory, logger);
} finally {
writeLock.unlock();
}
}

private Map<MessageFactory, WeakReference<T>> createLoggerRefByMessageFactoryMap(final String ignored) {
private Map<MessageFactory, T> createLoggerRefByMessageFactoryMap(final String ignored) {
return new WeakHashMap<>();
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -19,7 +19,7 @@
* API classes.
*/
@Export
@Version("2.25.0")
@Version("2.24.2")
package org.apache.logging.log4j.spi;

import org.osgi.annotation.bundle.Export;
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -33,6 +33,7 @@
import java.util.concurrent.TimeUnit;
import java.util.concurrent.locks.Lock;
import java.util.concurrent.locks.ReentrantLock;
import java.util.stream.Collectors;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.core.config.Configuration;
import org.apache.logging.log4j.core.config.ConfigurationFactory;
Expand All @@ -47,11 +48,11 @@
import org.apache.logging.log4j.core.util.ExecutorServices;
import org.apache.logging.log4j.core.util.NetUtils;
import org.apache.logging.log4j.core.util.ShutdownCallbackRegistry;
import org.apache.logging.log4j.core.util.internal.InternalLoggerRegistry;
import org.apache.logging.log4j.message.MessageFactory;
import org.apache.logging.log4j.spi.LoggerContextFactory;
import org.apache.logging.log4j.spi.LoggerContextShutdownAware;
import org.apache.logging.log4j.spi.LoggerContextShutdownEnabled;
import org.apache.logging.log4j.spi.LoggerRegistry;
import org.apache.logging.log4j.spi.Terminable;
import org.apache.logging.log4j.spi.ThreadContextMapFactory;
import org.apache.logging.log4j.util.PropertiesUtil;
Expand Down Expand Up @@ -83,7 +84,7 @@ public class LoggerContext extends AbstractLifeCycle
*/
private static final MessageFactory DEFAULT_MESSAGE_FACTORY = Logger.getEffectiveMessageFactory(null);

private final LoggerRegistry<Logger> loggerRegistry = new LoggerRegistry<>();
private final InternalLoggerRegistry loggerRegistry = new InternalLoggerRegistry();
private final CopyOnWriteArrayList<PropertyChangeListener> propertyChangeListeners = new CopyOnWriteArrayList<>();
private volatile List<LoggerContextShutdownAware> listeners;

Expand Down Expand Up @@ -513,7 +514,7 @@ public Logger getLogger(final String name) {
* @return a collection of the current loggers.
*/
public Collection<Logger> getLoggers() {
return loggerRegistry.getLoggers();
return loggerRegistry.getLoggers().collect(Collectors.toList());
}

/**
Expand All @@ -535,9 +536,14 @@ public Logger getLogger(final String name, @Nullable final MessageFactory messag
*
* @return the LoggerRegistry.
* @since 2.17.2
* @deprecated since 2.25.0 without a replacement.
*/
public LoggerRegistry<Logger> getLoggerRegistry() {
return loggerRegistry;
@Deprecated
public org.apache.logging.log4j.spi.LoggerRegistry<Logger> getLoggerRegistry() {
org.apache.logging.log4j.spi.LoggerRegistry<Logger> result =
new org.apache.logging.log4j.spi.LoggerRegistry<>();
loggerRegistry.getLoggers().forEach(l -> result.putIfAbsent(l.getName(), l.getMessageFactory(), l));
return result;
}

/**
Expand Down Expand Up @@ -770,9 +776,7 @@ public void updateLoggers() {
*/
public void updateLoggers(final Configuration config) {
final Configuration old = this.configuration;
for (final Logger logger : loggerRegistry.getLoggers()) {
logger.updateConfiguration(config);
}
loggerRegistry.getLoggers().forEach(logger -> logger.updateConfiguration(config));
firePropertyChangeEvent(new PropertyChangeEvent(this, PROPERTY_CONFIG, old, config));
}

Expand Down
Loading

0 comments on commit 20035c4

Please sign in to comment.