diff --git a/log4j-api-test/src/test/java/org/apache/logging/log4j/message/ParameterizedMessageRecursiveFormattingTestBase.java b/log4j-api-test/src/test/java/org/apache/logging/log4j/message/ParameterizedMessageRecursiveFormattingTestBase.java new file mode 100644 index 00000000000..072696029a7 --- /dev/null +++ b/log4j-api-test/src/test/java/org/apache/logging/log4j/message/ParameterizedMessageRecursiveFormattingTestBase.java @@ -0,0 +1,53 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to you under the Apache License, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package org.apache.logging.log4j.message; + +import static org.assertj.core.api.Assertions.assertThat; + +import org.apache.logging.log4j.util.Constants; +import org.junit.jupiter.api.Test; + +/** + * Tests {@link ParameterizedMessage#getFormattedMessage()} when formatted arguments causes another {@code ParameterizedMessage#getFormattedMessage()} (i.e., recursive) invocation. + */ +abstract class ParameterizedMessageRecursiveFormattingTestBase { + + private final boolean threadLocalsEnabled; + + ParameterizedMessageRecursiveFormattingTestBase(boolean threadLocalsEnabled) { + this.threadLocalsEnabled = threadLocalsEnabled; + } + + @Test + void thread_locals_toggle_should_match() { + assertThat(Constants.ENABLE_THREADLOCALS).isEqualTo(threadLocalsEnabled); + } + + @Test + void recursion_should_not_corrupt_formatting() { + final Object argInvokingParameterizedMessageFormatting = new Object() { + @Override + public String toString() { + return new ParameterizedMessage("bar {}", "baz").getFormattedMessage(); + } + }; + final ParameterizedMessage message = + new ParameterizedMessage("foo {}", argInvokingParameterizedMessageFormatting); + final String actualText = message.getFormattedMessage(); + assertThat(actualText).isEqualTo("foo bar baz"); + } +} diff --git a/log4j-api-test/src/test/java/org/apache/logging/log4j/message/ParameterizedMessageRecursiveFormattingWithThreadLocalsTest.java b/log4j-api-test/src/test/java/org/apache/logging/log4j/message/ParameterizedMessageRecursiveFormattingWithThreadLocalsTest.java new file mode 100644 index 00000000000..6496a5f12f2 --- /dev/null +++ b/log4j-api-test/src/test/java/org/apache/logging/log4j/message/ParameterizedMessageRecursiveFormattingWithThreadLocalsTest.java @@ -0,0 +1,31 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to you under the Apache License, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package org.apache.logging.log4j.message; + +import org.junitpioneer.jupiter.SetSystemProperty; + +/** + * {@link ParameterizedMessageRecursiveFormattingTestBase} subclass with thread locals disabled, i.e, with {@link StringBuilder} recycling. + */ +@SetSystemProperty(key = "log4j2.enable.threadlocals", value = "true") +class ParameterizedMessageRecursiveFormattingWithThreadLocalsTest + extends ParameterizedMessageRecursiveFormattingTestBase { + + ParameterizedMessageRecursiveFormattingWithThreadLocalsTest() { + super(true); + } +} diff --git a/log4j-api-test/src/test/java/org/apache/logging/log4j/message/ParameterizedMessageRecursiveFormattingWithoutThreadLocalsTest.java b/log4j-api-test/src/test/java/org/apache/logging/log4j/message/ParameterizedMessageRecursiveFormattingWithoutThreadLocalsTest.java new file mode 100644 index 00000000000..456d271d872 --- /dev/null +++ b/log4j-api-test/src/test/java/org/apache/logging/log4j/message/ParameterizedMessageRecursiveFormattingWithoutThreadLocalsTest.java @@ -0,0 +1,31 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to you under the Apache License, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package org.apache.logging.log4j.message; + +import org.junitpioneer.jupiter.SetSystemProperty; + +/** + * {@link ParameterizedMessageRecursiveFormattingTestBase} subclass with thread locals disabled, i.e, no {@link StringBuilder} recycling. + */ +@SetSystemProperty(key = "log4j2.enable.threadlocals", value = "false") +class ParameterizedMessageRecursiveFormattingWithoutThreadLocalsTest + extends ParameterizedMessageRecursiveFormattingTestBase { + + ParameterizedMessageRecursiveFormattingWithoutThreadLocalsTest() { + super(false); + } +} 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 db325327b71..4da3642cca1 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 @@ -17,6 +17,7 @@ package org.apache.logging.log4j.message; import static org.apache.logging.log4j.message.ParameterFormatter.analyzePattern; +import static org.apache.logging.log4j.util.StringBuilders.trimToMaxSize; import com.google.errorprone.annotations.InlineMe; import java.io.IOException; @@ -28,7 +29,6 @@ import org.apache.logging.log4j.message.ParameterFormatter.MessagePatternAnalysis; import org.apache.logging.log4j.util.Constants; import org.apache.logging.log4j.util.StringBuilderFormattable; -import org.apache.logging.log4j.util.StringBuilders; import org.apache.logging.log4j.util.internal.SerializationUtil; /** @@ -44,10 +44,6 @@ * {bar * {buzz} * - *

- * This class was originally written for Lilith by Jörn Huxhorn and licensed under the LGPL. - * It has been relicensed here with his permission providing that this attribution remain. - *

*/ public class ParameterizedMessage implements Message, StringBuilderFormattable { @@ -83,9 +79,15 @@ public class ParameterizedMessage implements Message, StringBuilderFormattable { private static final long serialVersionUID = -665975803997290697L; - private static final ThreadLocal STRING_BUILDER_HOLDER = Constants.ENABLE_THREADLOCALS - ? ThreadLocal.withInitial(() -> new StringBuilder(Constants.MAX_REUSABLE_MESSAGE_SIZE)) - : null; + private static final ThreadLocal FORMAT_BUFFER_HOLDER_REF = + Constants.ENABLE_THREADLOCALS ? ThreadLocal.withInitial(FormatBufferHolder::new) : null; + + private static final class FormatBufferHolder { + + private final StringBuilder buffer = new StringBuilder(Constants.MAX_REUSABLE_MESSAGE_SIZE); + + private boolean used = false; + } private final String pattern; @@ -242,17 +244,26 @@ public Throwable getThrowable() { @Override public String getFormattedMessage() { if (formattedMessage == null) { - if (STRING_BUILDER_HOLDER != null) { - final StringBuilder buffer = STRING_BUILDER_HOLDER.get(); - buffer.setLength(0); - formatTo(buffer); - formattedMessage = buffer.toString(); - StringBuilders.trimToMaxSize(buffer, Constants.MAX_REUSABLE_MESSAGE_SIZE); - } else { - final StringBuilder buffer = new StringBuilder(); + final FormatBufferHolder bufferHolder; + // If there isn't a format buffer to reuse + if (FORMAT_BUFFER_HOLDER_REF == null || (bufferHolder = FORMAT_BUFFER_HOLDER_REF.get()).used) { + final StringBuilder buffer = new StringBuilder(Constants.MAX_REUSABLE_MESSAGE_SIZE); formatTo(buffer); formattedMessage = buffer.toString(); } + // If there is a format buffer to reuse + else { + bufferHolder.used = true; + final StringBuilder buffer = bufferHolder.buffer; + try { + formatTo(buffer); + formattedMessage = buffer.toString(); + } finally { + trimToMaxSize(buffer, Constants.MAX_REUSABLE_MESSAGE_SIZE); + buffer.setLength(0); + bufferHolder.used = false; + } + } } return formattedMessage; } @@ -355,26 +366,28 @@ public static String identityToString(final Object obj) { @Override public String toString() { - return "ParameterizedMessage[messagePattern=" + pattern + ", stringArgs=" + Arrays.toString(args) - + ", throwable=" + throwable + ']'; + // Avoid formatting arguments! + // It can cause recursion, which can become pretty unpleasant while troubleshooting. + return "ParameterizedMessage[messagePattern=" + pattern + ", argCount=" + args.length + ", throwableProvided=" + + (throwable != null) + ']'; } private void writeObject(final ObjectOutputStream out) throws IOException { out.defaultWriteObject(); out.writeInt(args.length); - for (int i = 0; i < args.length; i++) { - SerializationUtil.writeWrappedObject( - args[i] instanceof Serializable ? (Serializable) args[i] : String.valueOf(args[i]), out); + for (final Object arg : args) { + final Serializable serializableArg = arg instanceof Serializable ? (Serializable) arg : String.valueOf(arg); + SerializationUtil.writeWrappedObject(serializableArg, out); } } private void readObject(final ObjectInputStream in) throws IOException, ClassNotFoundException { SerializationUtil.assertFiltered(in); in.defaultReadObject(); - final int length = in.readInt(); - args = new Object[length]; - for (int i = 0; i < args.length; i++) { - args[i] = SerializationUtil.readWrappedObject(in); + final int argCount = in.readInt(); + args = new Object[argCount]; + for (int argIndex = 0; argIndex < args.length; argIndex++) { + args[argIndex] = SerializationUtil.readWrappedObject(in); } } } diff --git a/log4j-api/src/main/java/org/apache/logging/log4j/message/ReusableParameterizedMessage.java b/log4j-api/src/main/java/org/apache/logging/log4j/message/ReusableParameterizedMessage.java index b9b73a6d007..d55b98ae700 100644 --- a/log4j-api/src/main/java/org/apache/logging/log4j/message/ReusableParameterizedMessage.java +++ b/log4j-api/src/main/java/org/apache/logging/log4j/message/ReusableParameterizedMessage.java @@ -16,11 +16,12 @@ */ package org.apache.logging.log4j.message; +import static org.apache.logging.log4j.util.StringBuilders.trimToMaxSize; + import java.util.Arrays; import org.apache.logging.log4j.message.ParameterFormatter.MessagePatternAnalysis; import org.apache.logging.log4j.util.Constants; import org.apache.logging.log4j.util.PerformanceSensitive; -import org.apache.logging.log4j.util.StringBuilders; /** * Reusable parameterized message. This message is mutable and is not safe to be accessed or modified by multiple @@ -32,13 +33,12 @@ @PerformanceSensitive("allocation") public class ReusableParameterizedMessage implements ReusableMessage, ParameterVisitable, Clearable { - private static final int MIN_BUILDER_SIZE = 512; private static final int MAX_PARAMS = 10; private static final long serialVersionUID = 7800075879295123856L; - private transient ThreadLocal buffer; // non-static: LOG4J2-1583 private String messagePattern; private final MessagePatternAnalysis patternAnalysis = new MessagePatternAnalysis(); + private final StringBuilder formatBuffer = new StringBuilder(Constants.MAX_REUSABLE_MESSAGE_SIZE); private int argCount; private transient Object[] varargs; private transient Object[] params = new Object[MAX_PARAMS]; @@ -336,25 +336,13 @@ public Throwable getThrowable() { */ @Override public String getFormattedMessage() { - final StringBuilder sb = getBuffer(); - formatTo(sb); - final String result = sb.toString(); - StringBuilders.trimToMaxSize(sb, Constants.MAX_REUSABLE_MESSAGE_SIZE); - return result; - } - - private StringBuilder getBuffer() { - if (buffer == null) { - buffer = new ThreadLocal<>(); - } - StringBuilder result = buffer.get(); - if (result == null) { - final int currentPatternLength = messagePattern == null ? 0 : messagePattern.length(); - result = new StringBuilder(Math.max(MIN_BUILDER_SIZE, currentPatternLength * 2)); - buffer.set(result); + try { + formatTo(formatBuffer); + return formatBuffer.toString(); + } finally { + trimToMaxSize(formatBuffer, Constants.MAX_REUSABLE_MESSAGE_SIZE); + formatBuffer.setLength(0); } - result.setLength(0); - return result; } @Override @@ -374,8 +362,10 @@ ReusableParameterizedMessage reserve() { @Override public String toString() { - return "ReusableParameterizedMessage[messagePattern=" + getFormat() + ", stringArgs=" - + Arrays.toString(getParameters()) + ", throwable=" + getThrowable() + ']'; + // Avoid formatting arguments! + // It can cause recursion, which can become pretty unpleasant while troubleshooting. + return "ReusableParameterizedMessage[messagePattern=" + getFormat() + ", argCount=" + getParameterCount() + + ", throwableProvided=" + (getThrowable() != null) + ']'; } @Override diff --git a/log4j-api/src/main/java/org/apache/logging/log4j/util/Strings.java b/log4j-api/src/main/java/org/apache/logging/log4j/util/Strings.java index a1a5bb1aab8..bee54324f44 100644 --- a/log4j-api/src/main/java/org/apache/logging/log4j/util/Strings.java +++ b/log4j-api/src/main/java/org/apache/logging/log4j/util/Strings.java @@ -16,6 +16,8 @@ */ package org.apache.logging.log4j.util; +import static org.apache.logging.log4j.util.StringBuilders.trimToMaxSize; + import java.util.Iterator; import java.util.Locale; import java.util.Objects; @@ -28,7 +30,11 @@ @InternalApi public final class Strings { - private static final ThreadLocal tempStr = ThreadLocal.withInitial(StringBuilder::new); + // 518 allows the `StringBuilder` to resize three times from its initial size. + // This should be sufficient for most use cases. + private static final int MAX_FORMAT_BUFFER_LENGTH = 518; + + private static final ThreadLocal FORMAT_BUFFER_REF = ThreadLocal.withInitial(StringBuilder::new); /** * The empty string. @@ -318,10 +324,11 @@ public static String concat(final String str1, final String str2) { } else if (isEmpty(str2)) { return str1; } - final StringBuilder sb = tempStr.get(); + final StringBuilder sb = FORMAT_BUFFER_REF.get(); try { return sb.append(str1).append(str2).toString(); } finally { + trimToMaxSize(sb, MAX_FORMAT_BUFFER_LENGTH); sb.setLength(0); } } @@ -338,13 +345,14 @@ public static String repeat(final String str, final int count) { if (count < 0) { throw new IllegalArgumentException("count"); } - final StringBuilder sb = tempStr.get(); + final StringBuilder sb = FORMAT_BUFFER_REF.get(); try { for (int index = 0; index < count; index++) { sb.append(str); } return sb.toString(); } finally { + trimToMaxSize(sb, MAX_FORMAT_BUFFER_LENGTH); sb.setLength(0); } } diff --git a/src/changelog/.2.x.x/fix_api_recursive_formatting.xml b/src/changelog/.2.x.x/fix_api_recursive_formatting.xml new file mode 100644 index 00000000000..558152b60ce --- /dev/null +++ b/src/changelog/.2.x.x/fix_api_recursive_formatting.xml @@ -0,0 +1,9 @@ + + + + Fix `StringBuilder` cache corruption on recursive access + +