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

Hardens PropertiesUtil against recursive property sources #3263

Open
wants to merge 1 commit 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 @@ -193,7 +193,7 @@ void testPublish() {
@Test
@ResourceLock(value = Resources.SYSTEM_PROPERTIES, mode = ResourceAccessMode.READ)
@Issue("https://github.com/spring-projects/spring-boot/issues/33450")
void testBadPropertySource() {
void testErrorPropertySource() {
final String key = "testKey";
final Properties props = new Properties();
props.put(key, "test");
Expand All @@ -208,6 +208,28 @@ void testBadPropertySource() {
}
}

@Test
@ResourceLock(value = Resources.SYSTEM_PROPERTIES, mode = ResourceAccessMode.READ)
@Issue("https://github.com/apache/logging-log4j2/issues/3252")
void testRecursivePropertySource() {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Shall we also verify the status logger warning?

final String key = "testKey";
final Properties props = new Properties();
props.put(key, "test");
final PropertiesUtil util = new PropertiesUtil(props);
final PropertySource source = new RecursivePropertySource(util);
util.addPropertySource(source);
try {
// We ignore the recursive source
assertThat(util.getStringProperty(key)).isEqualTo("test");
assertThat(util.hasProperty(key)).isTrue();
// We check that the source is recursive
assertThat(source.getProperty(key)).isEqualTo("test");
assertThat(source.containsProperty(key)).isTrue();
} finally {
util.removePropertySource(source);
}
}

private static final String[][] data = {
{null, "org.apache.logging.log4j.level"},
{null, "Log4jAnotherProperty"},
Expand Down Expand Up @@ -289,4 +311,28 @@ public boolean containsProperty(final String key) {
throw new IllegalStateException("Test");
}
}

private static class RecursivePropertySource implements PropertySource {

private final PropertiesUtil propertiesUtil;

private RecursivePropertySource(PropertiesUtil propertiesUtil) {
this.propertiesUtil = propertiesUtil;
}

@Override
public int getPriority() {
return Integer.MIN_VALUE;
}

@Override
public String getProperty(String key) {
return propertiesUtil.getStringProperty(key);
}

@Override
public boolean containsProperty(String key) {
return propertiesUtil.hasProperty(key);
}
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -496,6 +496,7 @@ public void reload() {}
private static final class Environment {

private final Set<PropertySource> sources = ConcurrentHashMap.newKeySet();
private final ThreadLocal<PropertySource> CURRENT_PROPERTY_SOURCE = new ThreadLocal<>();

private Environment(final PropertySource propertySource) {
final PropertySource sysProps = new PropertyFilePropertySource(LOG4J_SYSTEM_PROPERTIES_FILE_NAME, false);
Expand Down Expand Up @@ -547,21 +548,35 @@ private String get(final String key) {
}

private boolean sourceContainsProperty(final PropertySource source, final String key) {
try {
return source.containsProperty(key);
} catch (final Exception e) {
LOGGER.warn("Failed to retrieve Log4j property {} from property source {}.", key, source, e);
return false;
PropertySource recursiveSource = CURRENT_PROPERTY_SOURCE.get();
if (recursiveSource == null) {
CURRENT_PROPERTY_SOURCE.set(source);
try {
return source.containsProperty(key);
} catch (final Exception e) {
LOGGER.warn("Failed to retrieve Log4j property {} from property source {}.", key, source, e);
} finally {
CURRENT_PROPERTY_SOURCE.remove();
}
}
LOGGER.warn("Recursive call to `containsProperty()` from property source {}.", recursiveSource);
return false;
}

private String sourceGetProperty(final PropertySource source, final String key) {
try {
return source.getProperty(key);
} catch (final Exception e) {
LOGGER.warn("Failed to retrieve Log4j property {} from property source {}.", key, source, e);
return null;
PropertySource recursiveSource = CURRENT_PROPERTY_SOURCE.get();
if (recursiveSource == null) {
CURRENT_PROPERTY_SOURCE.set(source);
try {
return source.getProperty(key);
} catch (final Exception e) {
LOGGER.warn("Failed to retrieve Log4j property {} from property source {}.", key, source, e);
} finally {
CURRENT_PROPERTY_SOURCE.remove();
}
}
LOGGER.warn("Recursive call to `getProperty()` from property source {}.", recursiveSource);
return null;
}

private boolean containsKey(final String key) {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -24,34 +24,36 @@
import org.apache.logging.log4j.message.MessageFactory;
import org.apache.logging.log4j.message.ParameterizedMessageFactory;
import org.junit.jupiter.api.Test;
import org.junitpioneer.jupiter.ClearSystemProperty;
import org.junitpioneer.jupiter.SetSystemProperty;

@SetSystemProperty(
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

By making this test-scoped, aren't you changing the arguments_should_be_honored() test? That is,

  • Before: there are no property-provided configurations, but only arguments passed to Logger::new
  • New: there are property-provided configurations, and also arguments passed to Logger::new

In the new case, you cannot know which configuration source has kicked in.

key = "log4j2.messageFactory",
value = "org.apache.logging.log4j.core.LoggerMessageFactoryCustomizationTest$TestMessageFactory")
@SetSystemProperty(
key = "log4j2.flowMessageFactory",
value = "org.apache.logging.log4j.core.LoggerMessageFactoryCustomizationTest$TestFlowMessageFactory")
class LoggerMessageFactoryCustomizationTest {

@Test
@ClearSystemProperty(key = "log4j2.messageFactory")
@ClearSystemProperty(key = "log4j2.flowMessageFactory")
void arguments_should_be_honored() {
final LoggerContext loggerContext =
new LoggerContext(LoggerMessageFactoryCustomizationTest.class.getSimpleName());
final Logger logger = new Logger(
loggerContext, "arguments_should_be_honored", new TestMessageFactory(), new TestFlowMessageFactory());
assertTestMessageFactories(logger);
try (LoggerContext loggerContext =
new LoggerContext(LoggerMessageFactoryCustomizationTest.class.getSimpleName())) {
Logger logger = new Logger(
loggerContext,
"arguments_should_be_honored",
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You can use @TestInfo instead of hardcoding the method name. (Same goes for the other test methods too.)

new TestMessageFactory(),
new TestFlowMessageFactory());
assertTestMessageFactories(logger);
}
}

@Test
@SetSystemProperty(
key = "log4j2.messageFactory",
value = "org.apache.logging.log4j.core.LoggerMessageFactoryCustomizationTest$TestMessageFactory")
@SetSystemProperty(
key = "log4j2.flowMessageFactory",
value = "org.apache.logging.log4j.core.LoggerMessageFactoryCustomizationTest$TestFlowMessageFactory")
void properties_should_be_honored() {
final LoggerContext loggerContext =
new LoggerContext(LoggerMessageFactoryCustomizationTest.class.getSimpleName());
final Logger logger = new Logger(loggerContext, "properties_should_be_honored", null, null);
assertTestMessageFactories(logger);
try (LoggerContext loggerContext =
new LoggerContext(LoggerMessageFactoryCustomizationTest.class.getSimpleName())) {
Logger logger = loggerContext.getLogger("properties_should_be_honored");
assertTestMessageFactories(logger);
}
}

private static void assertTestMessageFactories(Logger logger) {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -28,14 +28,15 @@
class LoggerMessageFactoryDefaultsTlaEnabledTest {

@Test
@SetSystemProperty(key = "log4j2.is.webapp", value = "false")
@SetSystemProperty(key = "log4j2.enableThreadLocals", value = "true")
@SetSystemProperty(key = "log4j2.isWebapp", value = "false")
@SetSystemProperty(key = "log4j2.enableThreadlocals", value = "true")
void defaults_should_match_when_thread_locals_enabled() {
assertThat(Constants.ENABLE_THREADLOCALS).isTrue();
final LoggerContext loggerContext =
new LoggerContext(LoggerMessageFactoryDefaultsTlaEnabledTest.class.getSimpleName());
final Logger logger = new Logger(loggerContext, "defaults_should_match_when_thread_locals_enabled", null, null);
assertThat((MessageFactory) logger.getMessageFactory()).isSameAs(ReusableMessageFactory.INSTANCE);
assertThat(logger.getFlowMessageFactory()).isSameAs(DefaultFlowMessageFactory.INSTANCE);
try (LoggerContext loggerContext =
new LoggerContext(LoggerMessageFactoryDefaultsTlaEnabledTest.class.getSimpleName())) {
Logger logger = loggerContext.getLogger("defaults_should_match_when_thread_locals_enabled");
assertThat((MessageFactory) logger.getMessageFactory()).isSameAs(ReusableMessageFactory.INSTANCE);
assertThat(logger.getFlowMessageFactory()).isSameAs(DefaultFlowMessageFactory.INSTANCE);
}
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -33,7 +33,6 @@
import org.apache.logging.log4j.ThreadContext;
import org.apache.logging.log4j.core.ContextDataInjector;
import org.apache.logging.log4j.spi.ThreadContextMap;
import org.apache.logging.log4j.util.PropertiesUtil;
import org.apache.logging.log4j.util.ProviderUtil;
import org.apache.logging.log4j.util.SortedArrayStringMap;
import org.apache.logging.log4j.util.StringMap;
Expand All @@ -59,7 +58,6 @@ public static Collection<String[]> threadContextMapClassNames() {
public String threadContextMapClassName;

private static void resetThreadContextMap() {
PropertiesUtil.getProperties().reload();
final Log4jProvider provider = (Log4jProvider) ProviderUtil.getProvider();
provider.resetThreadContextMap();
ThreadContext.init();
Expand Down
75 changes: 11 additions & 64 deletions log4j-core/src/main/java/org/apache/logging/log4j/core/Logger.java
Original file line number Diff line number Diff line change
Expand Up @@ -33,16 +33,11 @@
import org.apache.logging.log4j.core.config.LoggerConfig;
import org.apache.logging.log4j.core.config.ReliabilityStrategy;
import org.apache.logging.log4j.core.filter.CompositeFilter;
import org.apache.logging.log4j.core.util.Constants;
import org.apache.logging.log4j.message.DefaultFlowMessageFactory;
import org.apache.logging.log4j.message.FlowMessageFactory;
import org.apache.logging.log4j.message.Message;
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.message.SimpleMessage;
import org.apache.logging.log4j.spi.AbstractLogger;
import org.apache.logging.log4j.util.LoaderUtil;
import org.apache.logging.log4j.util.Strings;
import org.apache.logging.log4j.util.Supplier;

Expand All @@ -62,90 +57,42 @@ public class Logger extends AbstractLogger implements Supplier<LoggerConfig> {

private static final long serialVersionUID = 1L;

private static final String MESSAGE_FACTORY_PROPERTY_NAME = "log4j2.messageFactory";

private static final String FLOW_MESSAGE_FACTORY_PROPERTY_NAME = "log4j2.flowMessageFactory";

/**
* Config should be consistent across threads.
*/
protected volatile PrivateConfig privateConfig;

// FIXME: ditto to the above
private final LoggerContext context;

/**
* Constructs an instance using the given {@link LoggerContext}, logger name, and {@link MessageFactory}.
*
* @param context the {@link LoggerContext} this logger is associated with
* @param context The {@link LoggerContext} this logger is associated with, never {@code null}.
* @param name The logger name, never {@code null}.
* @param messageFactory The message factory to be used.
* If null, first the {@value #MESSAGE_FACTORY_PROPERTY_NAME} property will be used to instantiate the message factory.
* If the property is missing and the {@code log4j2.enableThreadLocals} property is not {@code false}, {@link ReusableMessageFactory} will be used.
* Otherwise, we will fall back to {@link ParameterizedMessageFactory}.
* @param name the logger name
* Passing a {@code null} value is deprecated, but supported for backward compatibility.
*/
protected Logger(final LoggerContext context, final String name, final MessageFactory messageFactory) {
this(context, name, messageFactory, null);
protected Logger(LoggerContext context, String name, MessageFactory messageFactory) {
this(context, name, messageFactory, LoggerContext.DEFAULT_FLOW_MESSAGE_FACTORY);
}

/**
* The canonical constructor.
*
* @param context the {@link LoggerContext} this logger is associated with
* @param context The {@link LoggerContext} this logger is associated with, never {@code null}.
* @param name The logger name, never {@code null}.
* @param messageFactory The message factory to be used.
* If null, first the {@value #MESSAGE_FACTORY_PROPERTY_NAME} property will be used to instantiate the message factory.
* If the property is missing and the {@code log4j2.enableThreadLocals} property is not {@code false}, {@link ReusableMessageFactory} will be used.
* Otherwise, we will fall back to {@link ParameterizedMessageFactory}.
* Passing a {@code null} value is deprecated, but supported for backward compatibility.
* @param flowMessageFactory The flow message factory to be used.
* If null, first the {@value #FLOW_MESSAGE_FACTORY_PROPERTY_NAME} property will be used to instantiate the flow message factory.
* If the property is missing, {@link DefaultFlowMessageFactory} will be used.
* @param name the logger name
* Passing a {@code null} value is deprecated, but supported for backward compatibility.
*/
protected Logger(
final LoggerContext context,
final String name,
final MessageFactory messageFactory,
final FlowMessageFactory flowMessageFactory) {
super(name, getEffectiveMessageFactory(messageFactory), getEffectiveFlowMessageFactory(flowMessageFactory));
LoggerContext context, String name, MessageFactory messageFactory, FlowMessageFactory flowMessageFactory) {
super(name, messageFactory, flowMessageFactory);
this.context = requireNonNull(context, "context");
this.privateConfig = new PrivateConfig(context.getConfiguration(), this);
}

static MessageFactory getEffectiveMessageFactory(final MessageFactory messageFactory) {
return createInstanceFromFactoryProperty(
MessageFactory.class,
messageFactory,
MESSAGE_FACTORY_PROPERTY_NAME,
() -> Constants.ENABLE_THREADLOCALS
? ReusableMessageFactory.INSTANCE
: ParameterizedMessageFactory.INSTANCE);
}

private static FlowMessageFactory getEffectiveFlowMessageFactory(final FlowMessageFactory flowMessageFactory) {
return createInstanceFromFactoryProperty(
FlowMessageFactory.class,
flowMessageFactory,
FLOW_MESSAGE_FACTORY_PROPERTY_NAME,
() -> DefaultFlowMessageFactory.INSTANCE);
}

private static <V> V createInstanceFromFactoryProperty(
final Class<V> instanceType,
final V providedInstance,
final String propertyName,
final java.util.function.Supplier<V> fallbackInstanceSupplier) {
if (providedInstance != null) {
return providedInstance;
}
try {
return LoaderUtil.newCheckedInstanceOfProperty(propertyName, instanceType, fallbackInstanceSupplier);
} catch (final Exception error) {
final String message =
String.format("failed instantiating the class pointed by the `%s` property", propertyName);
throw new RuntimeException(message, error);
}
}

protected Object writeReplace() throws ObjectStreamException {
return new LoggerProxy(getName(), getMessageFactory());
}
Expand Down
Loading