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
The following commit(s) were added to refs/heads/2.x by this push:
new 3709962553 Improve performance and avoid memory consumption if logging
primitive arrays as parameters (#3645)
3709962553 is described below
commit 3709962553ddc27774163eb77845b0a47a7b9684
Author: magicwerk <[email protected]>
AuthorDate: Tue May 6 23:01:49 2025 +0200
Improve performance and avoid memory consumption if logging primitive
arrays as parameters (#3645)
Current implementation:
Method ParameterFormatter.appendArray() delegats to
java.util.Arrays.toString() which then allocates a new StringBuilder to return
a String which is then added to the existing StringBuilder.
Improved implementation:
For all primitive types, a method like
ParameterFormatter.appendArray(int[], StringBuilder) has been added which is
called by ParameterFormatter.appendArray() and avoids the unnecessary object
creation.
* review comments
---
.../log4j/message/ParameterFormatterTest.java | 39 ++++--
.../logging/log4j/message/ParameterFormatter.java | 149 +++++++++++++++++++--
.../log4j/message/ParameterFormatterBenchmark.java | 38 +++++-
.../.2.x.x/3645_speedup_array_logging.xml | 10 ++
4 files changed, 215 insertions(+), 21 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 70194a265b..e4988f4141 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.Arrays;
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.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.Arguments;
import org.junit.jupiter.params.provider.CsvSource;
import org.junit.jupiter.params.provider.MethodSource;
@@ -146,6 +148,18 @@ class ParameterFormatterTest {
};
}
+ @Test
+ void testIdentityToString() {
+ final List<Object> 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<Object> list = new ArrayList<>();
@@ -172,15 +186,22 @@ class ParameterFormatterTest {
assertThat(actual).isEqualTo(expected);
}
- @Test
- void testIdentityToString() {
- final List<Object> 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));
+ @ParameterizedTest
+ @MethodSource("deepToStringArgumentsPrimitiveArrays")
+ void testDeepToStringPrimitiveArrays(Object obj, String expected) {
+ final String actual = ParameterFormatter.deepToString(obj);
assertThat(actual).isEqualTo(expected);
}
+
+ static Stream<Arguments> 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 0e990894c0..551f02c7f7 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 @@ final class ParameterFormatter {
}
}
- // 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 @@ final class ParameterFormatter {
private static void appendArray(
final Object o, final StringBuilder str, final Set<Object> 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<Object> effectiveDejaVu = getOrCreateDejaVu(dejaVu);
@@ -643,4 +643,133 @@ final class ParameterFormatter {
}
return obj.getClass().getName() + '@' +
Integer.toHexString(System.identityHashCode(obj));
}
+
+ /**
+ * @see Arrays#toString(byte[])
+ */
+ private static void appendArray(final byte[] 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(']');
+ }
+
+ /**
+ * @see Arrays#toString(short[])
+ */
+ private static void appendArray(final short[] 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(']');
+ }
+
+ /**
+ * @see Arrays#toString(int[])
+ */
+ // 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("[]");
+ return;
+ }
+ str.append('[').append(a[0]);
+ for (int i = 1; i < len; i++) {
+ str.append(", ").append(a[i]);
+ }
+ str.append(']');
+ }
+
+ /**
+ * @see Arrays#toString(long[])
+ */
+ private static void appendArray(final long[] 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(']');
+ }
+
+ /**
+ * @see Arrays#toString(float[])
+ */
+ private static void appendArray(final float[] 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(']');
+ }
+
+ /**
+ * @see Arrays#toString(double[])
+ */
+ private static void appendArray(final double[] 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(']');
+ }
+
+ /**
+ * @see Arrays#toString(boolean[])
+ */
+ private static void appendArray(final boolean[] 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(']');
+ }
+
+ /**
+ * @see Arrays#toString(char[])
+ */
+ private static void appendArray(char[] 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/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 fce78e8843..846f3cc2c6 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 @@ import org.openjdk.jmh.annotations.State;
/**
* 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,24 @@ public class ParameterFormatterBenchmark {
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);
+ ParameterFormatter.appendArray(INT_ARRAY, buffer);
+ return state.buffer.length();
+ }
}
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 0000000000..dd1d15b6a4
--- /dev/null
+++ b/src/changelog/.2.x.x/3645_speedup_array_logging.xml
@@ -0,0 +1,10 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<entry xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance";
+ xmlns="https://logging.apache.org/xml/ns";
+ xsi:schemaLocation="https://logging.apache.org/xml/ns
https://logging.apache.org/xml/ns/log4j-changelog-0.xsd";
+ type="fixed">
+ <issue id="3645" link="https://github.com/apache/logging-log4j2/pull/3645"/>
+ <description format="asciidoc">
+ Improve performance and avoid memory consumption if logging primitive
arrays as parameters
+ </description>
+</entry>
