You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@logging.apache.org by rg...@apache.org on 2021/12/05 05:47:57 UTC
[logging-log4j2] 01/02: LOG4J2-3198: Log4j2 no longer formats lookups in messages by default
This is an automated email from the ASF dual-hosted git repository.
rgoers pushed a commit to branch release-2.x
in repository https://gitbox.apache.org/repos/asf/logging-log4j2.git
commit 001aaada7dab82c3c09cde5f8e14245dc9d8b454
Author: Carter Kozak <ck...@apache.org>
AuthorDate: Mon Nov 29 14:20:33 2021 +0000
LOG4J2-3198: Log4j2 no longer formats lookups in messages by default
Lookups in messages are confusing, and muddy the line between logging APIs
and implementation. Given a particular API, there's an expectation that a
particular shape of call will result in specific results. However, lookups
in messages can be passed into JUL and will result in resolved output in
log4j formatted output, but not any other implementations despite no direct
dependency on those implementations.
There's also a cost to searching formatted message strings for particular
escape sequences which define lookups. This feature is not used as far as
we've been able to tell searching github and stackoverflow, so it's
unnecessary for every log event in every application to burn several cpu
cycles searching for the value.
---
.../core/pattern/MessagePatternConverter.java | 31 +++++++++++++++-------
.../apache/logging/log4j/core/util/Constants.java | 10 ++++---
.../core/layout/PatternLayoutLookupDateTest.java | 2 +-
.../core/layout/PatternLayoutNoLookupDateTest.java | 2 +-
.../core/pattern/MessagePatternConverterTest.java | 27 +++++++++++++------
.../log4j/core/pattern/RegexReplacementTest.java | 18 ++++++++-----
...j-list-nolookups.xml => log4j-list-lookups.xml} | 2 +-
log4j-core/src/test/resources/log4j-replace.xml | 4 +--
src/changes/changes.xml | 6 +++++
src/site/xdoc/manual/configuration.xml.vm | 21 ++++-----------
src/site/xdoc/manual/layouts.xml.vm | 15 ++++++-----
11 files changed, 84 insertions(+), 54 deletions(-)
diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/MessagePatternConverter.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/MessagePatternConverter.java
index 5c4c6ef..41ab46b 100644
--- a/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/MessagePatternConverter.java
+++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/MessagePatternConverter.java
@@ -16,13 +16,13 @@
*/
package org.apache.logging.log4j.core.pattern;
+import java.util.ArrayList;
+import java.util.List;
import java.util.Locale;
import org.apache.logging.log4j.core.LogEvent;
import org.apache.logging.log4j.core.config.Configuration;
import org.apache.logging.log4j.core.config.plugins.Plugin;
-import org.apache.logging.log4j.core.util.ArrayUtils;
-import org.apache.logging.log4j.core.util.Constants;
import org.apache.logging.log4j.core.util.Loader;
import org.apache.logging.log4j.message.Message;
import org.apache.logging.log4j.message.MultiformatMessage;
@@ -39,17 +39,18 @@ import org.apache.logging.log4j.util.StringBuilderFormattable;
@PerformanceSensitive("allocation")
public class MessagePatternConverter extends LogEventPatternConverter {
+ private static final String LOOKUPS = "lookups";
private static final String NOLOOKUPS = "nolookups";
private MessagePatternConverter() {
super("Message", "message");
}
- private static int loadNoLookups(final String[] options) {
+ private static int loadLookups(final String[] options) {
if (options != null) {
for (int i = 0; i < options.length; i++) {
final String option = options[i];
- if (NOLOOKUPS.equalsIgnoreCase(option)) {
+ if (LOOKUPS.equalsIgnoreCase(option)) {
return i;
}
}
@@ -86,14 +87,13 @@ public class MessagePatternConverter extends LogEventPatternConverter {
* @return instance of pattern converter.
*/
public static MessagePatternConverter newInstance(final Configuration config, final String[] options) {
- int noLookupsIdx = loadNoLookups(options);
- boolean noLookups = Constants.FORMAT_MESSAGES_PATTERN_DISABLE_LOOKUPS || noLookupsIdx >= 0;
- String[] formats = noLookupsIdx >= 0 ? ArrayUtils.remove(options, noLookupsIdx) : options;
- TextRenderer textRenderer = loadMessageRenderer(noLookupsIdx >= 0 ? ArrayUtils.remove(options, noLookupsIdx) : options);
+ boolean lookups = loadLookups(options) >= 0;
+ String[] formats = withoutLookupOptions(options);
+ TextRenderer textRenderer = loadMessageRenderer(formats);
MessagePatternConverter result = formats == null || formats.length == 0
? SimpleMessagePatternConverter.INSTANCE
: new FormattedMessagePatternConverter(formats);
- if (!noLookups && config != null) {
+ if (lookups && config != null) {
result = new LookupMessagePatternConverter(result, config);
}
if (textRenderer != null) {
@@ -102,6 +102,19 @@ public class MessagePatternConverter extends LogEventPatternConverter {
return result;
}
+ private static String[] withoutLookupOptions(final String[] options) {
+ if (options == null || options.length == 0) {
+ return options;
+ }
+ List<String> results = new ArrayList<>(options.length);
+ for (String option : options) {
+ if (!LOOKUPS.equalsIgnoreCase(option) && !NOLOOKUPS.equalsIgnoreCase(option)) {
+ results.add(option);
+ }
+ }
+ return results.toArray(new String[0]);
+ }
+
@Override
public void format(final LogEvent event, final StringBuilder toAppendTo) {
throw new UnsupportedOperationException();
diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/Constants.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/Constants.java
index fa01c13..9609160 100644
--- a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/Constants.java
+++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/Constants.java
@@ -55,13 +55,17 @@ public final class Constants {
"log4j.format.msg.async", false);
/**
- * LOG4J2-2109 if {@code true}, MessagePatternConverter will always operate as though
- * <pre>%m{nolookups}</pre> is configured.
+ * LOG4J2-3198 property which used to globally opt out of lookups in pattern layout message text, however
+ * this is the default and this property is no longer read.
+ *
+ * Deprecated in 2.15.
*
* @since 2.10
+ * @deprecated no longer used, lookups are only used when {@code %m{lookups}} is specified
*/
+ @Deprecated
public static final boolean FORMAT_MESSAGES_PATTERN_DISABLE_LOOKUPS = PropertiesUtil.getProperties().getBooleanProperty(
- "log4j2.formatMsgNoLookups", false);
+ "log4j2.formatMsgNoLookups", true);
/**
* {@code true} if we think we are running in a web container, based on the boolean value of system property
diff --git a/log4j-core/src/test/java/org/apache/logging/log4j/core/layout/PatternLayoutLookupDateTest.java b/log4j-core/src/test/java/org/apache/logging/log4j/core/layout/PatternLayoutLookupDateTest.java
index d814d1d..01d1966 100644
--- a/log4j-core/src/test/java/org/apache/logging/log4j/core/layout/PatternLayoutLookupDateTest.java
+++ b/log4j-core/src/test/java/org/apache/logging/log4j/core/layout/PatternLayoutLookupDateTest.java
@@ -29,7 +29,7 @@ import static org.junit.jupiter.api.Assertions.assertFalse;
*
* This shows the behavior this user wants to disable.
*/
-@LoggerContextSource("log4j-list.xml")
+@LoggerContextSource("log4j-list-lookups.xml")
public class PatternLayoutLookupDateTest {
@Test
diff --git a/log4j-core/src/test/java/org/apache/logging/log4j/core/layout/PatternLayoutNoLookupDateTest.java b/log4j-core/src/test/java/org/apache/logging/log4j/core/layout/PatternLayoutNoLookupDateTest.java
index 78ae6dc..52a4e48 100644
--- a/log4j-core/src/test/java/org/apache/logging/log4j/core/layout/PatternLayoutNoLookupDateTest.java
+++ b/log4j-core/src/test/java/org/apache/logging/log4j/core/layout/PatternLayoutNoLookupDateTest.java
@@ -26,7 +26,7 @@ import org.junit.jupiter.api.Test;
/**
* See (LOG4J2-905) Ability to disable (date) lookup completely, compatibility issues with other libraries like camel.
*/
-@LoggerContextSource("log4j-list-nolookups.xml")
+@LoggerContextSource("log4j-list.xml")
public class PatternLayoutNoLookupDateTest {
@Test
diff --git a/log4j-core/src/test/java/org/apache/logging/log4j/core/pattern/MessagePatternConverterTest.java b/log4j-core/src/test/java/org/apache/logging/log4j/core/pattern/MessagePatternConverterTest.java
index 04aad5f..6c6dae9 100644
--- a/log4j-core/src/test/java/org/apache/logging/log4j/core/pattern/MessagePatternConverterTest.java
+++ b/log4j-core/src/test/java/org/apache/logging/log4j/core/pattern/MessagePatternConverterTest.java
@@ -22,7 +22,6 @@ import org.apache.logging.log4j.core.config.Configuration;
import org.apache.logging.log4j.core.config.DefaultConfiguration;
import org.apache.logging.log4j.core.config.builder.impl.DefaultConfigurationBuilder;
import org.apache.logging.log4j.core.impl.Log4jLogEvent;
-import org.apache.logging.log4j.core.util.Constants;
import org.apache.logging.log4j.message.Message;
import org.apache.logging.log4j.message.ParameterizedMessage;
import org.apache.logging.log4j.message.SimpleMessage;
@@ -76,12 +75,7 @@ public class MessagePatternConverterTest {
}
@Test
- public void testLookupEnabledByDefault() {
- assertFalse(Constants.FORMAT_MESSAGES_PATTERN_DISABLE_LOOKUPS, "Expected lookups to be enabled");
- }
-
- @Test
- public void testLookup() {
+ public void testDefaultDisabledLookup() {
final Configuration config = new DefaultConfigurationBuilder()
.addProperty("foo", "bar")
.build(true);
@@ -93,7 +87,7 @@ public class MessagePatternConverterTest {
.setMessage(msg).build();
final StringBuilder sb = new StringBuilder();
converter.format(event, sb);
- assertEquals("bar", sb.toString(), "Unexpected result");
+ assertEquals("${foo}", sb.toString(), "Unexpected result");
}
@Test
@@ -114,6 +108,23 @@ public class MessagePatternConverterTest {
}
@Test
+ public void testLookup() {
+ final Configuration config = new DefaultConfigurationBuilder()
+ .addProperty("foo", "bar")
+ .build(true);
+ final MessagePatternConverter converter =
+ MessagePatternConverter.newInstance(config, new String[] {"lookups"});
+ final Message msg = new ParameterizedMessage("${foo}");
+ final LogEvent event = Log4jLogEvent.newBuilder() //
+ .setLoggerName("MyLogger") //
+ .setLevel(Level.DEBUG) //
+ .setMessage(msg).build();
+ final StringBuilder sb = new StringBuilder();
+ converter.format(event, sb);
+ assertEquals("bar", sb.toString(), "Unexpected result");
+ }
+
+ @Test
public void testPatternWithConfiguration() {
final Configuration config = new DefaultConfiguration();
final MessagePatternConverter converter = MessagePatternConverter.newInstance(config, null);
diff --git a/log4j-core/src/test/java/org/apache/logging/log4j/core/pattern/RegexReplacementTest.java b/log4j-core/src/test/java/org/apache/logging/log4j/core/pattern/RegexReplacementTest.java
index 541ae19..6b2f63d 100644
--- a/log4j-core/src/test/java/org/apache/logging/log4j/core/pattern/RegexReplacementTest.java
+++ b/log4j-core/src/test/java/org/apache/logging/log4j/core/pattern/RegexReplacementTest.java
@@ -16,6 +16,12 @@
*/
package org.apache.logging.log4j.core.pattern;
+import static org.junit.jupiter.api.Assertions.assertEquals;
+import static org.junit.jupiter.api.Assertions.assertNotNull;
+import static org.junit.jupiter.api.Assertions.assertTrue;
+
+import java.util.List;
+
import org.apache.logging.log4j.ThreadContext;
import org.apache.logging.log4j.core.LoggerContext;
import org.apache.logging.log4j.junit.LoggerContextSource;
@@ -25,10 +31,6 @@ import org.apache.logging.log4j.test.appender.ListAppender;
import org.apache.logging.log4j.util.Strings;
import org.junit.jupiter.api.Test;
-import java.util.List;
-
-import static org.junit.jupiter.api.Assertions.*;
-
@LoggerContextSource("log4j-replace.xml")
@UsingThreadContextMap
public class RegexReplacementTest {
@@ -55,10 +57,14 @@ public class RegexReplacementTest {
assertEquals(1, msgs.size(), "Incorrect number of messages. Should be 1 is " + msgs.size());
assertTrue(
msgs.get(0).endsWith(EXPECTED), "Replacement failed - expected ending " + EXPECTED + " Actual " + msgs.get(0));
- app.clear();
+
+ }
+
+ @Test
+ public void testMessageReplacement() {
ThreadContext.put("MyKey", "Apache");
logger.error("This is a test for ${ctx:MyKey}");
- msgs = app.getMessages();
+ List<String> msgs = app.getMessages();
assertNotNull(msgs);
assertEquals(1, msgs.size(), "Incorrect number of messages. Should be 1 is " + msgs.size());
assertEquals("LoggerTest This is a test for Apache" + Strings.LINE_SEPARATOR, msgs.get(0));
diff --git a/log4j-core/src/test/resources/log4j-list-nolookups.xml b/log4j-core/src/test/resources/log4j-list-lookups.xml
similarity index 91%
rename from log4j-core/src/test/resources/log4j-list-nolookups.xml
rename to log4j-core/src/test/resources/log4j-list-lookups.xml
index 2477db7..f8df499 100644
--- a/log4j-core/src/test/resources/log4j-list-nolookups.xml
+++ b/log4j-core/src/test/resources/log4j-list-lookups.xml
@@ -18,7 +18,7 @@
<Configuration status="WARN">
<Appenders>
<List name="List">
- <PatternLayout pattern="[%-5level] %c{1.} %msg{ansi}{nolookups}%n" />
+ <PatternLayout pattern="[%-5level] %c{1.} %msg{ansi}{lookups}%n" />
</List>
</Appenders>
<Loggers>
diff --git a/log4j-core/src/test/resources/log4j-replace.xml b/log4j-core/src/test/resources/log4j-replace.xml
index 09ff3b1..8018167 100644
--- a/log4j-core/src/test/resources/log4j-replace.xml
+++ b/log4j-core/src/test/resources/log4j-replace.xml
@@ -21,12 +21,12 @@
<List name="List">
<PatternLayout>
<replace regex="\." replacement="/"/>
- <Pattern>%logger %msg%n</Pattern>
+ <Pattern>%logger %msg{lookups}%n</Pattern>
</PatternLayout>
</List>
<List name="List2">
<PatternLayout>
- <Pattern>%replace{%logger %C{1.} %msg%n}{\.}{/}</Pattern>
+ <Pattern>%replace{%logger %C{1.} %msg{lookups}%n}{\.}{/}</Pattern>
</PatternLayout>
</List>
</Appenders>
diff --git a/src/changes/changes.xml b/src/changes/changes.xml
index 50893bf..395da3b 100644
--- a/src/changes/changes.xml
+++ b/src/changes/changes.xml
@@ -31,6 +31,12 @@
-->
<release version="2.15.0" date="2021-MM-DD" description="GA Release 2.15.0">
<!-- ADDS -->
+ <action issue="LOG4J2-3198" dev="ckozak" type="add">
+ Pattern layout no longer enables lookups within message text by default for cleaner API boundaries and reduced
+ formatting overhead. The old 'log4j2.formatMsgNoLookups' which enabled this behavior has been removed as well
+ as the 'nolookups' message pattern converter option. The old behavior can be enabled on a per-pattern basis
+ using '%m{lookups}'.
+ </action>
<action issue="LOG4J2-3194" dev="rgoers" type="add" due-to="markuss">
Allow fractional attributes for size attribute of SizeBsaedTriggeringPolicy.
</action>
diff --git a/src/site/xdoc/manual/configuration.xml.vm b/src/site/xdoc/manual/configuration.xml.vm
index 5393fed..11f2940 100644
--- a/src/site/xdoc/manual/configuration.xml.vm
+++ b/src/site/xdoc/manual/configuration.xml.vm
@@ -1264,14 +1264,13 @@ rootLogger.appenderRef.stdout.ref = STDOUT
<code>app.properties</code> would be used as the default value.
</p>
</subsection>
- <a name="DisablingMessagePatternLookups"/>
- <subsection name="Disables Message Pattern Lookups">
+ <a name="EnablingMessagePatternLookups"/>
+ <subsection name="Enabling Message Pattern Lookups">
<p>
- A message is processed (by default) by lookups, for example if you defined
+ A message is processed (by default) without using lookups, for example if you defined
<code> <Property name="foo.bar">FOO_BAR </Property></code>, then <code>logger.info("${foo.bar}")</code>
- will output <code>FOO_BAR</code> instead of <code>${dollar}{foo.bar}</code>. You could disable message pattern
- lookups globally by setting system property <code>log4j2.formatMsgNoLookups</code> to true,
- or defining message pattern using %m{nolookups}.
+ will output <code>${dollar}{foo.bar}</code> instead of <code>FOO_BAR</code>. You could enable message pattern
+ lookups by defining message pattern using %m{lookups}.
</p>
</subsection>
<a name="RuntimeLookup"/>
@@ -2673,16 +2672,6 @@ public class AwesomeTest {
when the LoggerContext is started. For debug purposes.</td>
</tr>
<tr>
- <td><a name="formatMsgNoLookups"/>log4j2.formatMsgNoLookups
- <br />
- (<a name="log4j2.formatMsgNoLookups" />log4j2.formatMsgNoLookups)
- </td>
- <td>FORMAT_MESSAGES_PATTERN_DISABLE_LOOKUPS</td>
- <td>false</td>
- <td>Disables message pattern lookups globally when set to <tt>true</tt>.
- This is equivalent to defining all message patterns using <tt>%m{nolookups}</tt>.</td>
- </tr>
- <tr>
<td><a name="log4j2.trustStoreLocation "/>log4j2.trustStoreLocation</td>
<td>LOG4J_TRUST_STORE_LOCATION</td>
<td></td>
diff --git a/src/site/xdoc/manual/layouts.xml.vm b/src/site/xdoc/manual/layouts.xml.vm
index 0490d73..9d9ccc5 100644
--- a/src/site/xdoc/manual/layouts.xml.vm
+++ b/src/site/xdoc/manual/layouts.xml.vm
@@ -1455,9 +1455,9 @@ WARN [main]: Message 2</pre>
<tr>
<td align="center">
<a name="PatternMessage"/>
- <b>m</b>{nolookups}{ansi}<br />
- <b>msg</b>{nolookups}{ansi}<br />
- <b>message</b>{nolookups}{ansi}
+ <b>m</b>{ookups}{ansi}<br />
+ <b>msg</b>{lookups}{ansi}<br />
+ <b>message</b>{lookups}{ansi}
</td>
<td>
<p>
@@ -1493,10 +1493,11 @@ WARN [main]: Message 2</pre>
</p>
<pre class="prettyprint linenums">logger.info("@|KeyStyle {}|@ = @|ValueStyle {}|@", entry.getKey(), entry.getValue());</pre>
<p>
- Use <code>{nolookups}</code> to log messages like <code>"${esc.d}{date:YYYY-MM-dd}"</code>
- without using any lookups. Normally calling <code>logger.info("Try ${esc.d}{date:YYYY-MM-dd}")</code>
- would replace the date template <code>${esc.d}{date:YYYY-MM-dd}</code> with an actual date.
- Using <code>nolookups</code> disables this feature and logs the message string untouched.
+ Use <code>{lookups}</code> to log messages like <code>logger.info("Try ${esc.d}{date:YYYY-MM-dd}")</code>
+ using lookups, this will replace the date template <code>${esc.d}{date:YYYY-MM-dd}</code>
+ with an actual date. This can be confusing in many cases, and it's often both easier and
+ more obvious to handle the lookup in code.
+ This feature is disabled by default and the message string is logged untouched.
</p>
</td>
</tr>