From 9336aa5fe5612bb378c89f4d9f26fa10323f483c Mon Sep 17 00:00:00 2001 From: magicwerk Date: Sun, 4 May 2025 16:20:49 +0200 Subject: [PATCH 1/5] speedup-array-logging --- .../log4j/message/ParameterFormatter.java | 228 +++++++++++++++++- 1 file changed, 218 insertions(+), 10 deletions(-) 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 0e990894c0f..a9cada2a03b 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 @@ -257,12 +257,12 @@ static void formatMessage( } } - // Fast-path for patterns containing no escapes + // Slow-path for patterns containing escapes if (analysis.escapedCharFound) { formatMessageContainingEscapes(buffer, pattern, args, argCount, analysis); } - // Slow-path for patterns containing escapes + // Fast-path for patterns containing no escapes else { formatMessageContainingNoEscapes(buffer, pattern, args, argCount, analysis); } @@ -487,21 +487,21 @@ private static void appendPotentiallyRecursiveValue( private static void appendArray( final Object o, final StringBuilder str, final Set dejaVu, final Class oClass) { if (oClass == byte[].class) { - str.append(Arrays.toString((byte[]) o)); + appendArray((byte[]) o, str); } else if (oClass == short[].class) { - str.append(Arrays.toString((short[]) o)); + appendArray((short[]) o, str); } else if (oClass == int[].class) { - str.append(Arrays.toString((int[]) o)); + appendArray((int[]) o, str); } else if (oClass == long[].class) { - str.append(Arrays.toString((long[]) o)); + appendArray((long[]) o, str); } else if (oClass == float[].class) { - str.append(Arrays.toString((float[]) o)); + appendArray((float[]) o, str); } else if (oClass == double[].class) { - str.append(Arrays.toString((double[]) o)); + appendArray((double[]) o, str); } else if (oClass == boolean[].class) { - str.append(Arrays.toString((boolean[]) o)); + appendArray((boolean[]) o, str); } else if (oClass == char[].class) { - str.append(Arrays.toString((char[]) o)); + appendArray((char[]) o, str); } else { // special handling of container Object[] final Set effectiveDejaVu = getOrCreateDejaVu(dejaVu); @@ -643,4 +643,212 @@ static String identityToString(final Object obj) { } return obj.getClass().getName() + '@' + Integer.toHexString(System.identityHashCode(obj)); } + + /** + * Adds a string representation of the contents of the specified array to the buffer. + * + * @param a the array to convert (not null) + * @param str the {@code StringBuilder} that {@code a} will be appended to + * + * @see Arrays#toString(byte[]) + */ + private static void appendArray(final byte[] a, final StringBuilder str) { + int iMax = a.length - 1; + if (iMax == -1) { + str.append("[]"); + return; + } + + str.append('['); + for (int i = 0; ; i++) { + str.append(a[i]); + if (i == iMax) { + str.append(']'); + return; + } + str.append(", "); + } + } + + /** + * Adds a string representation of the contents of the specified array to the buffer. + * + * @param a the array to convert (not null) + * @param str the {@code StringBuilder} that {@code a} will be appended to + * + * @see Arrays#toString(short[]) + */ + private static void appendArray(final short[] a, final StringBuilder str) { + int iMax = a.length - 1; + if (iMax == -1) { + str.append("[]"); + return; + } + + str.append('['); + for (int i = 0; ; i++) { + str.append(a[i]); + if (i == iMax) { + str.append(']'); + return; + } + str.append(", "); + } + } + + /** + * Adds a string representation of the contents of the specified array to the buffer. + * + * @param a the array to convert (not null) + * @param str the {@code StringBuilder} that {@code a} will be appended to + * + * @see Arrays#toString(int[]) + */ + private static void appendArray(final int[] a, final StringBuilder str) { + int iMax = a.length - 1; + if (iMax == -1) { + str.append("[]"); + return; + } + + str.append('['); + for (int i = 0; ; i++) { + str.append(a[i]); + if (i == iMax) { + str.append(']'); + return; + } + str.append(", "); + } + } + + /** + * Adds a string representation of the contents of the specified array to the buffer. + * + * @param a the array to convert (not null) + * @param str the {@code StringBuilder} that {@code a} will be appended to + * + * @see Arrays#toString(long[]) + */ + private static void appendArray(final long[] a, final StringBuilder str) { + int iMax = a.length - 1; + if (iMax == -1) { + str.append("[]"); + return; + } + + str.append('['); + for (int i = 0; ; i++) { + str.append(a[i]); + if (i == iMax) { + str.append(']'); + return; + } + str.append(", "); + } + } + + /** + * Adds a string representation of the contents of the specified array to the buffer. + * + * @param a the array to convert (not null) + * @param str the {@code StringBuilder} that {@code a} will be appended to + * + * @see Arrays#toString(float[]) + */ + private static void appendArray(final float[] a, final StringBuilder str) { + int iMax = a.length - 1; + if (iMax == -1) { + str.append("[]"); + return; + } + + str.append('['); + for (int i = 0; ; i++) { + str.append(a[i]); + if (i == iMax) { + str.append(']'); + return; + } + str.append(", "); + } + } + + /** + * Adds a string representation of the contents of the specified array to the buffer. + * + * @param a the array to convert (not null) + * @param str the {@code StringBuilder} that {@code a} will be appended to + * + * @see Arrays#toString(double[]) + */ + private static void appendArray(final double[] a, final StringBuilder str) { + int iMax = a.length - 1; + if (iMax == -1) { + str.append("[]"); + return; + } + + str.append('['); + for (int i = 0; ; i++) { + str.append(a[i]); + if (i == iMax) { + str.append(']'); + return; + } + str.append(", "); + } + } + + /** + * Adds a string representation of the contents of the specified array to the buffer. + * + * @param a the array to convert (not null) + * @param str the {@code StringBuilder} that {@code a} will be appended to + * + * @see Arrays#toString(boolean[]) + */ + private static void appendArray(final boolean[] a, final StringBuilder str) { + int iMax = a.length - 1; + if (iMax == -1) { + str.append("[]"); + return; + } + + str.append('['); + for (int i = 0; ; i++) { + str.append(a[i]); + if (i == iMax) { + str.append(']'); + return; + } + str.append(", "); + } + } + + /** + * Adds a string representation of the contents of the specified array to the buffer. + * + * @param a the array to convert (not null) + * @param str the {@code StringBuilder} that {@code a} will be appended to + * + * @see Arrays#toString(char[]) + */ + private static void appendArray(char[] a, final StringBuilder str) { + int iMax = a.length - 1; + if (iMax == -1) { + str.append("[]"); + return; + } + + str.append('['); + for (int i = 0; ; i++) { + str.append(a[i]); + if (i == iMax) { + str.append(']'); + return; + } + str.append(", "); + } + } } From 5b4ba2d7a1f74ad260de10fe65ca3c1448e27a9d Mon Sep 17 00:00:00 2001 From: magicwerk Date: Sun, 4 May 2025 16:38:31 +0200 Subject: [PATCH 2/5] Add tests --- .../log4j/message/ParameterFormatterTest.java | 354 +++++++++++------- 1 file changed, 210 insertions(+), 144 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 70194a265b9..f4c11c1f526 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 @@ -23,6 +23,7 @@ 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.status.StatusData; @@ -39,148 +40,213 @@ @UsingStatusListener class ParameterFormatterTest { - final ListStatusListener statusListener; - - ParameterFormatterTest(ListStatusListener statusListener) { - this.statusListener = statusListener; - } - - @ParameterizedTest - @CsvSource({ - "0,,false,", - "0,,false,aaa", - "0,,true,\\{}", - "1,0,false,{}", - "1,0,true,{}\\{}", - "1,2,true,\\\\{}", - "2,8:10,true,foo \\{} {}{}", - "2,8:10,true,foo {\\} {}{}", - "2,0:2,false,{}{}", - "3,0:2:4,false,{}{}{}", - "4,0:2:4:8,false,{}{}{}aa{}", - "4,0:2:4:10,false,{}{}{}a{]b{}", - "5,0:2:4:7:10,false,{}{}{}a{}b{}" - }) - void test_pattern_analysis( - final int placeholderCount, - final String placeholderCharIndicesString, - final boolean escapedPlaceholderFound, - final String pattern) { - MessagePatternAnalysis analysis = ParameterFormatter.analyzePattern(pattern, placeholderCount); - assertThat(analysis.placeholderCount).isEqualTo(placeholderCount); - if (placeholderCount > 0) { - final int[] placeholderCharIndices = Arrays.stream(placeholderCharIndicesString.split(":")) - .mapToInt(Integer::parseInt) - .toArray(); - assertThat(analysis.placeholderCharIndices).startsWith(placeholderCharIndices); - assertThat(analysis.escapedCharFound).isEqualTo(escapedPlaceholderFound); - } - } - - @ParameterizedTest - @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 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 - @MethodSource("messageFormattingTestCases") - void format_should_work( - final String pattern, final Object[] args, final int argCount, final String expectedFormattedMessage) { - final String actualFormattedMessage = ParameterFormatter.format(pattern, args, argCount); - assertThat(actualFormattedMessage).isEqualTo(expectedFormattedMessage); - } - - static Object[][] messageFormattingTestCases() { - return new Object[][] { - new Object[] {"Test message {}{} {}", new Object[] {"a", "b", "c"}, 3, "Test message ab c"}, - new Object[] { - "Test message {} {} {} {} {} {}", - new Object[] {"a", null, "c", null, null, null}, - 6, - "Test message a null c null null null" - }, - new Object[] { - "Test message {}{} {}", - new Object[] {"a", "b", "c", "unnecessary", "superfluous"}, - 5, - "Test message ab c" - }, - new Object[] {"Test message \\{}{} {}", new Object[] {"a", "b", "c"}, 3, "Test message {}a b"}, - new Object[] {"Test message {}{} {}\\", new Object[] {"a", "b", "c"}, 3, "Test message ab c\\"}, - new Object[] {"Test message {}{} {}\\\\", new Object[] {"a", "b", "c"}, 3, "Test message ab c\\"}, - new Object[] {"Test message \\\\{}{} {}", new Object[] {"a", "b", "c"}, 3, "Test message \\ab c"}, - new Object[] {"Test message {}{} {}", new Object[] {"a", "b", "c"}, 3, "Test message ab c"}, - new Object[] { - "Test message {} {} {} {} {} {}", - new Object[] {"a", null, "c", null, null, null}, - 6, - "Test message a null c null null null" - }, - new Object[] { - "Test message {}{} {}", - new Object[] {"a", "b", "c", "unnecessary", "superfluous"}, - 5, - "Test message ab c" - }, - new Object[] {"Test message \\{}{} {}", new Object[] {"a", "b", "c"}, 3, "Test message {}a b"}, - new Object[] {"Test message {}{} {}\\", new Object[] {"a", "b", "c"}, 3, "Test message ab c\\"}, - new Object[] {"Test message {}{} {}\\\\", new Object[] {"a", "b", "c"}, 3, "Test message ab c\\"}, - new Object[] {"Test message \\\\{}{} {}", new Object[] {"a", "b", "c"}, 3, "Test message \\ab c"}, - new Object[] {"foo \\\\\\{} {}", new Object[] {"bar"}, 1, "foo \\{} bar"}, - new Object[] {"missing arg {} {}", new Object[] {1, 2}, 1, "missing arg 1 {}"}, - new Object[] {"foo {\\} {}", new Object[] {"bar"}, 1, "foo {\\} bar"} - }; - } - - @Test - void testDeepToString() { - final List list = new ArrayList<>(); - list.add(1); - // noinspection CollectionAddedToSelf - list.add(list); - list.add(2); - final String actual = ParameterFormatter.deepToString(list); - final String expected = "[1, [..." + ParameterFormatter.identityToString(list) + "...], 2]"; - assertThat(actual).isEqualTo(expected); - } - - @Test - void testDeepToStringUsingNonRecursiveButConsequentObjects() { - final List list = new ArrayList<>(); - final Object item = Collections.singletonList(0); - list.add(1); - list.add(item); - list.add(2); - list.add(item); - list.add(3); - final String actual = ParameterFormatter.deepToString(list); - final String expected = "[1, [0], 2, [0], 3]"; - assertThat(actual).isEqualTo(expected); - } - - @Test - void testIdentityToString() { - final List list = new ArrayList<>(); - list.add(1); - // noinspection CollectionAddedToSelf - list.add(list); - list.add(2); - final String actual = ParameterFormatter.identityToString(list); - final String expected = list.getClass().getName() + "@" + Integer.toHexString(System.identityHashCode(list)); - assertThat(actual).isEqualTo(expected); - } + final ListStatusListener statusListener; + + ParameterFormatterTest(ListStatusListener statusListener) { + this.statusListener = statusListener; + } + + @ParameterizedTest + @CsvSource({ + "0,,false,", + "0,,false,aaa", + "0,,true,\\{}", + "1,0,false,{}", + "1,0,true,{}\\{}", + "1,2,true,\\\\{}", + "2,8:10,true,foo \\{} {}{}", + "2,8:10,true,foo {\\} {}{}", + "2,0:2,false,{}{}", + "3,0:2:4,false,{}{}{}", + "4,0:2:4:8,false,{}{}{}aa{}", + "4,0:2:4:10,false,{}{}{}a{]b{}", + "5,0:2:4:7:10,false,{}{}{}a{}b{}" + }) + void test_pattern_analysis( + final int placeholderCount, + final String placeholderCharIndicesString, + final boolean escapedPlaceholderFound, + final String pattern) { + MessagePatternAnalysis analysis = ParameterFormatter.analyzePattern(pattern, placeholderCount); + assertThat(analysis.placeholderCount).isEqualTo(placeholderCount); + if (placeholderCount > 0) { + final int[] placeholderCharIndices = Arrays.stream(placeholderCharIndicesString.split(":")) + .mapToInt(Integer::parseInt) + .toArray(); + assertThat(analysis.placeholderCharIndices).startsWith(placeholderCharIndices); + assertThat(analysis.escapedCharFound).isEqualTo(escapedPlaceholderFound); + } + } + + @ParameterizedTest + @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 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 + @MethodSource("messageFormattingTestCases") + void format_should_work( + final String pattern, final Object[] args, final int argCount, final String expectedFormattedMessage) { + final String actualFormattedMessage = ParameterFormatter.format(pattern, args, argCount); + assertThat(actualFormattedMessage).isEqualTo(expectedFormattedMessage); + } + + static Object[][] messageFormattingTestCases() { + return new Object[][] { + new Object[] { "Test message {}{} {}", new Object[] { "a", "b", "c" }, 3, "Test message ab c" }, + new Object[] { + "Test message {} {} {} {} {} {}", + new Object[] { "a", null, "c", null, null, null }, + 6, + "Test message a null c null null null" + }, + new Object[] { + "Test message {}{} {}", + new Object[] { "a", "b", "c", "unnecessary", "superfluous" }, + 5, + "Test message ab c" + }, + new Object[] { "Test message \\{}{} {}", new Object[] { "a", "b", "c" }, 3, "Test message {}a b" }, + new Object[] { "Test message {}{} {}\\", new Object[] { "a", "b", "c" }, 3, "Test message ab c\\" }, + new Object[] { "Test message {}{} {}\\\\", new Object[] { "a", "b", "c" }, 3, "Test message ab c\\" }, + new Object[] { "Test message \\\\{}{} {}", new Object[] { "a", "b", "c" }, 3, "Test message \\ab c" }, + new Object[] { "Test message {}{} {}", new Object[] { "a", "b", "c" }, 3, "Test message ab c" }, + new Object[] { + "Test message {} {} {} {} {} {}", + new Object[] { "a", null, "c", null, null, null }, + 6, + "Test message a null c null null null" + }, + new Object[] { + "Test message {}{} {}", + new Object[] { "a", "b", "c", "unnecessary", "superfluous" }, + 5, + "Test message ab c" + }, + new Object[] { "Test message \\{}{} {}", new Object[] { "a", "b", "c" }, 3, "Test message {}a b" }, + new Object[] { "Test message {}{} {}\\", new Object[] { "a", "b", "c" }, 3, "Test message ab c\\" }, + new Object[] { "Test message {}{} {}\\\\", new Object[] { "a", "b", "c" }, 3, "Test message ab c\\" }, + new Object[] { "Test message \\\\{}{} {}", new Object[] { "a", "b", "c" }, 3, "Test message \\ab c" }, + new Object[] { "foo \\\\\\{} {}", new Object[] { "bar" }, 1, "foo \\{} bar" }, + new Object[] { "missing arg {} {}", new Object[] { 1, 2 }, 1, "missing arg 1 {}" }, + new Object[] { "foo {\\} {}", new Object[] { "bar" }, 1, "foo {\\} bar" } + }; + } + + @Test + void testDeepToString() { + final List list = new ArrayList<>(); + list.add(1); + // noinspection CollectionAddedToSelf + list.add(list); + list.add(2); + final String actual = ParameterFormatter.deepToString(list); + final String expected = "[1, [..." + ParameterFormatter.identityToString(list) + "...], 2]"; + assertThat(actual).isEqualTo(expected); + } + + @Test + void testDeepToStringUsingNonRecursiveButConsequentObjects() { + final List list = new ArrayList<>(); + final Object item = Collections.singletonList(0); + list.add(1); + list.add(item); + list.add(2); + list.add(item); + list.add(3); + final String actual = ParameterFormatter.deepToString(list); + final String expected = "[1, [0], 2, [0], 3]"; + assertThat(actual).isEqualTo(expected); + } + + @Test + void testIdentityToString() { + final List list = new ArrayList<>(); + list.add(1); + // noinspection CollectionAddedToSelf + list.add(list); + list.add(2); + final String actual = ParameterFormatter.identityToString(list); + final String expected = list.getClass().getName() + "@" + Integer.toHexString(System.identityHashCode(list)); + assertThat(actual).isEqualTo(expected); + } + + @Test + void testDeepToStringArrayByte() { + final byte[] array = new byte[] { 0, 1, 2, 3, 4 }; + final String actual = ParameterFormatter.deepToString(array); + final String expected = "[0, 1, 2, 3, 4]"; + assertThat(actual).isEqualTo(expected); + } + + @Test + void testDeepToStringArrayShort() { + final short[] array = new short[] { 0, 1, 2, 3, 4 }; + final String actual = ParameterFormatter.deepToString(array); + final String expected = "[0, 1, 2, 3, 4]"; + assertThat(actual).isEqualTo(expected); + } + + @Test + void testDeepToStringArrayInt() { + final int[] array = new int[] { 0, 1, 2, 3, 4 }; + final String actual = ParameterFormatter.deepToString(array); + final String expected = "[0, 1, 2, 3, 4]"; + assertThat(actual).isEqualTo(expected); + } + + @Test + void testDeepToStringArrayLong() { + final long[] array = new long[] { 0, 1, 2, 3, 4 }; + final String actual = ParameterFormatter.deepToString(array); + final String expected = "[0, 1, 2, 3, 4]"; + assertThat(actual).isEqualTo(expected); + } + + @Test + void testDeepToStringArrayFloat() { + final float[] array = new float[] { 0, 1, 2, 3, 4 }; + final String actual = ParameterFormatter.deepToString(array); + final String expected = "[0.0, 1.0, 2.0, 3.0, 4.0]"; + assertThat(actual).isEqualTo(expected); + } + + @Test + void testDeepToStringArrayDouble() { + final double[] array = new double[] { 0, 1, 2, 3, 4 }; + final String actual = ParameterFormatter.deepToString(array); + final String expected = "[0.0, 1.0, 2.0, 3.0, 4.0]"; + assertThat(actual).isEqualTo(expected); + } + + @Test + void testDeepToStringArrayBoolean() { + final boolean[] array = new boolean[] { false, true }; + final String actual = ParameterFormatter.deepToString(array); + final String expected = "[false, true]"; + assertThat(actual).isEqualTo(expected); + } + + @Test + void testDeepToStringArrayChar() { + final char[] array = new char[] { 'a', 'b', 'c' }; + final String actual = ParameterFormatter.deepToString(array); + final String expected = "[a, b, c]"; + assertThat(actual).isEqualTo(expected); + } + } From e1b6f15471c930fc75b982177bace9a165c94690 Mon Sep 17 00:00:00 2001 From: magicwerk Date: Sun, 4 May 2025 16:58:37 +0200 Subject: [PATCH 3/5] fix formatting --- .../log4j/message/ParameterFormatterTest.java | 402 +++++++++--------- 1 file changed, 192 insertions(+), 210 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 f4c11c1f526..29b6f61f5d8 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 @@ -23,7 +23,6 @@ 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.status.StatusData; @@ -40,213 +39,196 @@ @UsingStatusListener class ParameterFormatterTest { - final ListStatusListener statusListener; - - ParameterFormatterTest(ListStatusListener statusListener) { - this.statusListener = statusListener; - } - - @ParameterizedTest - @CsvSource({ - "0,,false,", - "0,,false,aaa", - "0,,true,\\{}", - "1,0,false,{}", - "1,0,true,{}\\{}", - "1,2,true,\\\\{}", - "2,8:10,true,foo \\{} {}{}", - "2,8:10,true,foo {\\} {}{}", - "2,0:2,false,{}{}", - "3,0:2:4,false,{}{}{}", - "4,0:2:4:8,false,{}{}{}aa{}", - "4,0:2:4:10,false,{}{}{}a{]b{}", - "5,0:2:4:7:10,false,{}{}{}a{}b{}" - }) - void test_pattern_analysis( - final int placeholderCount, - final String placeholderCharIndicesString, - final boolean escapedPlaceholderFound, - final String pattern) { - MessagePatternAnalysis analysis = ParameterFormatter.analyzePattern(pattern, placeholderCount); - assertThat(analysis.placeholderCount).isEqualTo(placeholderCount); - if (placeholderCount > 0) { - final int[] placeholderCharIndices = Arrays.stream(placeholderCharIndicesString.split(":")) - .mapToInt(Integer::parseInt) - .toArray(); - assertThat(analysis.placeholderCharIndices).startsWith(placeholderCharIndices); - assertThat(analysis.escapedCharFound).isEqualTo(escapedPlaceholderFound); - } - } - - @ParameterizedTest - @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 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 - @MethodSource("messageFormattingTestCases") - void format_should_work( - final String pattern, final Object[] args, final int argCount, final String expectedFormattedMessage) { - final String actualFormattedMessage = ParameterFormatter.format(pattern, args, argCount); - assertThat(actualFormattedMessage).isEqualTo(expectedFormattedMessage); - } - - static Object[][] messageFormattingTestCases() { - return new Object[][] { - new Object[] { "Test message {}{} {}", new Object[] { "a", "b", "c" }, 3, "Test message ab c" }, - new Object[] { - "Test message {} {} {} {} {} {}", - new Object[] { "a", null, "c", null, null, null }, - 6, - "Test message a null c null null null" - }, - new Object[] { - "Test message {}{} {}", - new Object[] { "a", "b", "c", "unnecessary", "superfluous" }, - 5, - "Test message ab c" - }, - new Object[] { "Test message \\{}{} {}", new Object[] { "a", "b", "c" }, 3, "Test message {}a b" }, - new Object[] { "Test message {}{} {}\\", new Object[] { "a", "b", "c" }, 3, "Test message ab c\\" }, - new Object[] { "Test message {}{} {}\\\\", new Object[] { "a", "b", "c" }, 3, "Test message ab c\\" }, - new Object[] { "Test message \\\\{}{} {}", new Object[] { "a", "b", "c" }, 3, "Test message \\ab c" }, - new Object[] { "Test message {}{} {}", new Object[] { "a", "b", "c" }, 3, "Test message ab c" }, - new Object[] { - "Test message {} {} {} {} {} {}", - new Object[] { "a", null, "c", null, null, null }, - 6, - "Test message a null c null null null" - }, - new Object[] { - "Test message {}{} {}", - new Object[] { "a", "b", "c", "unnecessary", "superfluous" }, - 5, - "Test message ab c" - }, - new Object[] { "Test message \\{}{} {}", new Object[] { "a", "b", "c" }, 3, "Test message {}a b" }, - new Object[] { "Test message {}{} {}\\", new Object[] { "a", "b", "c" }, 3, "Test message ab c\\" }, - new Object[] { "Test message {}{} {}\\\\", new Object[] { "a", "b", "c" }, 3, "Test message ab c\\" }, - new Object[] { "Test message \\\\{}{} {}", new Object[] { "a", "b", "c" }, 3, "Test message \\ab c" }, - new Object[] { "foo \\\\\\{} {}", new Object[] { "bar" }, 1, "foo \\{} bar" }, - new Object[] { "missing arg {} {}", new Object[] { 1, 2 }, 1, "missing arg 1 {}" }, - new Object[] { "foo {\\} {}", new Object[] { "bar" }, 1, "foo {\\} bar" } - }; - } - - @Test - void testDeepToString() { - final List list = new ArrayList<>(); - list.add(1); - // noinspection CollectionAddedToSelf - list.add(list); - list.add(2); - final String actual = ParameterFormatter.deepToString(list); - final String expected = "[1, [..." + ParameterFormatter.identityToString(list) + "...], 2]"; - assertThat(actual).isEqualTo(expected); - } - - @Test - void testDeepToStringUsingNonRecursiveButConsequentObjects() { - final List list = new ArrayList<>(); - final Object item = Collections.singletonList(0); - list.add(1); - list.add(item); - list.add(2); - list.add(item); - list.add(3); - final String actual = ParameterFormatter.deepToString(list); - final String expected = "[1, [0], 2, [0], 3]"; - assertThat(actual).isEqualTo(expected); - } - - @Test - void testIdentityToString() { - final List list = new ArrayList<>(); - list.add(1); - // noinspection CollectionAddedToSelf - list.add(list); - list.add(2); - final String actual = ParameterFormatter.identityToString(list); - final String expected = list.getClass().getName() + "@" + Integer.toHexString(System.identityHashCode(list)); - assertThat(actual).isEqualTo(expected); - } - - @Test - void testDeepToStringArrayByte() { - final byte[] array = new byte[] { 0, 1, 2, 3, 4 }; - final String actual = ParameterFormatter.deepToString(array); - final String expected = "[0, 1, 2, 3, 4]"; - assertThat(actual).isEqualTo(expected); - } - - @Test - void testDeepToStringArrayShort() { - final short[] array = new short[] { 0, 1, 2, 3, 4 }; - final String actual = ParameterFormatter.deepToString(array); - final String expected = "[0, 1, 2, 3, 4]"; - assertThat(actual).isEqualTo(expected); - } - - @Test - void testDeepToStringArrayInt() { - final int[] array = new int[] { 0, 1, 2, 3, 4 }; - final String actual = ParameterFormatter.deepToString(array); - final String expected = "[0, 1, 2, 3, 4]"; - assertThat(actual).isEqualTo(expected); - } - - @Test - void testDeepToStringArrayLong() { - final long[] array = new long[] { 0, 1, 2, 3, 4 }; - final String actual = ParameterFormatter.deepToString(array); - final String expected = "[0, 1, 2, 3, 4]"; - assertThat(actual).isEqualTo(expected); - } - - @Test - void testDeepToStringArrayFloat() { - final float[] array = new float[] { 0, 1, 2, 3, 4 }; - final String actual = ParameterFormatter.deepToString(array); - final String expected = "[0.0, 1.0, 2.0, 3.0, 4.0]"; - assertThat(actual).isEqualTo(expected); - } - - @Test - void testDeepToStringArrayDouble() { - final double[] array = new double[] { 0, 1, 2, 3, 4 }; - final String actual = ParameterFormatter.deepToString(array); - final String expected = "[0.0, 1.0, 2.0, 3.0, 4.0]"; - assertThat(actual).isEqualTo(expected); - } - - @Test - void testDeepToStringArrayBoolean() { - final boolean[] array = new boolean[] { false, true }; - final String actual = ParameterFormatter.deepToString(array); - final String expected = "[false, true]"; - assertThat(actual).isEqualTo(expected); - } - - @Test - void testDeepToStringArrayChar() { - final char[] array = new char[] { 'a', 'b', 'c' }; - final String actual = ParameterFormatter.deepToString(array); - final String expected = "[a, b, c]"; - assertThat(actual).isEqualTo(expected); - } - + final ListStatusListener statusListener; + + ParameterFormatterTest(ListStatusListener statusListener) { + this.statusListener = statusListener; + } + + @ParameterizedTest + @CsvSource({ + "0,,false,", + "0,,false,aaa", + "0,,true,\\{}", + "1,0,false,{}", + "1,0,true,{}\\{}", + "1,2,true,\\\\{}", + "2,8:10,true,foo \\{} {}{}", + "2,8:10,true,foo {\\} {}{}", + "2,0:2,false,{}{}", + "3,0:2:4,false,{}{}{}", + "4,0:2:4:8,false,{}{}{}aa{}", + "4,0:2:4:10,false,{}{}{}a{]b{}", + "5,0:2:4:7:10,false,{}{}{}a{}b{}" + }) + void test_pattern_analysis( + final int placeholderCount, + final String placeholderCharIndicesString, + final boolean escapedPlaceholderFound, + final String pattern) { + MessagePatternAnalysis analysis = ParameterFormatter.analyzePattern(pattern, placeholderCount); + assertThat(analysis.placeholderCount).isEqualTo(placeholderCount); + if (placeholderCount > 0) { + final int[] placeholderCharIndices = Arrays.stream(placeholderCharIndicesString.split(":")) + .mapToInt(Integer::parseInt) + .toArray(); + assertThat(analysis.placeholderCharIndices).startsWith(placeholderCharIndices); + assertThat(analysis.escapedCharFound).isEqualTo(escapedPlaceholderFound); + } + } + + @ParameterizedTest + @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 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 + @MethodSource("messageFormattingTestCases") + void format_should_work( + final String pattern, final Object[] args, final int argCount, final String expectedFormattedMessage) { + final String actualFormattedMessage = ParameterFormatter.format(pattern, args, argCount); + assertThat(actualFormattedMessage).isEqualTo(expectedFormattedMessage); + } + + static Object[][] messageFormattingTestCases() { + return new Object[][] { + new Object[] {"Test message {}{} {}", new Object[] {"a", "b", "c"}, 3, "Test message ab c"}, + new Object[] { + "Test message {} {} {} {} {} {}", + new Object[] {"a", null, "c", null, null, null}, + 6, + "Test message a null c null null null" + }, + new Object[] { + "Test message {}{} {}", + new Object[] {"a", "b", "c", "unnecessary", "superfluous"}, + 5, + "Test message ab c" + }, + new Object[] {"Test message \\{}{} {}", new Object[] {"a", "b", "c"}, 3, "Test message {}a b"}, + new Object[] {"Test message {}{} {}\\", new Object[] {"a", "b", "c"}, 3, "Test message ab c\\"}, + new Object[] {"Test message {}{} {}\\\\", new Object[] {"a", "b", "c"}, 3, "Test message ab c\\"}, + new Object[] {"Test message \\\\{}{} {}", new Object[] {"a", "b", "c"}, 3, "Test message \\ab c"}, + new Object[] {"Test message {}{} {}", new Object[] {"a", "b", "c"}, 3, "Test message ab c"}, + new Object[] { + "Test message {} {} {} {} {} {}", + new Object[] {"a", null, "c", null, null, null}, + 6, + "Test message a null c null null null" + }, + new Object[] { + "Test message {}{} {}", + new Object[] {"a", "b", "c", "unnecessary", "superfluous"}, + 5, + "Test message ab c" + }, + new Object[] {"Test message \\{}{} {}", new Object[] {"a", "b", "c"}, 3, "Test message {}a b"}, + new Object[] {"Test message {}{} {}\\", new Object[] {"a", "b", "c"}, 3, "Test message ab c\\"}, + new Object[] {"Test message {}{} {}\\\\", new Object[] {"a", "b", "c"}, 3, "Test message ab c\\"}, + new Object[] {"Test message \\\\{}{} {}", new Object[] {"a", "b", "c"}, 3, "Test message \\ab c"}, + new Object[] {"foo \\\\\\{} {}", new Object[] {"bar"}, 1, "foo \\{} bar"}, + new Object[] {"missing arg {} {}", new Object[] {1, 2}, 1, "missing arg 1 {}"}, + new Object[] {"foo {\\} {}", new Object[] {"bar"}, 1, "foo {\\} bar"} + }; + } + + @Test + void testDeepToString() { + final List list = new ArrayList<>(); + list.add(1); + // noinspection CollectionAddedToSelf + list.add(list); + list.add(2); + final String actual = ParameterFormatter.deepToString(list); + final String expected = "[1, [..." + ParameterFormatter.identityToString(list) + "...], 2]"; + assertThat(actual).isEqualTo(expected); + } + + @Test + void testDeepToStringUsingNonRecursiveButConsequentObjects() { + final List list = new ArrayList<>(); + final Object item = Collections.singletonList(0); + list.add(1); + list.add(item); + list.add(2); + list.add(item); + list.add(3); + final String actual = ParameterFormatter.deepToString(list); + final String expected = "[1, [0], 2, [0], 3]"; + assertThat(actual).isEqualTo(expected); + } + + @Test + void testIdentityToString() { + final List list = new ArrayList<>(); + list.add(1); + // noinspection CollectionAddedToSelf + list.add(list); + list.add(2); + final String actual = ParameterFormatter.identityToString(list); + final String expected = list.getClass().getName() + "@" + Integer.toHexString(System.identityHashCode(list)); + assertThat(actual).isEqualTo(expected); + } + + @Test + void testDeepToStringArrayInt() { + final int[] array = new int[] {0, 1, 2, 3, 4}; + final String actual = ParameterFormatter.deepToString(array); + final String expected = "[0, 1, 2, 3, 4]"; + assertThat(actual).isEqualTo(expected); + } + + @Test + void testDeepToStringArrayLong() { + final long[] array = new long[] {0, 1, 2, 3, 4}; + final String actual = ParameterFormatter.deepToString(array); + final String expected = "[0, 1, 2, 3, 4]"; + assertThat(actual).isEqualTo(expected); + } + + @Test + void testDeepToStringArrayFloat() { + final float[] array = new float[] {0, 1, 2, 3, 4}; + final String actual = ParameterFormatter.deepToString(array); + final String expected = "[0.0, 1.0, 2.0, 3.0, 4.0]"; + assertThat(actual).isEqualTo(expected); + } + + @Test + void testDeepToStringArrayDouble() { + final double[] array = new double[] {0, 1, 2, 3, 4}; + final String actual = ParameterFormatter.deepToString(array); + final String expected = "[0.0, 1.0, 2.0, 3.0, 4.0]"; + assertThat(actual).isEqualTo(expected); + } + + @Test + void testDeepToStringArrayBoolean() { + final boolean[] array = new boolean[] {false, true}; + final String actual = ParameterFormatter.deepToString(array); + final String expected = "[false, true]"; + assertThat(actual).isEqualTo(expected); + } + + @Test + void testDeepToStringArrayChar() { + final char[] array = new char[] {'a', 'b', 'c'}; + final String actual = ParameterFormatter.deepToString(array); + final String expected = "[a, b, c]"; + assertThat(actual).isEqualTo(expected); + } } From 3494eb466bba3325fa60d6ea86f19f21e96df5a1 Mon Sep 17 00:00:00 2001 From: magicwerk Date: Mon, 5 May 2025 23:58:36 +0200 Subject: [PATCH 4/5] implement review comments --- .../log4j/message/ParameterFormatterTest.java | 83 +++------ .../log4j/message/ParameterFormatter.java | 176 +++++------------- .../message/ParameterFormatterBenchmark.java | 52 +++++- 3 files changed, 126 insertions(+), 185 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 29b6f61f5d8..e4988f41417 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 @@ -23,6 +23,7 @@ import java.util.Collections; import java.util.List; import java.util.stream.Collectors; +import java.util.stream.Stream; import org.apache.logging.log4j.Level; import org.apache.logging.log4j.message.ParameterFormatter.MessagePatternAnalysis; import org.apache.logging.log4j.status.StatusData; @@ -30,6 +31,7 @@ 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.Arguments; import org.junit.jupiter.params.provider.CsvSource; import org.junit.jupiter.params.provider.MethodSource; @@ -146,6 +148,18 @@ static Object[][] messageFormattingTestCases() { }; } + @Test + void testIdentityToString() { + final List list = new ArrayList<>(); + list.add(1); + // noinspection CollectionAddedToSelf + list.add(list); + list.add(2); + final String actual = ParameterFormatter.identityToString(list); + final String expected = list.getClass().getName() + "@" + Integer.toHexString(System.identityHashCode(list)); + assertThat(actual).isEqualTo(expected); + } + @Test void testDeepToString() { final List list = new ArrayList<>(); @@ -172,63 +186,22 @@ void testDeepToStringUsingNonRecursiveButConsequentObjects() { assertThat(actual).isEqualTo(expected); } - @Test - void testIdentityToString() { - final List list = new ArrayList<>(); - list.add(1); - // noinspection CollectionAddedToSelf - list.add(list); - list.add(2); - final String actual = ParameterFormatter.identityToString(list); - final String expected = list.getClass().getName() + "@" + Integer.toHexString(System.identityHashCode(list)); - assertThat(actual).isEqualTo(expected); - } - - @Test - void testDeepToStringArrayInt() { - final int[] array = new int[] {0, 1, 2, 3, 4}; - final String actual = ParameterFormatter.deepToString(array); - final String expected = "[0, 1, 2, 3, 4]"; - assertThat(actual).isEqualTo(expected); - } - - @Test - void testDeepToStringArrayLong() { - final long[] array = new long[] {0, 1, 2, 3, 4}; - final String actual = ParameterFormatter.deepToString(array); - final String expected = "[0, 1, 2, 3, 4]"; - assertThat(actual).isEqualTo(expected); - } - - @Test - void testDeepToStringArrayFloat() { - final float[] array = new float[] {0, 1, 2, 3, 4}; - final String actual = ParameterFormatter.deepToString(array); - final String expected = "[0.0, 1.0, 2.0, 3.0, 4.0]"; - assertThat(actual).isEqualTo(expected); - } - - @Test - void testDeepToStringArrayDouble() { - final double[] array = new double[] {0, 1, 2, 3, 4}; - final String actual = ParameterFormatter.deepToString(array); - final String expected = "[0.0, 1.0, 2.0, 3.0, 4.0]"; - assertThat(actual).isEqualTo(expected); - } - - @Test - void testDeepToStringArrayBoolean() { - final boolean[] array = new boolean[] {false, true}; - final String actual = ParameterFormatter.deepToString(array); - final String expected = "[false, true]"; + @ParameterizedTest + @MethodSource("deepToStringArgumentsPrimitiveArrays") + void testDeepToStringPrimitiveArrays(Object obj, String expected) { + final String actual = ParameterFormatter.deepToString(obj); assertThat(actual).isEqualTo(expected); } - @Test - void testDeepToStringArrayChar() { - final char[] array = new char[] {'a', 'b', 'c'}; - final String actual = ParameterFormatter.deepToString(array); - final String expected = "[a, b, c]"; - assertThat(actual).isEqualTo(expected); + static Stream deepToStringArgumentsPrimitiveArrays() { + return Stream.of( + Arguments.of(new byte[] {0, 1, 2, 3, 4}, "[0, 1, 2, 3, 4]"), + Arguments.of(new short[] {0, 1, 2, 3, 4}, "[0, 1, 2, 3, 4]"), + Arguments.of(new int[] {0, 1, 2, 3, 4}, "[0, 1, 2, 3, 4]"), + Arguments.of(new long[] {0, 1, 2, 3, 4}, "[0, 1, 2, 3, 4]"), + Arguments.of(new float[] {0, 1, 2, 3, 4}, "[0.0, 1.0, 2.0, 3.0, 4.0]"), + Arguments.of(new double[] {0, 1, 2, 3, 4}, "[0.0, 1.0, 2.0, 3.0, 4.0]"), + Arguments.of(new char[] {'a', 'b', 'c'}, "[a, b, c]"), + Arguments.of(new boolean[] {false, true}, "[false, true]")); } } 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 a9cada2a03b..502f5d09ce2 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 @@ -645,210 +645,130 @@ static String identityToString(final Object obj) { } /** - * Adds a string representation of the contents of the specified array to the buffer. - * - * @param a the array to convert (not null) - * @param str the {@code StringBuilder} that {@code a} will be appended to - * * @see Arrays#toString(byte[]) */ private static void appendArray(final byte[] a, final StringBuilder str) { - int iMax = a.length - 1; - if (iMax == -1) { + int len = a.length; + if (len == 0) { str.append("[]"); return; } - - str.append('['); - for (int i = 0; ; i++) { - str.append(a[i]); - if (i == iMax) { - str.append(']'); - return; - } - str.append(", "); + str.append('[').append(a[0]); + for (int i = 1; i < len; i++) { + str.append(", ").append(a[i]); } + str.append(']'); } /** - * Adds a string representation of the contents of the specified array to the buffer. - * - * @param a the array to convert (not null) - * @param str the {@code StringBuilder} that {@code a} will be appended to - * * @see Arrays#toString(short[]) */ private static void appendArray(final short[] a, final StringBuilder str) { - int iMax = a.length - 1; - if (iMax == -1) { + int len = a.length; + if (len == 0) { str.append("[]"); return; } - - str.append('['); - for (int i = 0; ; i++) { - str.append(a[i]); - if (i == iMax) { - str.append(']'); - return; - } - str.append(", "); + str.append('[').append(a[0]); + for (int i = 1; i < len; i++) { + str.append(", ").append(a[i]); } + str.append(']'); } /** - * Adds a string representation of the contents of the specified array to the buffer. - * - * @param a the array to convert (not null) - * @param str the {@code StringBuilder} that {@code a} will be appended to - * * @see Arrays#toString(int[]) */ private static void appendArray(final int[] a, final StringBuilder str) { - int iMax = a.length - 1; - if (iMax == -1) { + int len = a.length; + if (len == 0) { str.append("[]"); return; } - - str.append('['); - for (int i = 0; ; i++) { - str.append(a[i]); - if (i == iMax) { - str.append(']'); - return; - } - str.append(", "); + str.append('[').append(a[0]); + for (int i = 1; i < len; i++) { + str.append(", ").append(a[i]); } + str.append(']'); } /** - * Adds a string representation of the contents of the specified array to the buffer. - * - * @param a the array to convert (not null) - * @param str the {@code StringBuilder} that {@code a} will be appended to - * * @see Arrays#toString(long[]) */ private static void appendArray(final long[] a, final StringBuilder str) { - int iMax = a.length - 1; - if (iMax == -1) { + int len = a.length; + if (len == 0) { str.append("[]"); return; } - - str.append('['); - for (int i = 0; ; i++) { - str.append(a[i]); - if (i == iMax) { - str.append(']'); - return; - } - str.append(", "); + str.append('[').append(a[0]); + for (int i = 1; i < len; i++) { + str.append(", ").append(a[i]); } + str.append(']'); } /** - * Adds a string representation of the contents of the specified array to the buffer. - * - * @param a the array to convert (not null) - * @param str the {@code StringBuilder} that {@code a} will be appended to - * * @see Arrays#toString(float[]) */ private static void appendArray(final float[] a, final StringBuilder str) { - int iMax = a.length - 1; - if (iMax == -1) { + int len = a.length; + if (len == 0) { str.append("[]"); return; } - - str.append('['); - for (int i = 0; ; i++) { - str.append(a[i]); - if (i == iMax) { - str.append(']'); - return; - } - str.append(", "); + str.append('[').append(a[0]); + for (int i = 1; i < len; i++) { + str.append(", ").append(a[i]); } + str.append(']'); } /** - * Adds a string representation of the contents of the specified array to the buffer. - * - * @param a the array to convert (not null) - * @param str the {@code StringBuilder} that {@code a} will be appended to - * * @see Arrays#toString(double[]) */ private static void appendArray(final double[] a, final StringBuilder str) { - int iMax = a.length - 1; - if (iMax == -1) { + int len = a.length; + if (len == 0) { str.append("[]"); return; } - - str.append('['); - for (int i = 0; ; i++) { - str.append(a[i]); - if (i == iMax) { - str.append(']'); - return; - } - str.append(", "); + str.append('[').append(a[0]); + for (int i = 1; i < len; i++) { + str.append(", ").append(a[i]); } + str.append(']'); } /** - * Adds a string representation of the contents of the specified array to the buffer. - * - * @param a the array to convert (not null) - * @param str the {@code StringBuilder} that {@code a} will be appended to - * * @see Arrays#toString(boolean[]) */ private static void appendArray(final boolean[] a, final StringBuilder str) { - int iMax = a.length - 1; - if (iMax == -1) { + int len = a.length; + if (len == 0) { str.append("[]"); return; } - - str.append('['); - for (int i = 0; ; i++) { - str.append(a[i]); - if (i == iMax) { - str.append(']'); - return; - } - str.append(", "); + str.append('[').append(a[0]); + for (int i = 1; i < len; i++) { + str.append(", ").append(a[i]); } + str.append(']'); } /** - * Adds a string representation of the contents of the specified array to the buffer. - * - * @param a the array to convert (not null) - * @param str the {@code StringBuilder} that {@code a} will be appended to - * * @see Arrays#toString(char[]) */ private static void appendArray(char[] a, final StringBuilder str) { - int iMax = a.length - 1; - if (iMax == -1) { + int len = a.length; + if (len == 0) { str.append("[]"); return; } - - str.append('['); - for (int i = 0; ; i++) { - str.append(a[i]); - if (i == iMax) { - str.append(']'); - return; - } - str.append(", "); + str.append('[').append(a[0]); + for (int i = 1; i < len; i++) { + str.append(", ").append(a[i]); } + str.append(']'); } } diff --git a/log4j-perf-test/src/main/java/org/apache/logging/log4j/message/ParameterFormatterBenchmark.java b/log4j-perf-test/src/main/java/org/apache/logging/log4j/message/ParameterFormatterBenchmark.java index fce78e8843f..78ba17f0be9 100644 --- a/log4j-perf-test/src/main/java/org/apache/logging/log4j/message/ParameterFormatterBenchmark.java +++ b/log4j-perf-test/src/main/java/org/apache/logging/log4j/message/ParameterFormatterBenchmark.java @@ -16,6 +16,7 @@ */ package org.apache.logging.log4j.message; +import java.util.Arrays; import java.util.concurrent.TimeUnit; import org.apache.logging.log4j.message.ParameterFormatter.MessagePatternAnalysis; import org.openjdk.jmh.annotations.Benchmark; @@ -28,11 +29,24 @@ /** * This benchmark is not in the perf.jmh package because it tests the package-protected ParameterFormatter class. */ +// ============================== HOW TO RUN THIS TEST: ==================================== +// +// single thread: +// java -jar log4j-perf/target/benchmarks.jar ".*ParameterFormatterBench.*" -f 1 -wi 5 -i 10 +// +// multiple threads (for example, 4 threads): +// java -jar log4j-perf/target/benchmarks.jar ".*ParameterFormatterBench.*" -f 1 -wi 5 -i 10 -t 4 -si true +// +// Usage help: +// java -jar log4j-perf/target/benchmarks.jar -help +// @State(Scope.Benchmark) public class ParameterFormatterBenchmark { - private static final Object[] ARGS = { - "arg1", "arg2", "arg3", "arg4", "arg5", "arg6", "arg7", "arg8", "arg9", "arg10" + "arg1", "arg2", "arg3", "arg4", "arg5", "arg6", "arg7", "arg8", "arg9", "arg10", + }; + private static final int[] INT_ARRAY = { + 0, 1, 2, 3, 4, 5, 6, 7, 8, 9, }; @State(Scope.Thread) @@ -81,4 +95,38 @@ private static int latencyParams(final ThreadState state, final String pattern) ParameterFormatter.formatMessage(state.buffer, pattern, ARGS, state.analysis.placeholderCount, state.analysis); return state.buffer.length(); } + + @Benchmark + @BenchmarkMode(Mode.SampleTime) + @OutputTimeUnit(TimeUnit.NANOSECONDS) + public int appendArrayToString(final ThreadState state) { + StringBuilder buffer = state.buffer; + buffer.setLength(0); + buffer.append(Arrays.toString(INT_ARRAY)); + return state.buffer.length(); + } + + @Benchmark + @BenchmarkMode(Mode.SampleTime) + @OutputTimeUnit(TimeUnit.NANOSECONDS) + public int appendArrayStringBuilder(final ThreadState state) { + StringBuilder buffer = state.buffer; + buffer.setLength(0); + appendArray(INT_ARRAY, buffer); + return state.buffer.length(); + } + + // Copied as method is static + private static void appendArray(final int[] a, final StringBuilder str) { + int len = a.length; + if (len == 0) { + str.append("[]"); + return; + } + str.append('[').append(a[0]); + for (int i = 1; i < len; i++) { + str.append(", ").append(a[i]); + } + str.append(']'); + } } From d8f7190474fb14dfad59011f3e8456a2fff0766e Mon Sep 17 00:00:00 2001 From: magicwerk Date: Tue, 6 May 2025 22:14:38 +0200 Subject: [PATCH 5/5] review comments --- .../log4j/message/ParameterFormatter.java | 3 ++- .../message/ParameterFormatterBenchmark.java | 16 +--------------- .../.2.x.x/3645_speedup_array_logging.xml | 10 ++++++++++ 3 files changed, 13 insertions(+), 16 deletions(-) create mode 100644 src/changelog/.2.x.x/3645_speedup_array_logging.xml 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 502f5d09ce2..551f02c7f7b 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 @@ -679,7 +679,8 @@ private static void appendArray(final short[] a, final StringBuilder str) { /** * @see Arrays#toString(int[]) */ - private static void appendArray(final int[] a, final StringBuilder str) { + // package protected to allow access from ParameterFormatterBenchmark + static void appendArray(final int[] a, final StringBuilder str) { int len = a.length; if (len == 0) { str.append("[]"); diff --git a/log4j-perf-test/src/main/java/org/apache/logging/log4j/message/ParameterFormatterBenchmark.java b/log4j-perf-test/src/main/java/org/apache/logging/log4j/message/ParameterFormatterBenchmark.java index 78ba17f0be9..846f3cc2c65 100644 --- a/log4j-perf-test/src/main/java/org/apache/logging/log4j/message/ParameterFormatterBenchmark.java +++ b/log4j-perf-test/src/main/java/org/apache/logging/log4j/message/ParameterFormatterBenchmark.java @@ -112,21 +112,7 @@ public int appendArrayToString(final ThreadState state) { public int appendArrayStringBuilder(final ThreadState state) { StringBuilder buffer = state.buffer; buffer.setLength(0); - appendArray(INT_ARRAY, buffer); + ParameterFormatter.appendArray(INT_ARRAY, buffer); return state.buffer.length(); } - - // Copied as method is static - private static void appendArray(final int[] a, final StringBuilder str) { - int len = a.length; - if (len == 0) { - str.append("[]"); - return; - } - str.append('[').append(a[0]); - for (int i = 1; i < len; i++) { - str.append(", ").append(a[i]); - } - str.append(']'); - } } diff --git a/src/changelog/.2.x.x/3645_speedup_array_logging.xml b/src/changelog/.2.x.x/3645_speedup_array_logging.xml new file mode 100644 index 00000000000..dd1d15b6a48 --- /dev/null +++ b/src/changelog/.2.x.x/3645_speedup_array_logging.xml @@ -0,0 +1,10 @@ + + + + + Improve performance and avoid memory consumption if logging primitive arrays as parameters + +