This is an automated email from the ASF dual-hosted git repository. pkarwasz pushed a commit to branch 2.x in repository https://gitbox.apache.org/repos/asf/logging-log4j2.git
commit f6df651de571bb1fcb91c5cf5b875faa22897249 Author: PanLongfei <[email protected]> AuthorDate: Fri Mar 22 09:35:35 2024 +0800 Fix issue 2380: Log messages with insufficient parameters should not throw exception.Add test cases. --- .../log4j/message/ParameterFormatterTest.java | 37 +++++-- .../log4j/message/ParameterizedMessageTest.java | 108 +++++++++++++++++++-- .../logging/log4j/message/ParameterFormatter.java | 15 ++- .../log4j/message/ParameterizedMessage.java | 18 +--- 4 files changed, 145 insertions(+), 33 deletions(-) diff --git a/log4j-api-test/src/test/java/org/apache/logging/log4j/message/ParameterFormatterTest.java b/log4j-api-test/src/test/java/org/apache/logging/log4j/message/ParameterFormatterTest.java index 6fe4f2d519..164aedf2ec 100644 --- a/log4j-api-test/src/test/java/org/apache/logging/log4j/message/ParameterFormatterTest.java +++ b/log4j-api-test/src/test/java/org/apache/logging/log4j/message/ParameterFormatterTest.java @@ -22,8 +22,12 @@ import java.util.ArrayList; import java.util.Arrays; import java.util.Collections; import java.util.List; +import java.util.stream.Collectors; +import org.apache.logging.log4j.Level; import org.apache.logging.log4j.message.ParameterFormatter.MessagePatternAnalysis; -import org.apache.logging.log4j.test.junit.UsingStatusLoggerMock; +import org.apache.logging.log4j.status.StatusData; +import org.apache.logging.log4j.test.ListStatusListener; +import org.apache.logging.log4j.test.junit.UsingStatusListener; import org.junit.jupiter.api.Test; import org.junit.jupiter.params.ParameterizedTest; import org.junit.jupiter.params.provider.CsvSource; @@ -32,9 +36,15 @@ import org.junit.jupiter.params.provider.MethodSource; /** * Tests {@link ParameterFormatter}. */ -@UsingStatusLoggerMock +@UsingStatusListener class ParameterFormatterTest { + final ListStatusListener statusListener; + + ParameterFormatterTest(ListStatusListener statusListener) { + this.statusListener = statusListener; + } + @ParameterizedTest @CsvSource({ "0,,false,", @@ -67,12 +77,23 @@ class ParameterFormatterTest { } } - @Test - void formatWithInsufficientArgs() { - final String pattern = "Test message {}-{} {}"; - final Object[] args = {"a", "b"}; - final String message = ParameterFormatter.format(pattern, args, args.length); - assertThat(message).isEqualTo("Test message a-b {}"); + @ParameterizedTest + @CsvSource({"2,pan {} {},a,pan a {}", "3,pan {}{}{},a-b,pan ab{}", "1,pan {},a-b-c,pan a"}) + void format_should_fail_on_insufficient_args( + final int placeholderCount, final String pattern, final String argsStr, final String expectedMessage) { + final String[] args = argsStr.split("-"); + final int argCount = args.length; + + String actualMessage = ParameterFormatter.format(pattern, args, argCount); + assertThat(actualMessage).isEqualTo(expectedMessage); + final List<StatusData> statusDataList = statusListener.getStatusData().collect(Collectors.toList()); + assertThat(statusDataList).hasSize(1); + final StatusData statusData = statusDataList.get(0); + assertThat(statusData.getLevel()).isEqualTo(Level.WARN); + assertThat(statusData.getMessage().getFormattedMessage()) + .isEqualTo( + "found %d argument placeholders, but provided %d for pattern `%s`", + placeholderCount, argCount, pattern); } @ParameterizedTest diff --git a/log4j-api-test/src/test/java/org/apache/logging/log4j/message/ParameterizedMessageTest.java b/log4j-api-test/src/test/java/org/apache/logging/log4j/message/ParameterizedMessageTest.java index 149709a6a4..3f6ba36da0 100644 --- a/log4j-api-test/src/test/java/org/apache/logging/log4j/message/ParameterizedMessageTest.java +++ b/log4j-api-test/src/test/java/org/apache/logging/log4j/message/ParameterizedMessageTest.java @@ -19,7 +19,12 @@ package org.apache.logging.log4j.message; import static org.assertj.core.api.Assertions.assertThat; import java.math.BigDecimal; +import java.util.List; +import java.util.function.Supplier; +import java.util.stream.Collectors; import java.util.stream.Stream; +import org.apache.logging.log4j.Level; +import org.apache.logging.log4j.status.StatusData; import org.apache.logging.log4j.test.ListStatusListener; import org.apache.logging.log4j.test.junit.Mutable; import org.apache.logging.log4j.test.junit.SerialUtil; @@ -181,20 +186,107 @@ class ParameterizedMessageTest { } @Test - void formatToWithInsufficientArgs() { - final String pattern = "Test message {}-{} {}"; - final Object[] args = {"a", "b"}; + void formatToWithMoreArgsButNoWarn() { + final String pattern = "no warn {} {}"; + final String expectedMessage = "no warn a b"; + final Object[] args = {"a", "b", new RuntimeException()}; final ParameterizedMessage message = new ParameterizedMessage(pattern, args); final StringBuilder buffer = new StringBuilder(); message.formatTo(buffer); - assertThat(buffer.toString()).isEqualTo("Test message a-b {}"); + assertThat(buffer.toString()).isEqualTo(expectedMessage); + assertThat(message.getThrowable()).isInstanceOf(RuntimeException.class); + final List<StatusData> statusDataList = statusListener.getStatusData().collect(Collectors.toList()); + assertThat(statusDataList).hasSize(0); } @Test - void formatWithInsufficientArgs() { - final String pattern = "Test message {}-{} {}"; - final Object[] args = {"a", "b"}; + void formatWithMoreArgsButNoWarn() { + final String pattern = "no warn {} {}"; + final String expectedMessage = "no warn a b"; + final Object[] args = {"a", "b", new RuntimeException()}; final String message = ParameterizedMessage.format(pattern, args); - assertThat(message).isEqualTo("Test message a-b {}"); + assertThat(message).isEqualTo(expectedMessage); + final List<StatusData> statusDataList = statusListener.getStatusData().collect(Collectors.toList()); + assertThat(statusDataList).hasSize(0); + } + + /** + * In this test cases, constructed the following scenarios: <br> + * <p> + * 1. The placeholders are greater than the count of arguments. <br> + * 2. The placeholders are less than the count of arguments. <br> + * 3. The arguments contains an exception, and the placeholder is greater than normal arguments. <br> + * 4. The arguments contains an exception, and the placeholder is less than the arguments.<br> + * All of these should logged in status logger with WARN level. + * </p> + * + * @return streams + */ + static Stream<Object[]> testCasesForInsufficientFormatArgs() { + return Stream.of( + new Object[] {"more {} {}", 2, new Object[] {"a"}, "more a {}"}, + new Object[] {"more {} {} {}", 3, new Object[] {"a"}, "more a {} {}"}, + new Object[] {"less {}", 1, new Object[] {"a", "b"}, "less a"}, + new Object[] {"less {} {}", 2, new Object[] {"a", "b", "c"}, "less a b"}, + new Object[] { + "more throwable {} {}", + 2, + new Object[] {"a", new RuntimeException()}, + "more throwable a java.lang.RuntimeException" + }, + new Object[] { + "more throwable {} {} {}", + 3, + new Object[] {"a", new RuntimeException()}, + "more throwable a java.lang.RuntimeException {}" + }, + new Object[] { + "less throwable {}", 1, new Object[] {"a", "b", new RuntimeException()}, "less throwable a" + }); + } + + @ParameterizedTest + @MethodSource("testCasesForInsufficientFormatArgs") + void formatTo_should_warn_on_insufficient_args( + final String pattern, final int placeholderCount, Object[] args, final String expected) { + final int argCount = args == null ? 0 : args.length; + verifyFormattingFailureOnInsufficientArgs(pattern, placeholderCount, argCount, expected, () -> { + final ParameterizedMessage message = new ParameterizedMessage(pattern, args); + final StringBuilder buffer = new StringBuilder(); + message.formatTo(buffer); + return buffer.toString(); + }); + } + + @ParameterizedTest + @MethodSource("testCasesForInsufficientFormatArgs") + void format_should_warn_on_insufficient_args( + final String pattern, final int placeholderCount, Object[] args, final String expected) { + final int argCount = args == null ? 0 : args.length; + verifyFormattingFailureOnInsufficientArgs( + pattern, placeholderCount, argCount, expected, () -> ParameterizedMessage.format(pattern, args)); + } + + private void verifyFormattingFailureOnInsufficientArgs( + final String pattern, + final int placeholderCount, + final int argCount, + final String expected, + final Supplier<String> formattedMessageSupplier) { + + // Verify the formatted message + final String formattedMessage = formattedMessageSupplier.get(); + assertThat(formattedMessage).isEqualTo(expected); + + // Verify the status logger warn + final List<StatusData> statusDataList = statusListener.getStatusData().collect(Collectors.toList()); + assertThat(statusDataList).hasSize(1); + final StatusData statusData = statusDataList.get(0); + assertThat(statusData.getLevel()).isEqualTo(Level.WARN); + assertThat(statusData.getMessage().getFormattedMessage()) + .isEqualTo( + "found %d argument placeholders, but provided %d for pattern `%s`", + placeholderCount, argCount, pattern); + assertThat(statusData.getThrowable()).isNull(); } } diff --git a/log4j-api/src/main/java/org/apache/logging/log4j/message/ParameterFormatter.java b/log4j-api/src/main/java/org/apache/logging/log4j/message/ParameterFormatter.java index d2bae68748..89d657dc02 100644 --- a/log4j-api/src/main/java/org/apache/logging/log4j/message/ParameterFormatter.java +++ b/log4j-api/src/main/java/org/apache/logging/log4j/message/ParameterFormatter.java @@ -26,6 +26,8 @@ import java.util.Date; import java.util.IdentityHashMap; import java.util.Map; import java.util.Set; +import org.apache.logging.log4j.Logger; +import org.apache.logging.log4j.status.StatusLogger; import org.apache.logging.log4j.util.StringBuilders; /** @@ -65,6 +67,8 @@ final class ParameterFormatter { private static final DateTimeFormatter DATE_FORMATTER = DateTimeFormatter.ofPattern("yyyy-MM-dd'T'HH:mm:ss.SSSZ").withZone(ZoneId.systemDefault()); + private static final Logger STATUS_LOGGER = StatusLogger.getLogger(); + private ParameterFormatter() {} /** @@ -235,11 +239,20 @@ final class ParameterFormatter { final MessagePatternAnalysis analysis) { // Short-circuit if there is nothing interesting - if (pattern == null || args == null || analysis.placeholderCount == 0) { + if (pattern == null || args == null || args.length == 0 || analysis.placeholderCount == 0) { buffer.append(pattern); return; } + // check if there are insufficient arguments that do not include Throwable arg + final int noThrowableArgCount = argCount - ((args[argCount - 1] instanceof Throwable) ? 1 : 0); + if (analysis.placeholderCount != noThrowableArgCount) { + final String message = String.format( + "found %d argument placeholders, but provided %d for pattern `%s`", + analysis.placeholderCount, args.length, pattern); + STATUS_LOGGER.warn(message); + } + // Fast-path for patterns containing no escapes if (analysis.escapedCharFound) { formatMessageContainingEscapes(buffer, pattern, args, argCount, analysis); diff --git a/log4j-api/src/main/java/org/apache/logging/log4j/message/ParameterizedMessage.java b/log4j-api/src/main/java/org/apache/logging/log4j/message/ParameterizedMessage.java index a5b27e985e..4da3642cca 100644 --- a/log4j-api/src/main/java/org/apache/logging/log4j/message/ParameterizedMessage.java +++ b/log4j-api/src/main/java/org/apache/logging/log4j/message/ParameterizedMessage.java @@ -26,9 +26,7 @@ import java.io.ObjectOutputStream; import java.io.Serializable; import java.util.Arrays; import java.util.Objects; -import org.apache.logging.log4j.Logger; import org.apache.logging.log4j.message.ParameterFormatter.MessagePatternAnalysis; -import org.apache.logging.log4j.status.StatusLogger; import org.apache.logging.log4j.util.Constants; import org.apache.logging.log4j.util.StringBuilderFormattable; import org.apache.logging.log4j.util.internal.SerializationUtil; @@ -81,8 +79,6 @@ public class ParameterizedMessage implements Message, StringBuilderFormattable { private static final long serialVersionUID = -665975803997290697L; - private static final Logger STATUS_LOGGER = StatusLogger.getLogger(); - private static final ThreadLocal<FormatBufferHolder> FORMAT_BUFFER_HOLDER_REF = Constants.ENABLE_THREADLOCALS ? ThreadLocal.withInitial(FormatBufferHolder::new) : null; @@ -278,12 +274,7 @@ public class ParameterizedMessage implements Message, StringBuilderFormattable { buffer.append(formattedMessage); } else { final int argCount = args != null ? args.length : 0; - try { - ParameterFormatter.formatMessage(buffer, pattern, args, argCount, patternAnalysis); - } catch (final Exception error) { - STATUS_LOGGER.error("Unable to format msg: {}", pattern, error); - buffer.append(pattern); - } + ParameterFormatter.formatMessage(buffer, pattern, args, argCount, patternAnalysis); } } @@ -294,12 +285,7 @@ public class ParameterizedMessage implements Message, StringBuilderFormattable { */ public static String format(final String pattern, final Object[] args) { final int argCount = args != null ? args.length : 0; - try { - return ParameterFormatter.format(pattern, args, argCount); - } catch (final Exception error) { - STATUS_LOGGER.error("Unable to format msg: {}", pattern, error); - return pattern; - } + return ParameterFormatter.format(pattern, args, argCount); } @Override
