Skip to content

Fix issue #2380: Log messages with insufficient parameters should not throw exception. #2393

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

Original file line number Diff line number Diff line change
Expand Up @@ -17,14 +17,17 @@
package org.apache.logging.log4j.message;

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

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;
Expand All @@ -33,9 +36,15 @@
/**
* Tests {@link ParameterFormatter}.
*/
@UsingStatusLoggerMock
@UsingStatusListener
class ParameterFormatterTest {

final ListStatusListener statusListener;

ParameterFormatterTest(ListStatusListener statusListener) {
this.statusListener = statusListener;
}

@ParameterizedTest
@CsvSource({
"0,,false,",
Expand Down Expand Up @@ -69,12 +78,20 @@ void test_pattern_analysis(
}

@ParameterizedTest
@CsvSource({"1,foo {}", "2,bar {}{}"})
void format_should_fail_on_insufficient_args(final int placeholderCount, final String pattern) {
final int argCount = placeholderCount - 1;
assertThatThrownBy(() -> ParameterFormatter.format(pattern, new Object[argCount], argCount))
.isInstanceOf(IllegalArgumentException.class)
.hasMessage(
@CsvSource({"2,pan {} {},a,pan a {}", "3,pan {}{}{},a b,pan ab{}", "1,pan {},a b c,pan a"})
void format_should_warn_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);
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -185,16 +185,84 @@ void testSerializable(final Object arg) {
assertThat(actual.getFormattedMessage()).isEqualTo(expected.getFormattedMessage());
}

/**
* In this test cases, constructed the following scenarios: <br>
* <p>
* 1. The arguments contains an exception, and the count of placeholder is equal to arguments include exception. <br>
* 2. The arguments contains an exception, and the count of placeholder is equal to arguments except exception.<br>
* All of these should not logged in status logger.
* </p>
*
* @return Streams
*/
static Stream<Object[]> testCasesWithExceptionArgsButNoWarn() {
return Stream.of(
new Object[] {
"with exception {} {}",
new Object[] {"a", new RuntimeException()},
"with exception a java.lang.RuntimeException"
},
new Object[] {
"with exception {} {}", new Object[] {"a", "b", new RuntimeException()}, "with exception a b"
});
}

@ParameterizedTest
@MethodSource("testCasesWithExceptionArgsButNoWarn")
void formatToWithExceptionButNoWarn(final String pattern, final Object[] args, final String expected) {
final ParameterizedMessage message = new ParameterizedMessage(pattern, args);
final StringBuilder buffer = new StringBuilder();
message.formatTo(buffer);
assertThat(buffer.toString()).isEqualTo(expected);
final List<StatusData> statusDataList = statusListener.getStatusData().collect(Collectors.toList());
assertThat(statusDataList).hasSize(0);
}

@ParameterizedTest
@MethodSource("testCasesWithExceptionArgsButNoWarn")
void formatWithExceptionButNoWarn(final String pattern, final Object[] args, final String expected) {
final String message = ParameterizedMessage.format(pattern, args);
assertThat(message).isEqualTo(expected);
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[] {1, "foo {}"}, new Object[] {2, "bar {}{}"});
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 {} {} {}",
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_fail_on_insufficient_args(final int placeholderCount, final String pattern) {
final int argCount = placeholderCount - 1;
verifyFormattingFailureOnInsufficientArgs(placeholderCount, pattern, argCount, () -> {
final ParameterizedMessage message = new ParameterizedMessage(pattern, new Object[argCount]);
void formatToShouldWarnOnInsufficientArgs(
final String pattern, final int placeholderCount, final 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();
Expand All @@ -203,32 +271,33 @@ void formatTo_should_fail_on_insufficient_args(final int placeholderCount, final

@ParameterizedTest
@MethodSource("testCasesForInsufficientFormatArgs")
void format_should_fail_on_insufficient_args(final int placeholderCount, final String pattern) {
final int argCount = placeholderCount - 1;
void formatShouldWarnOnInsufficientArgs(
final String pattern, final int placeholderCount, final Object[] args, final String expected) {
final int argCount = args == null ? 0 : args.length;
verifyFormattingFailureOnInsufficientArgs(
placeholderCount, pattern, argCount, () -> ParameterizedMessage.format(pattern, new Object[argCount]));
pattern, placeholderCount, argCount, expected, () -> ParameterizedMessage.format(pattern, args));
}

private void verifyFormattingFailureOnInsufficientArgs(
final int placeholderCount,
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(pattern);
assertThat(formattedMessage).isEqualTo(expected);

// Verify the logged failure
// 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.ERROR);
assertThat(statusData.getMessage().getFormattedMessage()).isEqualTo("Unable to format msg: %s", pattern);
assertThat(statusData.getThrowable())
.isInstanceOf(IllegalArgumentException.class)
.hasMessage(
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();
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -26,6 +26,8 @@
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;

/**
Expand Down Expand Up @@ -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() {}

/**
Expand Down Expand Up @@ -240,12 +244,17 @@ static void formatMessage(
return;
}

// Fail if there are insufficient arguments
if (analysis.placeholderCount > args.length) {
final String message = String.format(
"found %d argument placeholders, but provided %d for pattern `%s`",
analysis.placeholderCount, args.length, pattern);
throw new IllegalArgumentException(message);
// #2380: check if the count of placeholder is not equal to the count of arguments
if (analysis.placeholderCount != argCount) {
final int noThrowableArgCount =
argCount < 1 ? 0 : argCount - ((args[argCount - 1] instanceof Throwable) ? 1 : 0);
if (analysis.placeholderCount != noThrowableArgCount) {
STATUS_LOGGER.warn(
"found {} argument placeholders, but provided {} for pattern `{}`",
analysis.placeholderCount,
argCount,
pattern);
}
}

// Fast-path for patterns containing no escapes
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -26,9 +26,7 @@
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;
Expand Down Expand Up @@ -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;

Expand Down Expand Up @@ -278,12 +274,7 @@ public void formatTo(final StringBuilder buffer) {
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);
}
}

Expand All @@ -294,12 +285,7 @@ public void formatTo(final StringBuilder buffer) {
*/
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
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,11 @@
<?xml version="1.0" encoding="UTF-8"?>
<entry xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xmlns="http://logging.apache.org/log4j/changelog"
xsi:schemaLocation="http://logging.apache.org/log4j/changelog https://logging.apache.org/log4j/changelog-0.1.3.xsd"
type="fixed">
<issue id="2380" link="https://github.com/apache/logging-log4j2/pull/2380"/>
<description format="asciidoc">
Fix that parameterized message formatting throws an exception when there are insufficient number of parameters.
It previously simply didn't replace the '{}' sequence. The behavior changed in 2.21.0 and should be restored for backward compatibility.
</description>
</entry>