Remove caching from `PropertiesUtil` (+#2849 review)
The `PropertiesUtil` class preemptively caches lookups for all known keys from enumerable property sources.
On my Debian system a JVM has around 60 among environment variables and system properties, which causes `PropertiesUtil` to perform around 60 lookups for **each** of the 3 standard property sources. Most of these properties have nothing to do with Log4j.
On the other hand all Log4j artifacts use no more than 100 configuration properties and the results of most of those calls are cache in static fields.
This PR removes the property value caches used by `PropertiesUtil`.
The change should have no noticeable impact on the loading time of Log4j Core, while at the same time simplifies the system.
diff --git a/log4j-api-test/src/test/java/org/apache/logging/log4j/util/PropertiesUtilOrderTest.java b/log4j-api-test/src/test/java/org/apache/logging/log4j/util/PropertiesUtilOrderTest.java
index 4343d96..662bfcd 100644
--- a/log4j-api-test/src/test/java/org/apache/logging/log4j/util/PropertiesUtilOrderTest.java
+++ b/log4j-api-test/src/test/java/org/apache/logging/log4j/util/PropertiesUtilOrderTest.java
@@ -35,9 +35,9 @@
@ExtendWith(SystemStubsExtension.class)
@ResourceLock(value = Resources.SYSTEM_PROPERTIES)
-public class PropertiesUtilOrderTest {
+class PropertiesUtilOrderTest {
- public static class NonEnumerablePropertySource implements PropertySource {
+ private static class NonEnumerablePropertySource implements PropertySource {
private final Properties props;
@@ -67,14 +67,6 @@
}
}
- public static class NullPropertySource implements PropertySource {
-
- @Override
- public int getPriority() {
- return Integer.MIN_VALUE;
- }
- }
-
private final Properties properties = new Properties();
@BeforeEach
@@ -85,7 +77,7 @@
}
@Test
- public void testNormalizedOverrideLegacy() {
+ void testNormalizedOverrideLegacy() {
final PropertiesUtil util = new PropertiesUtil(properties);
final String legacy = "props.legacy";
final String normalized = "props.normalized";
@@ -104,20 +96,7 @@
}
@Test
- public void testFallsBackToTokenMatching() {
- final PropertiesUtil util = new PropertiesUtil(properties);
- for (int i = 1; i <= 4; i++) {
- final String key = "log4j2.tokenBasedProperty" + i;
- assertTrue(util.hasProperty(key));
- assertEquals("props.token", util.getStringProperty(key));
- }
- // No fall back (a normalized property is present)
- assertTrue(util.hasProperty("log4j2.normalizedProperty"));
- assertEquals("props.normalized", util.getStringProperty("log4j2.normalizedProperty"));
- }
-
- @Test
- public void testOrderOfNormalizedProperties(final EnvironmentVariables env, final SystemProperties sysProps) {
+ void testOrderOfNormalizedProperties(final EnvironmentVariables env, final SystemProperties sysProps) {
properties.remove("log4j2.normalizedProperty");
properties.remove("LOG4J_normalized.property");
final PropertiesUtil util = new PropertiesUtil(properties);
@@ -128,21 +107,18 @@
assertEquals(null, util.getStringProperty("log4j2.normalizedProperty"));
properties.setProperty("log4j2.normalizedProperty", "props.normalized");
- util.reload();
assertTrue(util.hasProperty("Log4jNormalizedProperty"));
assertEquals("props.normalized", util.getStringProperty("Log4jNormalizedProperty"));
assertTrue(util.hasProperty("log4j2.normalizedProperty"));
assertEquals("props.normalized", util.getStringProperty("log4j2.normalizedProperty"));
env.set("LOG4J_NORMALIZED_PROPERTY", "env");
- util.reload();
assertTrue(util.hasProperty("Log4jNormalizedProperty"));
assertEquals("env", util.getStringProperty("Log4jNormalizedProperty"));
assertTrue(util.hasProperty("log4j2.normalizedProperty"));
assertEquals("env", util.getStringProperty("log4j2.normalizedProperty"));
sysProps.set("log4j2.normalizedProperty", "sysProps");
- util.reload();
assertTrue(util.hasProperty("Log4jNormalizedProperty"));
assertEquals("sysProps", util.getStringProperty("Log4jNormalizedProperty"));
assertTrue(util.hasProperty("log4j2.normalizedProperty"));
@@ -150,7 +126,7 @@
}
@Test
- public void testLegacySystemPropertyHasHigherPriorityThanEnv(
+ void testLegacySystemPropertyHasHigherPriorityThanEnv(
final EnvironmentVariables env, final SystemProperties sysProps) {
env.set("LOG4J_CONFIGURATION_FILE", "env");
final PropertiesUtil util = new PropertiesUtil(properties);
@@ -159,18 +135,16 @@
assertEquals("env", util.getStringProperty("log4j.configurationFile"));
sysProps.set("log4j.configurationFile", "legacy");
- util.reload();
assertTrue(util.hasProperty("log4j.configurationFile"));
assertEquals("legacy", util.getStringProperty("log4j.configurationFile"));
sysProps.set("log4j2.configurationFile", "new");
- util.reload();
assertTrue(util.hasProperty("log4j.configurationFile"));
assertEquals("new", util.getStringProperty("log4j.configurationFile"));
}
@Test
- public void testHighPriorityNonEnumerableSource(final SystemProperties sysProps) {
+ void testHighPriorityNonEnumerableSource(final SystemProperties sysProps) {
// In both datasources
assertNotNull(properties.getProperty("log4j2.normalizedProperty"));
assertNotNull(properties.getProperty("log4j.onlyLegacy"));
@@ -201,22 +175,19 @@
}
/**
- * Checks the for missing null checks. The {@link NullPropertySource} returns
+ * Checks the for missing null checks, using a {@link PropertySource}, which returns
* {@code null} in almost every call.
- *
- * @param sysProps
*/
@Test
- public void testNullChecks(final SystemProperties sysProps) {
+ void testNullChecks(final SystemProperties sysProps) {
sysProps.set("log4j2.someProperty", "sysProps");
sysProps.set("Log4jLegacyProperty", "sysProps");
- final PropertiesUtil util = new PropertiesUtil(new NullPropertySource());
- assertTrue(util.hasProperty("log4j2.someProperty"));
- assertEquals("sysProps", util.getStringProperty("log4j2.someProperty"));
+ final PropertiesUtil util = new PropertiesUtil(() -> Integer.MIN_VALUE);
+
+ assertTrue(util.hasProperty("Log4jSomeProperty"));
+ assertEquals("sysProps", util.getStringProperty("log4jSomeProperty"));
assertTrue(util.hasProperty("Log4jLegacyProperty"));
assertEquals("sysProps", util.getStringProperty("Log4jLegacyProperty"));
- assertTrue(util.hasProperty("log4j.legacyProperty"));
- assertEquals("sysProps", util.getStringProperty("log4j.legacyProperty"));
assertFalse(util.hasProperty("log4j2.nonExistentProperty"));
assertNull(util.getStringProperty("log4j2.nonExistentProperty"));
}
diff --git a/log4j-api-test/src/test/java/org/apache/logging/log4j/util/PropertiesUtilTest.java b/log4j-api-test/src/test/java/org/apache/logging/log4j/util/PropertiesUtilTest.java
index 230d8d1..a655959 100644
--- a/log4j-api-test/src/test/java/org/apache/logging/log4j/util/PropertiesUtilTest.java
+++ b/log4j-api-test/src/test/java/org/apache/logging/log4j/util/PropertiesUtilTest.java
@@ -212,15 +212,15 @@
{null, "org.apache.logging.log4j.level"},
{null, "Log4jAnotherProperty"},
{null, "log4j2.catalinaBase"},
- {"ok", "log4j2.configurationFile"},
- {"ok", "log4j2.defaultStatusLevel"},
- {"ok", "log4j2.newLevel"},
- {"ok", "log4j2.asyncLoggerTimeout"},
- {"ok", "log4j2.asyncLoggerConfigRingBufferSize"},
- {"ok", "log4j2.disableThreadContext"},
- {"ok", "log4j2.disableThreadContextStack"},
- {"ok", "log4j2.disableThreadContextMap"},
- {"ok", "log4j2.isThreadContextMapInheritable"}
+ {"ok", "log4j.configurationFile"},
+ {"ok", "Log4jDefaultStatusLevel"},
+ {"ok", "org.apache.logging.log4j.newLevel"},
+ {"ok", "AsyncLogger.Timeout"},
+ {"ok", "AsyncLoggerConfig.RingBufferSize"},
+ {"ok", "disableThreadContext"},
+ {"ok", "disableThreadContextStack"},
+ {"ok", "disableThreadContextMap"},
+ {"ok", "isThreadContextMapInheritable"}
};
/**
@@ -232,7 +232,9 @@
void testResolvesOnlyLog4jProperties() {
final PropertiesUtil util = new PropertiesUtil("Jira3413Test.properties");
for (final String[] pair : data) {
- assertEquals(pair[0], util.getStringProperty(pair[1]));
+ assertThat(util.getStringProperty(pair[1]))
+ .as("Checking property %s", pair[1])
+ .isEqualTo(pair[0]);
}
}
diff --git a/log4j-api-test/src/test/resources/Jira3413Test.properties b/log4j-api-test/src/test/resources/Jira3413Test.properties
index 371cca0..6932845 100644
--- a/log4j-api-test/src/test/resources/Jira3413Test.properties
+++ b/log4j-api-test/src/test/resources/Jira3413Test.properties
@@ -21,14 +21,14 @@
catalina.base=fail
# Some legacy properties with a characteristic prefix
-log4j.configurationFile=ok
-Log4jDefaultStatusLevel=ok
-org.apache.logging.log4j.newLevel=ok
+log4j2.configurationFile=ok
+log4j2.defaultStatusLevel=ok
+log4j2.newLevel=ok
# No characteristic prefix
-AsyncLogger.Timeout=ok
-AsyncLoggerConfig.RingBufferSize=ok
-disableThreadContext=ok
-disableThreadContextStack=ok
-disableThreadContextMap=ok
-isThreadContextMapInheritable=ok
+log4j2.asyncLoggerTimeout=ok
+log4j2.asyncLoggerConfigRingBufferSize=ok
+log4j2.disableThreadContext=ok
+log4j2.disableThreadContextStack=ok
+log4j2.disableThreadContextMap=ok
+log4j2.isThreadContextMapInheritable=ok
diff --git a/log4j-api/src/main/java/org/apache/logging/log4j/util/PropertiesUtil.java b/log4j-api/src/main/java/org/apache/logging/log4j/util/PropertiesUtil.java
index fdcee68..8b4baf4 100644
--- a/log4j-api/src/main/java/org/apache/logging/log4j/util/PropertiesUtil.java
+++ b/log4j-api/src/main/java/org/apache/logging/log4j/util/PropertiesUtil.java
@@ -27,7 +27,7 @@
import java.time.temporal.TemporalUnit;
import java.util.ArrayList;
import java.util.Arrays;
-import java.util.HashSet;
+import java.util.Collection;
import java.util.List;
import java.util.Map;
import java.util.Objects;
@@ -36,16 +36,12 @@
import java.util.ServiceLoader;
import java.util.Set;
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.regex.Matcher;
import java.util.regex.Pattern;
import java.util.stream.Collectors;
import java.util.stream.Stream;
import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.status.StatusLogger;
-import org.apache.logging.log4j.util.PropertySource.Comparator;
/**
* <em>Consider this class private.</em>
@@ -104,7 +100,7 @@
* @param source a property source
*/
PropertiesUtil(final PropertySource source) {
- this.environment = new Environment(source);
+ environment = new Environment(source);
}
/**
@@ -479,10 +475,10 @@
* Reloads all properties. This is primarily useful for unit tests.
*
* @since 2.10.0
+ * @deprecated since 2.24.0 caching of property values is disabled.
*/
- public void reload() {
- environment.reload();
- }
+ @Deprecated
+ public void reload() {}
/**
* Provides support for looking up global configuration properties via environment variables, property files,
@@ -499,17 +495,7 @@
*/
private static final class Environment {
- private final List<PropertySource> sources = new ArrayList<>();
- private final ReadWriteLock sourceLock = new ReentrantReadWriteLock();
- private final Lock sourceReadLock = sourceLock.readLock();
- private final Lock sourceWriteLock = sourceLock.writeLock();
-
- /**
- * Maps a key to its value or the value of its normalization in the lowest priority source that contains it.
- */
- private final Map<String, String> literal = new ConcurrentHashMap<>();
-
- private final Map<List<CharSequence>, String> tokenized = new ConcurrentHashMap<>();
+ private final Set<PropertySource> sources = ConcurrentHashMap.newKeySet();
private Environment(final PropertySource propertySource) {
final PropertySource sysProps = new PropertyFilePropertySource(LOG4J_SYSTEM_PROPERTIES_FILE_NAME, false);
@@ -532,89 +518,32 @@
ServiceLoader.load(PropertySource.class, PropertiesUtil.class.getClassLoader()),
LOGGER)
.forEach(sources::add);
- sources.sort(Comparator.INSTANCE);
-
- reload();
}
private void addPropertySource(final PropertySource propertySource) {
- sourceWriteLock.lock();
- try {
- if (!sources.contains(propertySource)) {
- sources.add(propertySource);
- sources.sort(Comparator.INSTANCE);
- }
- } finally {
- sourceWriteLock.unlock();
- }
+ sources.add(propertySource);
}
private void removePropertySource(final PropertySource propertySource) {
- sourceWriteLock.lock();
- try {
- sources.remove(propertySource);
- } finally {
- sourceWriteLock.unlock();
- }
- }
-
- private void reload() {
- literal.clear();
- tokenized.clear();
- sourceWriteLock.lock();
- try {
- // 1. Collects all property keys from enumerable sources.
- final Set<String> keys = new HashSet<>();
- sources.stream().map(PropertySource::getPropertyNames).forEach(keys::addAll);
- // 2. Fills the property caches. Sources with higher priority values don't override the previous ones.
- keys.stream().filter(Strings::isNotBlank).forEach(key -> {
- final List<CharSequence> tokens = PropertySource.Util.tokenize(key);
- final boolean hasTokens = !tokens.isEmpty();
- sources.forEach(source -> {
- if (sourceContainsProperty(source, key)) {
- final String value = sourceGetProperty(source, key);
- if (hasTokens) {
- tokenized.putIfAbsent(tokens, value);
- }
- }
- if (hasTokens) {
- final String normalKey = Objects.toString(source.getNormalForm(tokens), null);
- if (normalKey != null && sourceContainsProperty(source, normalKey)) {
- literal.putIfAbsent(key, sourceGetProperty(source, normalKey));
- } else if (sourceContainsProperty(source, key)) {
- literal.putIfAbsent(key, sourceGetProperty(source, key));
- }
- }
- });
- });
- } finally {
- sourceWriteLock.unlock();
- }
+ sources.remove(propertySource);
}
private String get(final String key) {
- if (literal.containsKey(key)) {
- return literal.get(key);
- }
final List<CharSequence> tokens = PropertySource.Util.tokenize(key);
- final boolean hasTokens = !tokens.isEmpty();
- sourceReadLock.lock();
- try {
- for (final PropertySource source : sources) {
- if (hasTokens) {
- final String normalKey = Objects.toString(source.getNormalForm(tokens), null);
- if (normalKey != null && sourceContainsProperty(source, normalKey)) {
- return sourceGetProperty(source, normalKey);
+ return sources.stream()
+ .sorted(PropertySource.Comparator.INSTANCE)
+ .map(source -> {
+ if (!tokens.isEmpty()) {
+ final String normalKey = Objects.toString(source.getNormalForm(tokens), null);
+ if (normalKey != null && sourceContainsProperty(source, normalKey)) {
+ return sourceGetProperty(source, normalKey);
+ }
}
- }
- if (sourceContainsProperty(source, key)) {
return sourceGetProperty(source, key);
- }
- }
- } finally {
- sourceReadLock.unlock();
- }
- return tokenized.get(tokens);
+ })
+ .filter(Objects::nonNull)
+ .findFirst()
+ .orElse(null);
}
private boolean sourceContainsProperty(final PropertySource source, final String key) {
@@ -637,18 +566,11 @@
private boolean containsKey(final String key) {
final List<CharSequence> tokens = PropertySource.Util.tokenize(key);
- sourceReadLock.lock();
- try {
- return literal.containsKey(key)
- || tokenized.containsKey(tokens)
- || sources.stream().anyMatch(s -> {
- final CharSequence normalizedKey = s.getNormalForm(tokens);
- return sourceContainsProperty(s, key)
- || (normalizedKey != null && sourceContainsProperty(s, normalizedKey.toString()));
- });
- } finally {
- sourceReadLock.unlock();
- }
+ return sources.stream().anyMatch(s -> {
+ final CharSequence normalizedKey = tokens.isEmpty() ? null : s.getNormalForm(tokens);
+ return sourceContainsProperty(s, key)
+ || (normalizedKey != null && sourceContainsProperty(s, normalizedKey.toString()));
+ });
}
}
@@ -663,13 +585,13 @@
public static Properties extractSubset(final Properties properties, final String prefix) {
final Properties subset = new Properties();
- if (prefix == null || prefix.length() == 0) {
+ if (prefix == null || prefix.isEmpty()) {
return subset;
}
final String prefixToMatch = prefix.charAt(prefix.length() - 1) != '.' ? prefix + '.' : prefix;
- final List<String> keys = new ArrayList<>();
+ final Collection<String> keys = new ArrayList<>();
for (final String key : properties.stringPropertyNames()) {
if (key.startsWith(prefixToMatch)) {
diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/async/AsyncQueueFullPolicyFactoryTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/async/AsyncQueueFullPolicyFactoryTest.java
index 06f6f06..37f4a77 100644
--- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/async/AsyncQueueFullPolicyFactoryTest.java
+++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/async/AsyncQueueFullPolicyFactoryTest.java
@@ -21,7 +21,6 @@
import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.core.test.categories.AsyncLoggers;
-import org.apache.logging.log4j.util.PropertiesUtil;
import org.junit.After;
import org.junit.Before;
import org.junit.Test;
@@ -38,7 +37,6 @@
public void resetProperties() throws Exception {
System.clearProperty(AsyncQueueFullPolicyFactory.PROPERTY_NAME_ASYNC_EVENT_ROUTER);
System.clearProperty(AsyncQueueFullPolicyFactory.PROPERTY_NAME_DISCARDING_THRESHOLD_LEVEL);
- PropertiesUtil.getProperties().reload();
}
@Test
diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/impl/ThreadContextDataInjectorTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/impl/ThreadContextDataInjectorTest.java
index 39258f5..ff4211c 100644
--- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/impl/ThreadContextDataInjectorTest.java
+++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/impl/ThreadContextDataInjectorTest.java
@@ -35,7 +35,6 @@
import org.apache.logging.log4j.core.ContextDataInjector;
import org.apache.logging.log4j.spi.ReadOnlyThreadContextMap;
import org.apache.logging.log4j.test.ThreadContextUtilityClass;
-import org.apache.logging.log4j.util.PropertiesUtil;
import org.apache.logging.log4j.util.SortedArrayStringMap;
import org.apache.logging.log4j.util.StringMap;
import org.junit.After;
@@ -122,7 +121,6 @@
private void prepareThreadContext(final boolean isThreadContextMapInheritable) {
System.setProperty("log4j2.isThreadContextMapInheritable", Boolean.toString(isThreadContextMapInheritable));
- PropertiesUtil.getProperties().reload();
ThreadContextUtilityClass.reset();
ThreadContext.remove("baz");
ThreadContext.put("foo", "bar");
diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/net/ssl/SslConfigurationFactoryTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/net/ssl/SslConfigurationFactoryTest.java
index 53e3f11..0492ef0 100644
--- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/net/ssl/SslConfigurationFactoryTest.java
+++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/net/ssl/SslConfigurationFactoryTest.java
@@ -58,7 +58,6 @@
// Only keystore
props.clear();
addKeystoreConfiguration(props);
- util.reload();
sslConfiguration = SslConfigurationFactory.createSslConfiguration(util);
assertNotNull(sslConfiguration);
assertNotNull(sslConfiguration.getKeyStoreConfig());
@@ -66,7 +65,6 @@
// Only truststore
props.clear();
addTruststoreConfiguration(props);
- util.reload();
sslConfiguration = SslConfigurationFactory.createSslConfiguration(util);
assertNotNull(sslConfiguration);
assertNull(sslConfiguration.getKeyStoreConfig());
@@ -75,7 +73,6 @@
props.clear();
addKeystoreConfiguration(props);
addTruststoreConfiguration(props);
- util.reload();
sslConfiguration = SslConfigurationFactory.createSslConfiguration(util);
assertNotNull(sslConfiguration);
assertNotNull(sslConfiguration.getKeyStoreConfig());
diff --git a/log4j-jpa/src/test/java/org/apache/logging/log4j/core/appender/db/jpa/AbstractJpaAppenderTest.java b/log4j-jpa/src/test/java/org/apache/logging/log4j/core/appender/db/jpa/AbstractJpaAppenderTest.java
index 29ceb34..dc963af 100644
--- a/log4j-jpa/src/test/java/org/apache/logging/log4j/core/appender/db/jpa/AbstractJpaAppenderTest.java
+++ b/log4j-jpa/src/test/java/org/apache/logging/log4j/core/appender/db/jpa/AbstractJpaAppenderTest.java
@@ -36,7 +36,6 @@
import org.apache.logging.log4j.core.config.DefaultConfiguration;
import org.apache.logging.log4j.core.test.categories.Appenders;
import org.apache.logging.log4j.status.StatusLogger;
-import org.apache.logging.log4j.util.PropertiesUtil;
import org.junit.Test;
import org.junit.experimental.categories.Category;
@@ -57,7 +56,6 @@
System.setProperty(
ConfigurationFactory.CONFIGURATION_FILE_PROPERTY,
"org/apache/logging/log4j/core/appender/db/jpa/" + configFileName);
- PropertiesUtil.getProperties().reload();
final LoggerContext context = LoggerContext.getContext(false);
if (context.getConfiguration() instanceof DefaultConfiguration) {
context.reconfigure();
@@ -75,7 +73,6 @@
((JpaAppender) appender).getManager().close();
} finally {
System.clearProperty(ConfigurationFactory.CONFIGURATION_FILE_PROPERTY);
- PropertiesUtil.getProperties().reload();
context.reconfigure();
StatusLogger.getLogger().reset();
diff --git a/src/changelog/.2.x.x/2849-remove-token-based-matching.xml b/src/changelog/.2.x.x/2849-remove-token-based-matching.xml
new file mode 100644
index 0000000..32d8b3c
--- /dev/null
+++ b/src/changelog/.2.x.x/2849-remove-token-based-matching.xml
@@ -0,0 +1,8 @@
+<?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="changed">
+ <issue id="2849" link="https://github.com/apache/logging-log4j2/pull/2849"/>
+ <description format="asciidoc">Remove configuration properties caching and (undocumented) fuzzy property name matching.</description>
+</entry>
