From 2a398ead98e2d46b2616e5e523bc5b2b10186cb6 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Volkan=20Yaz=C4=B1c=C4=B1?= Date: Wed, 9 Oct 2024 15:49:33 +0200 Subject: [PATCH] Prefix stack traces with a newline in Pattern Layout (#3045) - Exception converters are reworked to ensure a newline prefix (which used to be a whitespace) - Fix property extraction for root exceptions (e.g., %rEx{short.className}) Co-authored-by: AlanYu Co-authored-by: Piotr P. Karwasz --- ...yncLoggerTestArgumentFreedOnErrorTest.java | 64 +++-- .../logger/QueueFullAsyncLogger3Test.java | 82 ++----- .../log4j/core/GarbageCollectionHelper.java | 68 ------ .../log4j/core/test/internal/GcHelper.java | 54 +++++ .../test/internal/GcPressureGenerator.java | 81 +++++++ .../test/java/foo/TestFriendlyException.java | 27 ++- .../core/EventParameterMemoryLeakTest.java | 138 ++++++----- ...bleParameterizedMessageMemoryLeakTest.java | 34 +-- .../RollingAppenderDirectWriteTest.java | 5 +- ...NestedLoggingFromThrowableMessageTest.java | 7 +- .../log4j/core/internal/GcHelperTest.java | 29 +++ ...ternLayoutDefaultExceptionHandlerTest.java | 75 ++++++ ...ExtendedThrowablePatternConverterTest.java | 9 +- .../RootThrowablePatternConverterTest.java | 27 ++- .../ThrowablePatternConverterTest.java | 71 +++--- .../log4j/core/pattern/ThrowableTest.java | 229 ------------------ .../log4j/core/util/ThrowablesTest.java | 19 +- .../EventParameterMemoryLeakTest.xml | 35 --- .../ExtendedThrowablePatternConverter.java | 8 +- .../RootThrowablePatternConverter.java | 13 +- ...ableExtendedStackTraceRendererFactory.java | 31 +++ ...owableInvertedPropertyRendererFactory.java | 40 +++ .../ThrowableInvertedStackTraceRenderer.java | 2 +- ...ableInvertedStackTraceRendererFactory.java | 31 +++ .../pattern/ThrowablePatternConverter.java | 55 ++--- .../pattern/ThrowablePropertyRenderer.java | 98 -------- .../ThrowablePropertyRendererFactory.java | 120 +++++++++ .../pattern/ThrowableStackTraceRenderer.java | 10 + .../ThrowableStackTraceRendererFactory.java | 33 +++ .../logging/log4j/core/util/Throwables.java | 37 ++- .../resolver/StackTraceStringResolver.java | 6 +- .../ROOT/pages/manual/pattern-layout.adoc | 150 ++++++------ 32 files changed, 899 insertions(+), 789 deletions(-) delete mode 100644 log4j-core-test/src/main/java/org/apache/logging/log4j/core/GarbageCollectionHelper.java create mode 100644 log4j-core-test/src/main/java/org/apache/logging/log4j/core/test/internal/GcHelper.java create mode 100644 log4j-core-test/src/main/java/org/apache/logging/log4j/core/test/internal/GcPressureGenerator.java create mode 100644 log4j-core-test/src/test/java/org/apache/logging/log4j/core/internal/GcHelperTest.java create mode 100644 log4j-core-test/src/test/java/org/apache/logging/log4j/core/layout/PatternLayoutDefaultExceptionHandlerTest.java delete mode 100644 log4j-core-test/src/test/java/org/apache/logging/log4j/core/pattern/ThrowableTest.java delete mode 100644 log4j-core-test/src/test/resources/EventParameterMemoryLeakTest.xml create mode 100644 log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableExtendedStackTraceRendererFactory.java create mode 100644 log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableInvertedPropertyRendererFactory.java create mode 100644 log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableInvertedStackTraceRendererFactory.java delete mode 100644 log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowablePropertyRenderer.java create mode 100644 log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowablePropertyRendererFactory.java create mode 100644 log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableStackTraceRendererFactory.java diff --git a/log4j-async-logger/src/test/java/org/apache/logging/log4j/async/logger/AsyncLoggerTestArgumentFreedOnErrorTest.java b/log4j-async-logger/src/test/java/org/apache/logging/log4j/async/logger/AsyncLoggerTestArgumentFreedOnErrorTest.java index 68c98d42ba9..b3ae9d59998 100644 --- a/log4j-async-logger/src/test/java/org/apache/logging/log4j/async/logger/AsyncLoggerTestArgumentFreedOnErrorTest.java +++ b/log4j-async-logger/src/test/java/org/apache/logging/log4j/async/logger/AsyncLoggerTestArgumentFreedOnErrorTest.java @@ -16,63 +16,55 @@ */ package org.apache.logging.log4j.async.logger; -import static org.junit.jupiter.api.Assertions.assertTrue; +import static org.apache.logging.log4j.core.test.internal.GcHelper.awaitGarbageCollection; -import java.util.concurrent.CountDownLatch; -import java.util.concurrent.TimeUnit; -import org.apache.logging.log4j.LogManager; -import org.apache.logging.log4j.core.GarbageCollectionHelper; +import org.apache.logging.log4j.core.Logger; +import org.apache.logging.log4j.core.LoggerContext; import org.apache.logging.log4j.core.test.TestConstants; -import org.apache.logging.log4j.core.test.junit.ContextSelectorType; import org.apache.logging.log4j.message.Message; +import org.apache.logging.log4j.plugins.di.DI; import org.apache.logging.log4j.test.junit.SetTestProperty; +import org.apache.logging.log4j.test.junit.UsingStatusListener; import org.apache.logging.log4j.util.StringBuilderFormattable; import org.junit.jupiter.api.Tag; import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.TestInfo; @Tag("async") -@SetTestProperty(key = TestConstants.GC_ENABLE_DIRECT_ENCODERS, value = "true") -@SetTestProperty(key = TestConstants.ASYNC_FORMAT_MESSAGES_IN_BACKGROUND, value = "true") -@ContextSelectorType(AsyncLoggerContextSelector.class) -public class AsyncLoggerTestArgumentFreedOnErrorTest { +class AsyncLoggerArgumentFreedOnErrorTest { - // LOG4J2-2725: events are cleared even after failure + /** + * Tests events are cleared even after failure. + * + * @see LOG4J2-2725 + */ @Test - public void testMessageIsGarbageCollected() throws Exception { - final AsyncLogger log = (AsyncLogger) LogManager.getLogger("com.foo.Bar"); - final CountDownLatch garbageCollectionLatch = new CountDownLatch(1); - log.fatal(new ThrowingMessage(garbageCollectionLatch)); - try (final GarbageCollectionHelper gcHelper = new GarbageCollectionHelper()) { - gcHelper.run(); - assertTrue( - garbageCollectionLatch.await(30, TimeUnit.SECONDS), "Parameter should have been garbage collected"); - } + @UsingStatusListener // Suppresses `StatusLogger` output, unless there is a failure + @SetTestProperty(key = TestConstants.GC_ENABLE_DIRECT_ENCODERS, value = "true") + @SetTestProperty(key = TestConstants.ASYNC_FORMAT_MESSAGES_IN_BACKGROUND, value = "true") + void parameters_throwing_exception_should_be_garbage_collected(final TestInfo testInfo) throws Exception { + awaitGarbageCollection(() -> { + final String loggerContextName = String.format("%s-LC", testInfo.getDisplayName()); + try (final LoggerContext loggerContext = + new AsyncLoggerContext(loggerContextName, null, null, DI.createInitializedFactory())) { + loggerContext.start(); + final Logger logger = loggerContext.getRootLogger(); + final ThrowingMessage parameter = new ThrowingMessage(); + logger.fatal(parameter); + return parameter; + } + }); } private static class ThrowingMessage implements Message, StringBuilderFormattable { - private final CountDownLatch latch; - - ThrowingMessage(final CountDownLatch latch) { - this.latch = latch; - } - - @Override - protected void finalize() throws Throwable { - latch.countDown(); - super.finalize(); - } + private ThrowingMessage() {} @Override public String getFormattedMessage() { throw new Error("Expected"); } - @Override - public String getFormat() { - return ""; - } - @Override public Object[] getParameters() { return new Object[0]; diff --git a/log4j-async-logger/src/test/java/org/apache/logging/log4j/async/logger/QueueFullAsyncLogger3Test.java b/log4j-async-logger/src/test/java/org/apache/logging/log4j/async/logger/QueueFullAsyncLogger3Test.java index 3641aa29b50..c0a23c49008 100644 --- a/log4j-async-logger/src/test/java/org/apache/logging/log4j/async/logger/QueueFullAsyncLogger3Test.java +++ b/log4j-async-logger/src/test/java/org/apache/logging/log4j/async/logger/QueueFullAsyncLogger3Test.java @@ -16,29 +16,32 @@ */ package org.apache.logging.log4j.async.logger; -import static java.util.concurrent.TimeUnit.SECONDS; +import static org.apache.logging.log4j.async.logger.QueueFullAsyncAbstractTest.assertAsyncLogger; import static org.apache.logging.log4j.core.test.TestConstants.ASYNC_FORMAT_MESSAGES_IN_BACKGROUND; import static org.apache.logging.log4j.core.test.TestConstants.ASYNC_LOGGER_RING_BUFFER_SIZE; import static org.apache.logging.log4j.core.test.TestConstants.ASYNC_QUEUE_FULL_POLICY_CLASS_NAME; +import static org.apache.logging.log4j.core.test.internal.GcHelper.awaitGarbageCollection; import static org.assertj.core.api.Assertions.assertThat; -import static org.junit.Assert.assertTrue; +import java.util.List; import java.util.concurrent.CountDownLatch; +import java.util.stream.Collectors; +import java.util.stream.IntStream; import org.apache.logging.log4j.Logger; -import org.apache.logging.log4j.core.GarbageCollectionHelper; import org.apache.logging.log4j.core.LoggerContext; import org.apache.logging.log4j.core.async.AsyncQueueFullPolicyFactory; import org.apache.logging.log4j.core.async.DiscardingAsyncQueueFullPolicy; import org.apache.logging.log4j.core.impl.CoreProperties; import org.apache.logging.log4j.core.test.async.BlockingAppender; +import org.apache.logging.log4j.core.test.async.QueueFullAbstractTest; import org.apache.logging.log4j.core.test.junit.ContextSelectorType; import org.apache.logging.log4j.core.test.junit.LoggerContextSource; import org.apache.logging.log4j.core.test.junit.Named; import org.apache.logging.log4j.message.Message; +import org.apache.logging.log4j.message.SimpleMessage; import org.apache.logging.log4j.status.StatusLogger; import org.apache.logging.log4j.test.junit.SetTestProperty; import org.junit.jupiter.api.Test; -import org.junit.jupiter.api.Timeout; /** * Tests queue full scenarios with pure AsyncLoggers (all loggers async). @@ -47,7 +50,7 @@ @SetTestProperty(key = ASYNC_LOGGER_RING_BUFFER_SIZE, value = "128") @SetTestProperty(key = ASYNC_FORMAT_MESSAGES_IN_BACKGROUND, value = "true") @SetTestProperty(key = ASYNC_QUEUE_FULL_POLICY_CLASS_NAME, value = "Discard") -public class QueueFullAsyncLogger3Test extends QueueFullAsyncAbstractTest { +class QueueFullAsyncLogger3Test extends QueueFullAbstractTest { @Override protected void checkConfig(final LoggerContext ctx) { @@ -60,64 +63,21 @@ protected void checkConfig(final LoggerContext ctx) { } @Test - @Timeout(value = 15, unit = SECONDS) @LoggerContextSource - public void discardedMessagesShouldBeGarbageCollected( + void discarded_messages_should_be_garbage_collected( final LoggerContext ctx, final @Named(APPENDER_NAME) BlockingAppender blockingAppender) throws InterruptedException { - checkConfig(ctx); - final Logger logger = ctx.getLogger(getClass()); - - blockingAppender.logEvents = null; - blockingAppender.countDownLatch = new CountDownLatch(1); - final int count = 200; - final CountDownLatch garbageCollectionLatch = new CountDownLatch(count); - for (int i = 0; i < count; i++) { - logger.info(new CountdownOnGarbageCollectMessage(garbageCollectionLatch)); - } - blockingAppender.countDownLatch.countDown(); - - final GarbageCollectionHelper gcHelper = new GarbageCollectionHelper(); - gcHelper.run(); - try { - assertTrue("Parameter should have been garbage collected", garbageCollectionLatch.await(30, SECONDS)); - } finally { - gcHelper.close(); - } - } - - private static final class CountdownOnGarbageCollectMessage implements Message { - - private final CountDownLatch latch; - - CountdownOnGarbageCollectMessage(final CountDownLatch latch) { - this.latch = latch; - } - - @Override - public String getFormattedMessage() { - return "formatted"; - } - - @Override - public String getFormat() { - return null; - } - - @Override - public Object[] getParameters() { - return org.apache.logging.log4j.util.Constants.EMPTY_OBJECT_ARRAY; - } - - @Override - public Throwable getThrowable() { - return null; - } - - @Override - protected void finalize() throws Throwable { - latch.countDown(); - super.finalize(); - } + awaitGarbageCollection(() -> { + checkConfig(ctx); + final Logger logger = ctx.getLogger(getClass()); + blockingAppender.logEvents = null; + blockingAppender.countDownLatch = new CountDownLatch(1); + final List messages = IntStream.range(0, 200) + .mapToObj(messageIndex -> new SimpleMessage("message " + messageIndex)) + .collect(Collectors.toList()); + messages.forEach(logger::info); + blockingAppender.countDownLatch.countDown(); + return messages; + }); } } diff --git a/log4j-core-test/src/main/java/org/apache/logging/log4j/core/GarbageCollectionHelper.java b/log4j-core-test/src/main/java/org/apache/logging/log4j/core/GarbageCollectionHelper.java deleted file mode 100644 index 1feff3edd8c..00000000000 --- a/log4j-core-test/src/main/java/org/apache/logging/log4j/core/GarbageCollectionHelper.java +++ /dev/null @@ -1,68 +0,0 @@ -/* - * 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.core; - -import static org.junit.Assert.assertTrue; - -import java.io.Closeable; -import java.io.IOException; -import java.io.OutputStream; -import java.util.concurrent.CountDownLatch; -import java.util.concurrent.TimeUnit; -import java.util.concurrent.atomic.AtomicBoolean; - -public final class GarbageCollectionHelper implements Closeable, Runnable { - private static final OutputStream sink = OutputStream.nullOutputStream(); - private final AtomicBoolean running = new AtomicBoolean(); - private final CountDownLatch latch = new CountDownLatch(1); - private final Thread gcThread = new Thread(new Runnable() { - @Override - public void run() { - try { - while (running.get()) { - // Allocate data to help suggest a GC - try { - // 1mb of heap - sink.write(new byte[1024 * 1024]); - } catch (IOException ignored) { - } - // May no-op depending on the jvm configuration - System.gc(); - } - } finally { - latch.countDown(); - } - } - }); - - @Override - public void run() { - if (running.compareAndSet(false, true)) { - gcThread.start(); - } - } - - @Override - public void close() { - running.set(false); - try { - assertTrue("GarbageCollectionHelper did not shut down cleanly", latch.await(10, TimeUnit.SECONDS)); - } catch (InterruptedException e) { - throw new RuntimeException(e); - } - } -} diff --git a/log4j-core-test/src/main/java/org/apache/logging/log4j/core/test/internal/GcHelper.java b/log4j-core-test/src/main/java/org/apache/logging/log4j/core/test/internal/GcHelper.java new file mode 100644 index 00000000000..7c32eaff268 --- /dev/null +++ b/log4j-core-test/src/main/java/org/apache/logging/log4j/core/test/internal/GcHelper.java @@ -0,0 +1,54 @@ +/* + * 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.core.test.internal; + +import java.lang.ref.PhantomReference; +import java.lang.ref.Reference; +import java.lang.ref.ReferenceQueue; +import org.junit.jupiter.api.function.ThrowingSupplier; + +public final class GcHelper { + + private GcHelper() {} + + /** + * Waits for the value to be garbage collected. + * + * @param valueSupplier a value provider + */ + @SuppressWarnings({"unused", "UnusedAssignment"}) + public static void awaitGarbageCollection(final ThrowingSupplier valueSupplier) throws InterruptedException { + + // Create the reference queue + final ReferenceQueue refQueue = new ReferenceQueue<>(); + final Reference ref; + try { + final Object value = valueSupplier.get(); + ref = new PhantomReference<>(value, refQueue); + } catch (final Throwable error) { + throw new RuntimeException("failed obtaining value", error); + } + + // Wait for the garbage collection + try (final GcPressureGenerator ignored = GcPressureGenerator.ofStarted()) { + final Reference removedRef = refQueue.remove(30_000L); + if (removedRef == null) { + throw new AssertionError("garbage collector did not reclaim the value"); + } + } + } +} diff --git a/log4j-core-test/src/main/java/org/apache/logging/log4j/core/test/internal/GcPressureGenerator.java b/log4j-core-test/src/main/java/org/apache/logging/log4j/core/test/internal/GcPressureGenerator.java new file mode 100644 index 00000000000..b5be23b6b5e --- /dev/null +++ b/log4j-core-test/src/main/java/org/apache/logging/log4j/core/test/internal/GcPressureGenerator.java @@ -0,0 +1,81 @@ +/* + * 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.core.test.internal; + +import static org.assertj.core.api.Assertions.assertThat; + +import java.util.concurrent.CountDownLatch; +import java.util.concurrent.TimeUnit; +import java.util.concurrent.atomic.AtomicBoolean; +import java.util.concurrent.atomic.AtomicInteger; + +/** + * Creates GC pressure by continuously allocating and {@link System#gc() triggering GC}. + */ +final class GcPressureGenerator implements AutoCloseable { + + private final AtomicInteger sink = new AtomicInteger(0); + + private final AtomicBoolean running = new AtomicBoolean(true); + + private final CountDownLatch stopLatch = new CountDownLatch(1); + + private GcPressureGenerator() { + startGeneratorThread(); + } + + private void startGeneratorThread() { + final String threadName = GcPressureGenerator.class.getSimpleName(); + final Thread thread = new Thread(this::generateGarbage, threadName); + thread.setDaemon(true); // Avoid blocking JVM exit + thread.start(); + } + + private void generateGarbage() { + try { + while (running.get()) { + final Object object = new byte[1024 * 1024]; + int positiveValue = Math.abs(object.hashCode()); + sink.set(positiveValue); + System.gc(); + System.runFinalization(); + } + } finally { + stopLatch.countDown(); + } + } + + static GcPressureGenerator ofStarted() { + return new GcPressureGenerator(); + } + + @Override + public void close() { + final boolean signalled = running.compareAndSet(true, false); + if (signalled) { + try { + final boolean stopped = stopLatch.await(10, TimeUnit.SECONDS); + assertThat(stopped).isTrue(); + assertThat(sink.get()).isPositive(); + } catch (final InterruptedException error) { + // Restore the `interrupted` flag + Thread.currentThread().interrupt(); + throw new RuntimeException(error); + } + } + } +} diff --git a/log4j-core-test/src/test/java/foo/TestFriendlyException.java b/log4j-core-test/src/test/java/foo/TestFriendlyException.java index 4ce0c7d5a06..7c791dc20d2 100644 --- a/log4j-core-test/src/test/java/foo/TestFriendlyException.java +++ b/log4j-core-test/src/test/java/foo/TestFriendlyException.java @@ -27,18 +27,21 @@ * A testing friendly exception featuring *
    *
  • Distinct localized message
  • - *
  • Non-Log4j package origin1
  • + *
  • Non-Log4j1 and fixed2 (to {@code bar}) package origin
  • *
  • Sufficient causal chain depth
  • - *
  • Cyclic causal chain
  • + *
  • Circular causal chain
  • *
  • Suppressed exceptions
  • *
  • Clutter-free stack trace (i.e., elements from JUnit, JDK, etc.)
  • - *
  • Stack trace elements from named modules2
  • + *
  • Stack trace elements from named modules3
  • *
*

* 1 Helps with observing stack trace manipulation effects of Log4j. *

*

- * 2 Helps with testing module name serialization. + * 2 Helps to make the origin of {@link #INSTANCE} independent of the first test accessing to it. + *

+ *

+ * 3 Helps with testing module name serialization. *

*/ public final class TestFriendlyException extends RuntimeException { @@ -48,6 +51,9 @@ public final class TestFriendlyException extends RuntimeException { assertThat(TestFriendlyException.class.getPackage().getName()).doesNotStartWith("org.apache"); } + public static final StackTraceElement ORG_APACHE_REPLACEMENT_STACK_TRACE_ELEMENT = + new StackTraceElement("bar.OrgApacheReplacement", "someMethod", "OrgApacheReplacement.java", 0); + public static final StackTraceElement NAMED_MODULE_STACK_TRACE_ELEMENT = namedModuleStackTraceElement(); @SuppressWarnings("resource") @@ -127,9 +133,13 @@ private static Stream mapStackTraceElement( private static Stream filterStackTraceElement( final StackTraceElement stackTraceElement, final boolean[] seenExcludedStackTraceElement) { + + // Short-circuit if we have already encountered an excluded stack trace element if (seenExcludedStackTraceElement[0]) { return Stream.empty(); } + + // Check if the class name is excluded final String className = stackTraceElement.getClassName(); for (final String excludedClassNamePrefix : EXCLUDED_CLASS_NAME_PREFIXES) { if (className.startsWith(excludedClassNamePrefix)) { @@ -137,6 +147,15 @@ private static Stream filterStackTraceElement( return Stream.empty(); } } + + // Replace `org.apache`-originating entries with a constant one. + // Without this, `INSTANCE` might yield different origin depending on the first class accessing to it. + // We remove this ambiguity and fix our origin to a constant instead. + if (className.startsWith("org.apache")) { + return Stream.of(ORG_APACHE_REPLACEMENT_STACK_TRACE_ELEMENT); + } + + // Otherwise, it looks good return Stream.of(stackTraceElement); } diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/EventParameterMemoryLeakTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/EventParameterMemoryLeakTest.java index a036484f4c1..009058e772a 100644 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/EventParameterMemoryLeakTest.java +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/EventParameterMemoryLeakTest.java @@ -16,76 +16,99 @@ */ package org.apache.logging.log4j.core; -import static org.hamcrest.MatcherAssert.assertThat; -import static org.hamcrest.Matchers.containsString; -import static org.hamcrest.Matchers.is; -import static org.junit.jupiter.api.Assertions.assertNull; -import static org.junit.jupiter.api.Assertions.assertTrue; - -import java.io.BufferedReader; -import java.io.File; -import java.io.FileReader; -import java.lang.ref.Cleaner; -import java.util.concurrent.CountDownLatch; -import java.util.concurrent.TimeUnit; -import org.apache.logging.log4j.LogManager; +import static org.apache.logging.log4j.core.test.internal.GcHelper.awaitGarbageCollection; +import static org.assertj.core.api.Assertions.assertThat; + +import java.util.List; +import org.apache.logging.log4j.Level; import org.apache.logging.log4j.Logger; -import org.apache.logging.log4j.core.test.CoreLoggerContexts; +import org.apache.logging.log4j.core.config.Configuration; +import org.apache.logging.log4j.core.config.builder.api.AppenderComponentBuilder; +import org.apache.logging.log4j.core.config.builder.api.ConfigurationBuilder; +import org.apache.logging.log4j.core.config.builder.api.ConfigurationBuilderFactory; +import org.apache.logging.log4j.core.config.builder.api.LayoutComponentBuilder; +import org.apache.logging.log4j.core.config.builder.api.RootLoggerComponentBuilder; +import org.apache.logging.log4j.core.config.builder.impl.BuiltConfiguration; import org.apache.logging.log4j.core.test.TestConstants; +import org.apache.logging.log4j.core.test.appender.ListAppender; +import org.apache.logging.log4j.plugins.di.DI; import org.apache.logging.log4j.test.junit.SetTestProperty; import org.junit.jupiter.api.Tag; import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.TestInfo; @Tag("functional") -@SetTestProperty(key = TestConstants.GC_ENABLE_DIRECT_ENCODERS, value = "true") -@SetTestProperty(key = TestConstants.CONFIGURATION_FILE, value = "EventParameterMemoryLeakTest.xml") -public class EventParameterMemoryLeakTest { +class EventParameterMemoryLeakTest { @Test - @SuppressWarnings("UnusedAssignment") // parameter set to null to allow garbage collection - public void testParametersAreNotLeaked() throws Exception { - final File file = new File("target", "EventParameterMemoryLeakTest.log"); - assertTrue(!file.exists() || file.delete(), "Deleted old file before test"); - - final Logger log = LogManager.getLogger("com.foo.Bar"); - final CountDownLatch latch = new CountDownLatch(1); - final Cleaner cleaner = Cleaner.create(); - Object parameter = new ParameterObject("paramValue"); - cleaner.register(parameter, latch::countDown); - log.info("Message with parameter {}", parameter); - log.info(parameter); - log.info("test", new ObjectThrowable(parameter)); - log.info("test {}", "hello", new ObjectThrowable(parameter)); - parameter = null; - CoreLoggerContexts.stopLoggerContext(file); - final BufferedReader reader = new BufferedReader(new FileReader(file)); - final String line1 = reader.readLine(); - final String line2 = reader.readLine(); - final String line3 = reader.readLine(); - // line4 is empty line because of the line separator after throwable pattern - final String line4 = reader.readLine(); - final String line5 = reader.readLine(); - final String line6 = reader.readLine(); - final String line7 = reader.readLine(); - reader.close(); - file.delete(); - assertThat(line1, containsString("Message with parameter paramValue")); - assertThat(line2, containsString("paramValue")); - assertThat(line3, containsString("paramValue")); - assertThat(line4, is("")); - assertThat(line5, containsString("paramValue")); - assertThat(line6, is("")); - assertNull(line7, "Expected only six lines"); - try (final GarbageCollectionHelper gcHelper = new GarbageCollectionHelper()) { - gcHelper.run(); - assertTrue(latch.await(30, TimeUnit.SECONDS), "Parameter should have been garbage collected"); - } + @SetTestProperty(key = TestConstants.GC_ENABLE_DIRECT_ENCODERS, value = "true") + void parameters_should_be_garbage_collected(final TestInfo testInfo) throws Throwable { + awaitGarbageCollection(() -> { + final ListAppender[] appenderRef = {null}; + final Logger[] loggerRef = {null}; + try (final LoggerContext ignored = createLoggerContext(testInfo, appenderRef, loggerRef)) { + + // Log messages + final ParameterObject parameter = new ParameterObject("paramValue"); + loggerRef[0].info("Message with parameter {}", parameter); + loggerRef[0].info(parameter); + loggerRef[0].info("test", new ObjectThrowable(parameter)); + loggerRef[0].info("test {}", "hello", new ObjectThrowable(parameter)); + + // Verify the logging + final List messages = appenderRef[0].getMessages(); + assertThat(messages).hasSize(4); + assertThat(messages.get(0)).isEqualTo("Message with parameter %s", parameter.value); + assertThat(messages.get(1)).isEqualTo(parameter.value); + assertThat(messages.get(2)) + .startsWith(String.format("test%n%s: %s", ObjectThrowable.class.getName(), parameter.value)); + assertThat(messages.get(3)) + .startsWith( + String.format("test hello%n%s: %s", ObjectThrowable.class.getName(), parameter.value)); + + // Return the GC subject + return parameter; + } + }); + } + + private static LoggerContext createLoggerContext( + final TestInfo testInfo, final ListAppender[] appenderRef, final Logger[] loggerRef) { + final String loggerContextName = String.format("%s-LC", testInfo.getDisplayName()); + final LoggerContext loggerContext = + new LoggerContext(loggerContextName, null, (String) null, DI.createInitializedFactory()); + final String appenderName = "LIST"; + final Configuration configuration = createConfiguration(appenderName); + loggerContext.start(configuration); + appenderRef[0] = configuration.getAppender(appenderName); + assertThat(appenderRef[0]).isNotNull(); + final Class testClass = testInfo.getTestClass().orElse(null); + assertThat(testClass).isNotNull(); + loggerRef[0] = loggerContext.getLogger(testClass); + return loggerContext; + } + + @SuppressWarnings("SameParameterValue") + private static Configuration createConfiguration(final String appenderName) { + final ConfigurationBuilder configBuilder = + ConfigurationBuilderFactory.newConfigurationBuilder(); + final LayoutComponentBuilder layoutComponentBuilder = + configBuilder.newLayout("PatternLayout").addAttribute("pattern", "%m"); + final AppenderComponentBuilder appenderComponentBuilder = + configBuilder.newAppender(appenderName, "List").add(layoutComponentBuilder); + final RootLoggerComponentBuilder loggerComponentBuilder = + configBuilder.newRootLogger(Level.ALL).add(configBuilder.newAppenderRef(appenderName)); + return configBuilder + .add(appenderComponentBuilder) + .add(loggerComponentBuilder) + .build(false); } private static final class ParameterObject { + private final String value; - ParameterObject(final String value) { + private ParameterObject(final String value) { this.value = value; } @@ -96,9 +119,10 @@ public String toString() { } private static final class ObjectThrowable extends RuntimeException { + private final Object object; - ObjectThrowable(final Object object) { + private ObjectThrowable(final Object object) { super(String.valueOf(object)); this.object = object; } diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/ReusableParameterizedMessageMemoryLeakTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/ReusableParameterizedMessageMemoryLeakTest.java index 00f8ba2da3f..1a425b5eac7 100644 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/ReusableParameterizedMessageMemoryLeakTest.java +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/ReusableParameterizedMessageMemoryLeakTest.java @@ -16,10 +16,8 @@ */ package org.apache.logging.log4j.core; -import static org.junit.jupiter.api.Assertions.assertTrue; +import static org.apache.logging.log4j.core.test.internal.GcHelper.awaitGarbageCollection; -import java.util.concurrent.CountDownLatch; -import java.util.concurrent.TimeUnit; import org.apache.logging.log4j.message.ReusableMessage; import org.apache.logging.log4j.message.ReusableMessageFactory; import org.junit.jupiter.api.Test; @@ -27,36 +25,28 @@ public class ReusableParameterizedMessageMemoryLeakTest { @Test - public void testParametersAreNotLeaked() throws Exception { - final CountDownLatch latch = new CountDownLatch(1); - final ReusableMessage message = (ReusableMessage) - ReusableMessageFactory.INSTANCE.newMessage("foo {}", new ParameterObject("paramValue", latch)); - // Large enough for the parameters, but smaller than the default reusable array size. - message.swapParameters(new Object[5]); - try (final GarbageCollectionHelper gcHelper = new GarbageCollectionHelper()) { - gcHelper.run(); - assertTrue(latch.await(30, TimeUnit.SECONDS), "Parameter should have been garbage collected"); - } + public void parameters_should_be_garbage_collected() throws Exception { + awaitGarbageCollection(() -> { + final ParameterObject parameter = new ParameterObject("paramValue"); + final ReusableMessage message = + (ReusableMessage) ReusableMessageFactory.INSTANCE.newMessage("foo {}", parameter); + // Large enough for the parameters, but smaller than the default reusable array size + message.swapParameters(new Object[5]); + return parameter; + }); } private static final class ParameterObject { + private final String value; - private final CountDownLatch latch; - ParameterObject(final String value, final CountDownLatch latch) { + private ParameterObject(final String value) { this.value = value; - this.latch = latch; } @Override public String toString() { return value; } - - @Override - protected void finalize() throws Throwable { - latch.countDown(); - super.finalize(); - } } } diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/rolling/RollingAppenderDirectWriteTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/rolling/RollingAppenderDirectWriteTest.java index 01a2291e2f9..4a34ca917c6 100644 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/rolling/RollingAppenderDirectWriteTest.java +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/rolling/RollingAppenderDirectWriteTest.java @@ -62,8 +62,11 @@ public void testAppender(final LoggerContext ctx) throws Exception { final InputStream uncompressed = fileName.endsWith(".gz") ? new GZIPInputStream(is) : is; final BufferedReader reader = new BufferedReader(new InputStreamReader(uncompressed, UTF_8))) { String line; + int lineIndex = 0; while ((line = reader.readLine()) != null) { - assertThat(line).matches(LINE_PATTERN); + assertThat(line) + .as("line %d of file `%s`", ++lineIndex, file) + .matches(LINE_PATTERN); ++found; } } diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/impl/NestedLoggingFromThrowableMessageTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/impl/NestedLoggingFromThrowableMessageTest.java index 8f1c6c6d9cb..108b08b19ee 100644 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/impl/NestedLoggingFromThrowableMessageTest.java +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/impl/NestedLoggingFromThrowableMessageTest.java @@ -21,9 +21,9 @@ import java.io.BufferedReader; import java.io.File; -import java.io.FileInputStream; import java.io.IOException; import java.io.InputStreamReader; +import java.nio.file.Files; import java.util.HashSet; import java.util.Set; import org.apache.logging.log4j.Logger; @@ -78,14 +78,15 @@ public void testNestedLoggingInLastArgument() throws Exception { final Set lines2 = readUniqueLines(file2); assertEquals("Expected the same data from both appenders", lines1, lines2); - assertEquals(3, lines1.size()); + assertEquals(2, lines1.size()); assertTrue(lines1.contains("INFO NestedLoggingFromThrowableMessageTest Logging in getMessage ")); assertTrue(lines1.contains("ERROR NestedLoggingFromThrowableMessageTest Test message")); } private static Set readUniqueLines(final File input) throws IOException { final Set lines = new HashSet<>(); - try (final BufferedReader reader = new BufferedReader(new InputStreamReader(new FileInputStream(input)))) { + try (final BufferedReader reader = + new BufferedReader(new InputStreamReader(Files.newInputStream(input.toPath())))) { String line; while ((line = reader.readLine()) != null) { assertTrue("Read duplicate line: " + line, lines.add(line)); diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/internal/GcHelperTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/internal/GcHelperTest.java new file mode 100644 index 00000000000..ae994466feb --- /dev/null +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/internal/GcHelperTest.java @@ -0,0 +1,29 @@ +/* + * 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.core.internal; + +import static org.apache.logging.log4j.core.test.internal.GcHelper.awaitGarbageCollection; + +import org.junit.jupiter.api.Test; + +class GcHelperTest { + + @Test + void await_should_work() throws InterruptedException { + awaitGarbageCollection(Object::new); + } +} diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/layout/PatternLayoutDefaultExceptionHandlerTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/layout/PatternLayoutDefaultExceptionHandlerTest.java new file mode 100644 index 00000000000..6a5fcbac126 --- /dev/null +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/layout/PatternLayoutDefaultExceptionHandlerTest.java @@ -0,0 +1,75 @@ +/* + * 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.core.layout; + +import static org.assertj.core.api.Assertions.assertThat; + +import org.apache.logging.log4j.core.Layout; +import org.apache.logging.log4j.core.LogEvent; +import org.apache.logging.log4j.core.config.Configuration; +import org.apache.logging.log4j.core.config.NullConfiguration; +import org.apache.logging.log4j.core.impl.Log4jLogEvent; +import org.assertj.core.api.AbstractStringAssert; +import org.junit.jupiter.api.Test; + +class PatternLayoutDefaultExceptionHandlerTest { + + private static final Configuration CONFIG = new NullConfiguration(); + + private static final Exception EXCEPTION = new RuntimeException("foo"); + + @Test + void default_exception_handler_should_be_provided() { + final String threadName = Thread.currentThread().getName(); + final String exceptionClassName = EXCEPTION.getClass().getCanonicalName(); + final String exceptionMessage = EXCEPTION.getMessage(); + final String firstLine = String.format("%s%n%s: %s", threadName, exceptionClassName, exceptionMessage); + assertThatPatternEncodes("%t", true).startsWith(firstLine); + } + + @Test + void default_exception_handler_should_be_provided_after_newline() { + final String threadName = Thread.currentThread().getName(); + final String exceptionClassName = EXCEPTION.getClass().getCanonicalName(); + final String exceptionMessage = EXCEPTION.getMessage(); + final String firstLine = String.format("%s%n%s: %s", threadName, exceptionClassName, exceptionMessage); + assertThatPatternEncodes("%t%n", true).startsWith(firstLine); + } + + @Test + void default_exception_handler_should_not_be_provided_if_user_provides_one() { + final String className = EXCEPTION.getStackTrace()[0].getClassName(); + assertThatPatternEncodes("%ex{short.className}", true).isEqualTo(className); + } + + @Test + void default_exception_handler_should_not_be_provided_if_alwaysWriteExceptions_disabled() { + final String threadName = Thread.currentThread().getName(); + assertThatPatternEncodes("%t", false).isEqualTo(threadName); + } + + private static AbstractStringAssert assertThatPatternEncodes( + final String pattern, final boolean alwaysWriteExceptions) { + final Layout layout = PatternLayout.newBuilder() + .setConfiguration(CONFIG) + .setPattern(pattern) + .setAlwaysWriteExceptions(alwaysWriteExceptions) + .build(); + final LogEvent event = Log4jLogEvent.newBuilder().setThrown(EXCEPTION).build(); + return assertThat(layout.toSerializable(event)).as("pattern=`%s`", pattern); + } +} diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/pattern/ExtendedThrowablePatternConverterTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/pattern/ExtendedThrowablePatternConverterTest.java index b1418c62e44..ea71b625440 100644 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/pattern/ExtendedThrowablePatternConverterTest.java +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/pattern/ExtendedThrowablePatternConverterTest.java @@ -17,6 +17,7 @@ package org.apache.logging.log4j.core.pattern; import static java.util.Arrays.asList; +import static org.apache.logging.log4j.core.pattern.ThrowablePatternConverterTest.THROWING_METHOD; import foo.TestFriendlyException; import java.util.List; @@ -36,7 +37,7 @@ class ExtendedThrowablePatternConverterTest { class PropertyTest extends AbstractPropertyTest { PropertyTest() { - super("%xEx"); + super("%xEx", THROWING_METHOD); } } @@ -45,7 +46,7 @@ class PropertyTest extends AbstractPropertyTest { " at " + TestFriendlyException.NAMED_MODULE_STACK_TRACE_ELEMENT + " ~[?:?]", " at foo.TestFriendlyException.create(TestFriendlyException.java:0) ~[test-classes/:?]", " at foo.TestFriendlyException.(TestFriendlyException.java:0) ~[test-classes/:?]", - " at org.apache.logging.log4j.core.pattern.ThrowablePatternConverterTest.(ThrowablePatternConverterTest.java:0) [test-classes/:?]", + " at " + TestFriendlyException.ORG_APACHE_REPLACEMENT_STACK_TRACE_ELEMENT + " ~[?:0]", " Suppressed: foo.TestFriendlyException: r_s [localized]", " at foo.TestFriendlyException.create(TestFriendlyException.java:0) ~[test-classes/:?]", " at foo.TestFriendlyException.create(TestFriendlyException.java:0) ~[test-classes/:?]", @@ -109,7 +110,7 @@ void depth_and_package_limited_output_should_match_1(final DepthTestCase depthTe "foo.TestFriendlyException: r [localized]", " at " + TestFriendlyException.NAMED_MODULE_STACK_TRACE_ELEMENT + " ~[?:?]", " ... suppressed 2 lines", - " at org.apache.logging.log4j.core.pattern.ThrowablePatternConverterTest.(ThrowablePatternConverterTest.java:0) [test-classes/:?]", + " at " + TestFriendlyException.ORG_APACHE_REPLACEMENT_STACK_TRACE_ELEMENT + " ~[?:0]", " Suppressed: foo.TestFriendlyException: r_s [localized]", " ... suppressed 2 lines", " ... 2 more", @@ -136,7 +137,7 @@ void depth_and_package_limited_output_should_match_1(final DepthTestCase depthTe @MethodSource("org.apache.logging.log4j.core.pattern.ThrowablePatternConverterTest#depthTestCases") void depth_and_package_limited_output_should_match_2(final DepthTestCase depthTestCase) { final String pattern = String.format( - "%s{%d}{filters(org.apache)}%s", + "%s{%d}{filters(bar)}%s", patternPrefix, depthTestCase.maxLineCount, depthTestCase.separatorTestCase.patternAddendum); assertStackTraceLines( depthTestCase, diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/pattern/RootThrowablePatternConverterTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/pattern/RootThrowablePatternConverterTest.java index b02618aff4b..b7cee50b3ae 100644 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/pattern/RootThrowablePatternConverterTest.java +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/pattern/RootThrowablePatternConverterTest.java @@ -17,13 +17,19 @@ package org.apache.logging.log4j.core.pattern; import static java.util.Arrays.asList; +import static org.apache.logging.log4j.core.pattern.ThrowablePatternConverterTest.EXCEPTION; +import static org.apache.logging.log4j.core.pattern.ThrowablePatternConverterTest.LEVEL; +import static org.apache.logging.log4j.core.pattern.ThrowablePatternConverterTest.convert; +import static org.assertj.core.api.Assertions.assertThat; import foo.TestFriendlyException; import java.util.List; import org.apache.logging.log4j.core.pattern.ThrowablePatternConverterTest.AbstractPropertyTest; import org.apache.logging.log4j.core.pattern.ThrowablePatternConverterTest.AbstractStackTraceTest; import org.apache.logging.log4j.core.pattern.ThrowablePatternConverterTest.DepthTestCase; +import org.apache.logging.log4j.core.util.Throwables; import org.junit.jupiter.api.Nested; +import org.junit.jupiter.api.Test; import org.junit.jupiter.params.ParameterizedTest; import org.junit.jupiter.params.provider.MethodSource; @@ -32,11 +38,14 @@ */ class RootThrowablePatternConverterTest { + private static final StackTraceElement THROWING_METHOD = + Throwables.getRootCause(EXCEPTION).getStackTrace()[0]; + @Nested class PropertyTest extends AbstractPropertyTest { PropertyTest() { - super("%rEx"); + super("%rEx", THROWING_METHOD); } } @@ -59,7 +68,7 @@ class PropertyTest extends AbstractPropertyTest { " at " + TestFriendlyException.NAMED_MODULE_STACK_TRACE_ELEMENT, " at foo.TestFriendlyException.create(TestFriendlyException.java:0)", " at foo.TestFriendlyException.(TestFriendlyException.java:0)", - " at org.apache.logging.log4j.core.pattern.ThrowablePatternConverterTest.(ThrowablePatternConverterTest.java:0)", + " at " + TestFriendlyException.ORG_APACHE_REPLACEMENT_STACK_TRACE_ELEMENT, " Suppressed: foo.TestFriendlyException: r_s_c [localized]", " at foo.TestFriendlyException.create(TestFriendlyException.java:0)", " at foo.TestFriendlyException.create(TestFriendlyException.java:0)", @@ -80,6 +89,16 @@ class StackTraceTest extends AbstractStackTraceTest { super("%rEx"); } + @Test + @Override + void output_should_be_newline_prefixed() { + final String pattern = "%p" + patternPrefix; + final String stackTrace = convert(pattern); + final String expectedStart = String.format( + "%s%n[CIRCULAR REFERENCE: %s", LEVEL, EXCEPTION.getClass().getCanonicalName()); + assertThat(stackTrace).as("pattern=`%s`", pattern).startsWith(expectedStart); + } + @ParameterizedTest @MethodSource("org.apache.logging.log4j.core.pattern.ThrowablePatternConverterTest#fullStackTracePatterns") void full_output_should_match(final String pattern) { @@ -120,7 +139,7 @@ void depth_and_package_limited_output_should_match_1(final DepthTestCase depthTe "Wrapped by: foo.TestFriendlyException: r [localized]", " at " + TestFriendlyException.NAMED_MODULE_STACK_TRACE_ELEMENT, " ... suppressed 2 lines", - " at org.apache.logging.log4j.core.pattern.ThrowablePatternConverterTest.(ThrowablePatternConverterTest.java:0)", + " at " + TestFriendlyException.ORG_APACHE_REPLACEMENT_STACK_TRACE_ELEMENT, " Suppressed: foo.TestFriendlyException: r_s_c [localized]", " ... suppressed 2 lines", " ... 3 more", @@ -136,7 +155,7 @@ void depth_and_package_limited_output_should_match_1(final DepthTestCase depthTe @MethodSource("org.apache.logging.log4j.core.pattern.ThrowablePatternConverterTest#depthTestCases") void depth_and_package_limited_output_should_match_2(final DepthTestCase depthTestCase) { final String pattern = String.format( - "%s{%d}{filters(org.apache)}%s", + "%s{%d}{filters(bar)}%s", patternPrefix, depthTestCase.maxLineCount, depthTestCase.separatorTestCase.patternAddendum); assertStackTraceLines( depthTestCase, diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/pattern/ThrowablePatternConverterTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/pattern/ThrowablePatternConverterTest.java index c886def43ce..e178526fd99 100644 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/pattern/ThrowablePatternConverterTest.java +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/pattern/ThrowablePatternConverterTest.java @@ -17,6 +17,7 @@ package org.apache.logging.log4j.core.pattern; import static java.util.Arrays.asList; +import static org.apache.logging.log4j.util.Strings.LINE_SEPARATOR; import static org.assertj.core.api.Assertions.assertThat; import foo.TestFriendlyException; @@ -33,6 +34,7 @@ import org.apache.logging.log4j.core.layout.PatternLayout; import org.jspecify.annotations.Nullable; import org.junit.jupiter.api.Nested; +import org.junit.jupiter.api.Test; import org.junit.jupiter.params.ParameterizedTest; import org.junit.jupiter.params.provider.MethodSource; @@ -41,15 +43,13 @@ */ public class ThrowablePatternConverterTest { - private static final String NEWLINE = System.lineSeparator(); + static final Throwable EXCEPTION = TestFriendlyException.INSTANCE; - private static final Throwable EXCEPTION = TestFriendlyException.INSTANCE; - - private static final StackTraceElement THROWING_METHOD = EXCEPTION.getStackTrace()[0]; + static final StackTraceElement THROWING_METHOD = EXCEPTION.getStackTrace()[0]; private static final PatternParser PATTERN_PARSER = PatternLayout.createPatternParser(null); - private static final Level LEVEL = Level.FATAL; + static final Level LEVEL = Level.FATAL; static final class SeparatorTestCase { @@ -75,10 +75,10 @@ static Stream separatorTestCases() { new SeparatorTestCase("{separator()}", ""), new SeparatorTestCase("{separator(#)}", "#"), // Only suffixes - new SeparatorTestCase("{suffix()}", NEWLINE), - new SeparatorTestCase("{suffix(~)}", " ~" + NEWLINE), - new SeparatorTestCase("{suffix(%level)}", " " + level + NEWLINE), - new SeparatorTestCase("{suffix(%rEx)}", NEWLINE), + new SeparatorTestCase("{suffix()}", LINE_SEPARATOR), + new SeparatorTestCase("{suffix(~)}", " ~" + LINE_SEPARATOR), + new SeparatorTestCase("{suffix(%level)}", " " + level + LINE_SEPARATOR), + new SeparatorTestCase("{suffix(%rEx)}", LINE_SEPARATOR), // Both separators and suffixes new SeparatorTestCase("{separator()}{suffix()}", ""), new SeparatorTestCase("{separator()}{suffix(~)}", " ~"), @@ -94,7 +94,7 @@ static Stream separatorTestCases() { class PropertyTest extends AbstractPropertyTest { PropertyTest() { - super("%ex"); + super("%ex", THROWING_METHOD); } } @@ -102,8 +102,11 @@ abstract static class AbstractPropertyTest { private final String patternPrefix; - AbstractPropertyTest(final String patternPrefix) { + private final StackTraceElement throwingMethod; + + AbstractPropertyTest(final String patternPrefix, final StackTraceElement throwingMethod) { this.patternPrefix = patternPrefix; + this.throwingMethod = throwingMethod; } @ParameterizedTest @@ -121,37 +124,34 @@ void localizedMessage_should_be_rendered(final SeparatorTestCase separatorTestCa @ParameterizedTest @MethodSource("org.apache.logging.log4j.core.pattern.ThrowablePatternConverterTest#separatorTestCases") void className_should_be_rendered(final SeparatorTestCase separatorTestCase) { - assertConversion(separatorTestCase, "{short.className}", THROWING_METHOD.getClassName()); + assertConversion(separatorTestCase, "{short.className}", throwingMethod.getClassName()); } @ParameterizedTest @MethodSource("org.apache.logging.log4j.core.pattern.ThrowablePatternConverterTest#separatorTestCases") void methodName_should_be_rendered(final SeparatorTestCase separatorTestCase) { - assertConversion(separatorTestCase, "{short.methodName}", THROWING_METHOD.getMethodName()); + assertConversion(separatorTestCase, "{short.methodName}", throwingMethod.getMethodName()); } @ParameterizedTest @MethodSource("org.apache.logging.log4j.core.pattern.ThrowablePatternConverterTest#separatorTestCases") void lineNumber_should_be_rendered(final SeparatorTestCase separatorTestCase) { - assertConversion(separatorTestCase, "{short.lineNumber}", THROWING_METHOD.getLineNumber() + ""); + assertConversion(separatorTestCase, "{short.lineNumber}", throwingMethod.getLineNumber() + ""); } @ParameterizedTest @MethodSource("org.apache.logging.log4j.core.pattern.ThrowablePatternConverterTest#separatorTestCases") void fileName_should_be_rendered(final SeparatorTestCase separatorTestCase) { - assertConversion(separatorTestCase, "{short.fileName}", THROWING_METHOD.getFileName()); + assertConversion(separatorTestCase, "{short.fileName}", throwingMethod.getFileName()); } private void assertConversion( final SeparatorTestCase separatorTestCase, final String pattern, final Object expectedOutput) { final String effectivePattern = patternPrefix + pattern + separatorTestCase.patternAddendum; final String output = convert(effectivePattern); - final String effectiveExpectedOutput = expectedOutput + separatorTestCase.conversionEnding; assertThat(output) - .as( - "pattern=`%s`, separatorTestCase=%s, expectedOutput=`%s`", - pattern, separatorTestCase, expectedOutput) - .isEqualTo(effectiveExpectedOutput); + .as("pattern=`%s`, separatorTestCase=%s", pattern, separatorTestCase) + .isEqualTo(expectedOutput); } } @@ -182,7 +182,7 @@ static Stream maxLineCounts() { } static Stream fullStackTracePatterns() { - return Stream.of("", "{}", "{full}", "{" + Integer.MAX_VALUE + "}", "{separator(" + NEWLINE + ")}"); + return Stream.of("", "{}", "{full}", "{" + Integer.MAX_VALUE + "}", "{separator(" + LINE_SEPARATOR + ")}"); } @Nested @@ -230,8 +230,8 @@ private String limitLines(final String text, final int maxLineCount) { int lineCount = 0; int startIndex = 0; int newlineIndex; - while (lineCount < maxLineCount && (newlineIndex = text.indexOf(NEWLINE, startIndex)) != -1) { - final int endIndex = newlineIndex + NEWLINE.length(); + while (lineCount < maxLineCount && (newlineIndex = text.indexOf(LINE_SEPARATOR, startIndex)) != -1) { + final int endIndex = newlineIndex + LINE_SEPARATOR.length(); final String line = text.substring(startIndex, endIndex); buffer.append(line); lineCount++; @@ -266,7 +266,7 @@ void depth_limited_output_should_match(final DepthTestCase depthTestCase) { " at " + TestFriendlyException.NAMED_MODULE_STACK_TRACE_ELEMENT, " at foo.TestFriendlyException.create(TestFriendlyException.java:0)", " at foo.TestFriendlyException.(TestFriendlyException.java:0)", - " at org.apache.logging.log4j.core.pattern.ThrowablePatternConverterTest.(ThrowablePatternConverterTest.java:0)", + " at " + TestFriendlyException.ORG_APACHE_REPLACEMENT_STACK_TRACE_ELEMENT, " Suppressed: foo.TestFriendlyException: r_s [localized]", " at foo.TestFriendlyException.create(TestFriendlyException.java:0)", " at foo.TestFriendlyException.create(TestFriendlyException.java:0)", @@ -308,7 +308,7 @@ void depth_and_package_limited_output_should_match_1(final DepthTestCase depthTe "foo.TestFriendlyException: r [localized]", " at " + TestFriendlyException.NAMED_MODULE_STACK_TRACE_ELEMENT, " ... suppressed 2 lines", - " at org.apache.logging.log4j.core.pattern.ThrowablePatternConverterTest.(ThrowablePatternConverterTest.java:0)", + " at " + TestFriendlyException.ORG_APACHE_REPLACEMENT_STACK_TRACE_ELEMENT, " Suppressed: foo.TestFriendlyException: r_s [localized]", " ... suppressed 2 lines", " ... 2 more", @@ -335,7 +335,7 @@ void depth_and_package_limited_output_should_match_1(final DepthTestCase depthTe @MethodSource("org.apache.logging.log4j.core.pattern.ThrowablePatternConverterTest#depthTestCases") void depth_and_package_limited_output_should_match_2(final DepthTestCase depthTestCase) { final String pattern = String.format( - "%s{%d}{filters(org.apache)}%s", + "%s{%d}{filters(bar)}%s", patternPrefix, depthTestCase.maxLineCount, depthTestCase.separatorTestCase.patternAddendum); assertStackTraceLines( depthTestCase, @@ -383,6 +383,15 @@ abstract static class AbstractStackTraceTest { this.patternPrefix = patternPrefix; } + @Test + void output_should_be_newline_prefixed() { + final String pattern = "%p" + patternPrefix; + final String stackTrace = convert(pattern); + final String expectedStart = + String.format("%s%n%s", LEVEL, EXCEPTION.getClass().getCanonicalName()); + assertThat(stackTrace).as("pattern=`%s`", pattern).startsWith(expectedStart); + } + @ParameterizedTest @MethodSource("org.apache.logging.log4j.core.pattern.ThrowablePatternConverterTest#separatorTestCases") void none_output_should_be_empty(final SeparatorTestCase separatorTestCase) { @@ -400,7 +409,7 @@ void assertStackTraceLines( final String conversionEnding; if (depthTestCase == null) { maxLineCount = Integer.MAX_VALUE; - conversionEnding = NEWLINE; + conversionEnding = LINE_SEPARATOR; } else { maxLineCount = depthTestCase.maxLineCount; conversionEnding = depthTestCase.separatorTestCase.conversionEnding; @@ -426,14 +435,14 @@ private static String normalizeStackTrace(final String stackTrace, final String } } - private static String convert(final String pattern) { + static String convert(final String pattern) { final List patternFormatters = PATTERN_PARSER.parse(pattern, false, true, true); - assertThat(patternFormatters).hasSize(1); - final PatternFormatter patternFormatter = patternFormatters.get(0); final LogEvent logEvent = Log4jLogEvent.newBuilder().setThrown(EXCEPTION).setLevel(LEVEL).build(); final StringBuilder buffer = new StringBuilder(); - patternFormatter.format(logEvent, buffer); + for (final PatternFormatter patternFormatter : patternFormatters) { + patternFormatter.format(logEvent, buffer); + } return buffer.toString(); } } diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/pattern/ThrowableTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/pattern/ThrowableTest.java deleted file mode 100644 index 3b25dce8da6..00000000000 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/pattern/ThrowableTest.java +++ /dev/null @@ -1,229 +0,0 @@ -/* - * 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.core.pattern; - -import static org.assertj.core.api.Assertions.assertThat; - -import java.io.PrintWriter; -import java.util.Collections; -import java.util.stream.Stream; -import org.apache.logging.log4j.Level; -import org.apache.logging.log4j.Logger; -import org.apache.logging.log4j.core.LoggerContext; -import org.apache.logging.log4j.core.LoggerTest; -import org.apache.logging.log4j.core.config.Configuration; -import org.apache.logging.log4j.core.config.Configurator; -import org.apache.logging.log4j.core.config.builder.api.ConfigurationBuilder; -import org.apache.logging.log4j.core.config.builder.api.ConfigurationBuilderFactory; -import org.apache.logging.log4j.core.config.builder.impl.BuiltConfiguration; -import org.apache.logging.log4j.core.test.appender.ListAppender; -import org.apache.logging.log4j.core.util.StringBuilderWriter; -import org.junit.Test; -import org.junit.jupiter.params.ParameterizedTest; -import org.junit.jupiter.params.provider.Arguments; -import org.junit.jupiter.params.provider.MethodSource; - -/** - * Unit tests for {@code throwable}, {@code rThrowable} and {@code xThrowable} pattern. - */ -public class ThrowableTest { - static Stream testConverter_dataSource() { - final String filters = "org.junit,org.apache.maven,sun.reflect,java.lang.reflect"; - final Integer depth = 5; - return Stream.of( - // Throwable - Arguments.of("%ex", filters, null, null, null), - Arguments.of("%ex", null, depth, null, null), - Arguments.of("%ex", null, null, "I am suffix", "#"), - // RootThrowable - Arguments.of("%rEx", filters, null, null, null), - Arguments.of("%rEx", null, depth, null, null), - Arguments.of("%rEx", null, null, "I am suffix", "#"), - // ExtendedThrowable - Arguments.of("%xEx", filters, null, null, null), - Arguments.of("%xEx", null, depth, null, null), - Arguments.of("%xEx", null, null, "I am suffix", "#")); - } - - @ParameterizedTest - @MethodSource("testConverter_dataSource") - void testConverter(String exceptionPattern, String filters, Integer depth, String suffix, String lineSeparator) { - final String pattern = buildPattern(exceptionPattern, filters, depth, suffix, lineSeparator); - final ConfigurationBuilder configBuilder = - ConfigurationBuilderFactory.newConfigurationBuilder(); - - final String appenderName = "LIST"; - final Configuration config = configBuilder - .add(configBuilder - .newAppender(appenderName, "List") - .add(configBuilder.newLayout("PatternLayout").addAttribute("pattern", pattern))) - .add(configBuilder.newRootLogger(Level.ALL).add(configBuilder.newAppenderRef(appenderName))) - .build(false); - - try (final LoggerContext loggerContext = Configurator.initialize(config)) { - // Restart logger context after first test run - if (loggerContext.isStopped()) { - loggerContext.start(); - loggerContext.reconfigure(config); - } - final Throwable r = createException("r", 1, 3); - - final Logger logger = loggerContext.getLogger(LoggerTest.class); - final ListAppender appender = loggerContext.getConfiguration().getAppender(appenderName); - logger.error("Exception", r); - - assertThat(appender.getMessages()).hasSize(1); - final String message = appender.getMessages().get(0); - assertThat(message).isNotNull(); - verifyFilters(message, filters); - verifyDepth(message, depth); - verifySuffix(message, suffix, lineSeparator); - } - } - - static Stream renderers_dataSource() { - return Stream.of( - Arguments.of(new ThrowableStackTraceRenderer<>(Collections.emptyList(), Integer.MAX_VALUE)), - Arguments.of(new ThrowableInvertedStackTraceRenderer(Collections.emptyList(), Integer.MAX_VALUE)), - Arguments.of(new ThrowableExtendedStackTraceRenderer(Collections.emptyList(), Integer.MAX_VALUE))); - } - - @ParameterizedTest - @MethodSource("renderers_dataSource") - void testCircularSuppressedExceptions(final ThrowableStackTraceRenderer renderer) { - final Exception e1 = new Exception(); - final Exception e2 = new Exception(); - e2.addSuppressed(e1); - e1.addSuppressed(e2); - - render(renderer, e1); - } - - @ParameterizedTest - @MethodSource("renderers_dataSource") - void testCircularSuppressedNestedException(final ThrowableStackTraceRenderer renderer) { - final Exception e1 = new Exception(); - final Exception e2 = new Exception(e1); - e2.addSuppressed(e1); - e1.addSuppressed(e2); - - render(renderer, e1); - } - - @ParameterizedTest - @MethodSource("renderers_dataSource") - void testCircularCauseExceptions(final ThrowableStackTraceRenderer renderer) { - final Exception e1 = new Exception(); - final Exception e2 = new Exception(e1); - e1.initCause(e2); - render(renderer, e1); - } - - /** - * Default setting ThrowableRenderer render output should equal to throwable.printStackTrace(). - */ - @Test - public void testThrowableRenderer() { - final Throwable throwable = createException("r", 1, 3); - final ThrowableStackTraceRenderer renderer = - new ThrowableStackTraceRenderer<>(Collections.emptyList(), Integer.MAX_VALUE); - String actual = render(renderer, throwable); - assertThat(actual).isEqualTo(getStandardThrowableStackTrace(throwable)); - } - - private static String render(final ThrowableStackTraceRenderer renderer, final Throwable throwable) { - final StringBuilder stringBuilder = new StringBuilder(); - renderer.renderThrowable(stringBuilder, throwable, System.lineSeparator()); - return stringBuilder.toString(); - } - - private static String getStandardThrowableStackTrace(final Throwable throwable) { - final StringBuilder buffer = new StringBuilder(); - final PrintWriter printWriter = new PrintWriter(new StringBuilderWriter(buffer)); - throwable.printStackTrace(printWriter); - return buffer.toString(); - } - - private static String buildPattern( - final String exceptionPattern, - final String filters, - final Integer depth, - final String suffix, - final String lineSeparator) { - final StringBuilder buffer = new StringBuilder("%m"); - buffer.append(exceptionPattern); - if (filters != null) { - buffer.append("{filters("); - buffer.append(filters); - buffer.append(")}"); - } - - if (depth != null) { - buffer.append("{"); - buffer.append(depth); - buffer.append("}"); - } - - if (suffix != null) { - buffer.append("{suffix("); - buffer.append(suffix); - buffer.append(")}"); - } - - if (lineSeparator != null) { - buffer.append("{separator("); - buffer.append(lineSeparator); - buffer.append(")}"); - } - return buffer.toString(); - } - - private static void verifyFilters(final String message, final String filters) { - if (filters != null) { - assertThat(message).contains("suppressed"); - final String[] filterArray = filters.split(","); - for (final String filter : filterArray) { - assertThat(message).doesNotContain(filter); - } - } else { - assertThat(message).doesNotContain("suppressed"); - } - } - - private static void verifyDepth(final String message, final Integer depth) { - if (depth != null) { - assertThat(message).hasLineCount(depth); - } - } - - private static void verifySuffix(final String message, final String suffix, final String lineSeparator) { - if (suffix != null && lineSeparator != null) { - for (String line : message.split(lineSeparator)) { - assertThat(line).endsWith(suffix); - } - } - } - - private static Throwable createException(final String name, int depth, int maxDepth) { - Exception r = new Exception(name); - if (depth < maxDepth) { - r.initCause(createException(name + "_c", depth + 1, maxDepth)); - r.addSuppressed(createException(name + "_s", depth + 1, maxDepth)); - } - return r; - } -} diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/ThrowablesTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/ThrowablesTest.java index 4d3cdfec3ef..912d62a1d90 100644 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/ThrowablesTest.java +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/ThrowablesTest.java @@ -21,51 +21,50 @@ import org.junit.jupiter.api.Test; -public class ThrowablesTest { +class ThrowablesTest { @Test - public void testGetRootCauseNone() { + void testGetRootCauseNone() { final NullPointerException throwable = new NullPointerException(); assertEquals(throwable, Throwables.getRootCause(throwable)); } @Test - public void testGetRootCauseDepth1() { + void testGetRootCauseDepth1() { final Throwable cause = new NullPointerException(); final Throwable error = new UnsupportedOperationException(cause); assertEquals(cause, Throwables.getRootCause(error)); } @Test - public void testGetRootCauseDepth2() { + void testGetRootCauseDepth2() { final Throwable rootCause = new NullPointerException(); final Throwable cause = new UnsupportedOperationException(rootCause); final Throwable error = new IllegalArgumentException(cause); assertEquals(rootCause, Throwables.getRootCause(error)); } - @SuppressWarnings("ThrowableNotThrown") @Test - public void testGetRootCauseLoop() { + void testGetRootCauseLoop() { final Throwable cause1 = new RuntimeException(); final Throwable cause2 = new RuntimeException(cause1); final Throwable cause3 = new RuntimeException(cause2); cause1.initCause(cause3); - assertThrows(IllegalArgumentException.class, () -> Throwables.getRootCause(cause3)); + assertEquals(cause1, Throwables.getRootCause(cause3)); } @Test - public void testRethrowRuntimeException() { + void testRethrowRuntimeException() { assertThrows(NullPointerException.class, () -> Throwables.rethrow(new NullPointerException())); } @Test - public void testRethrowError() { + void testRethrowError() { assertThrows(UnknownError.class, () -> Throwables.rethrow(new UnknownError())); } @Test - public void testRethrowCheckedException() { + void testRethrowCheckedException() { assertThrows(NoSuchMethodException.class, () -> Throwables.rethrow(new NoSuchMethodException())); } } diff --git a/log4j-core-test/src/test/resources/EventParameterMemoryLeakTest.xml b/log4j-core-test/src/test/resources/EventParameterMemoryLeakTest.xml deleted file mode 100644 index 54554cd97d0..00000000000 --- a/log4j-core-test/src/test/resources/EventParameterMemoryLeakTest.xml +++ /dev/null @@ -1,35 +0,0 @@ - - - - - - - %d %p %c{1.} [%t] %m %throwable{short.message}%n - - - - - - - - - diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ExtendedThrowablePatternConverter.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ExtendedThrowablePatternConverter.java index edeed932827..954cf250379 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ExtendedThrowablePatternConverter.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ExtendedThrowablePatternConverter.java @@ -33,7 +33,13 @@ public final class ExtendedThrowablePatternConverter extends ThrowablePatternConverter { private ExtendedThrowablePatternConverter(@Nullable final Configuration config, @Nullable final String[] options) { - super("ExtendedThrowable", "throwable", options, config, ExtendedThrowablePatternConverter::createRenderer); + super( + "ExtendedThrowable", + "throwable", + options, + config, + ThrowablePropertyRendererFactory.INSTANCE, + ThrowableExtendedStackTraceRendererFactory.INSTANCE); } private static ThrowableExtendedStackTraceRenderer createRenderer(final ThrowableFormatOptions options) { diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/RootThrowablePatternConverter.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/RootThrowablePatternConverter.java index 8b032a893d9..aae942d7a4d 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/RootThrowablePatternConverter.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/RootThrowablePatternConverter.java @@ -17,7 +17,6 @@ package org.apache.logging.log4j.core.pattern; import org.apache.logging.log4j.core.config.Configuration; -import org.apache.logging.log4j.core.impl.ThrowableFormatOptions; import org.apache.logging.log4j.plugins.Namespace; import org.apache.logging.log4j.plugins.Plugin; import org.jspecify.annotations.NullMarked; @@ -33,11 +32,13 @@ public final class RootThrowablePatternConverter extends ThrowablePatternConverter { private RootThrowablePatternConverter(@Nullable final Configuration config, @Nullable final String[] options) { - super("RootThrowable", "throwable", options, config, RootThrowablePatternConverter::createRenderer); - } - - private static ThrowableInvertedStackTraceRenderer createRenderer(final ThrowableFormatOptions options) { - return new ThrowableInvertedStackTraceRenderer(options.getIgnorePackages(), options.getLines()); + super( + "RootThrowable", + "throwable", + options, + config, + ThrowableInvertedPropertyRendererFactory.INSTANCE, + ThrowableInvertedStackTraceRendererFactory.INSTANCE); } /** diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableExtendedStackTraceRendererFactory.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableExtendedStackTraceRendererFactory.java new file mode 100644 index 00000000000..d95399c21b6 --- /dev/null +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableExtendedStackTraceRendererFactory.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.core.pattern; + +import org.apache.logging.log4j.core.impl.ThrowableFormatOptions; + +final class ThrowableExtendedStackTraceRendererFactory extends ThrowableStackTraceRendererFactory { + + static final ThrowableExtendedStackTraceRendererFactory INSTANCE = new ThrowableExtendedStackTraceRendererFactory(); + + private ThrowableExtendedStackTraceRendererFactory() {} + + @Override + ThrowableExtendedStackTraceRenderer createStackTraceRenderer(ThrowableFormatOptions options) { + return new ThrowableExtendedStackTraceRenderer(options.getIgnorePackages(), options.getLines()); + } +} diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableInvertedPropertyRendererFactory.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableInvertedPropertyRendererFactory.java new file mode 100644 index 00000000000..4d0e8eaa431 --- /dev/null +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableInvertedPropertyRendererFactory.java @@ -0,0 +1,40 @@ +/* + * 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.core.pattern; + +import org.apache.logging.log4j.core.util.Throwables; +import org.jspecify.annotations.NullMarked; +import org.jspecify.annotations.Nullable; + +/** + * {@link ThrowablePropertyRendererFactory} implementation where the causal chain will be processed in reverse order. + */ +@NullMarked +final class ThrowableInvertedPropertyRendererFactory extends ThrowablePropertyRendererFactory { + + static final ThrowableInvertedPropertyRendererFactory INSTANCE = new ThrowableInvertedPropertyRendererFactory(); + + private ThrowableInvertedPropertyRendererFactory() { + super(ThrowableInvertedPropertyRendererFactory::extractThrowingMethod); + } + + @Nullable + private static StackTraceElement extractThrowingMethod(final Throwable throwable) { + final Throwable rootThrowable = Throwables.getRootCause(throwable); + return rootThrowable.getStackTrace()[0]; + } +} diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableInvertedStackTraceRenderer.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableInvertedStackTraceRenderer.java index 786016f5496..6ad7173462b 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableInvertedStackTraceRenderer.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableInvertedStackTraceRenderer.java @@ -21,7 +21,7 @@ import org.jspecify.annotations.Nullable; /** - * {@link ThrowableStackTraceRenderer} variant where the stack trace causal chain is rendered in reverse order. + * {@link ThrowableStackTraceRenderer} variant where the stack trace causal chain is processed in reverse order. */ final class ThrowableInvertedStackTraceRenderer extends ThrowableStackTraceRenderer { diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableInvertedStackTraceRendererFactory.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableInvertedStackTraceRendererFactory.java new file mode 100644 index 00000000000..d8c61eda9b4 --- /dev/null +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableInvertedStackTraceRendererFactory.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.core.pattern; + +import org.apache.logging.log4j.core.impl.ThrowableFormatOptions; + +final class ThrowableInvertedStackTraceRendererFactory extends ThrowableStackTraceRendererFactory { + + static final ThrowableInvertedStackTraceRendererFactory INSTANCE = new ThrowableInvertedStackTraceRendererFactory(); + + private ThrowableInvertedStackTraceRendererFactory() {} + + @Override + ThrowableInvertedStackTraceRenderer createStackTraceRenderer(ThrowableFormatOptions options) { + return new ThrowableInvertedStackTraceRenderer(options.getIgnorePackages(), options.getLines()); + } +} diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowablePatternConverter.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowablePatternConverter.java index d22926b7811..aa6009ed2fb 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowablePatternConverter.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowablePatternConverter.java @@ -55,15 +55,15 @@ public class ThrowablePatternConverter extends LogEventPatternConverter { private final ThrowableRenderer renderer; /** - * @deprecated Use {@link #ThrowablePatternConverter(String, String, String[], Configuration, Function)} instead. + * @deprecated Use {@link #ThrowablePatternConverter(String, String, String[], Configuration, ThrowablePropertyRendererFactory, ThrowableStackTraceRendererFactory)} instead. */ @Deprecated protected ThrowablePatternConverter(final String name, final String style, @Nullable final String[] options) { - this(name, style, options, null, null); + this(name, style, options, null, null, null); } /** - * @deprecated Use {@link #ThrowablePatternConverter(String, String, String[], Configuration, Function)} instead. + * @deprecated Use {@link #ThrowablePatternConverter(String, String, String[], Configuration, ThrowablePropertyRendererFactory, ThrowableStackTraceRendererFactory)} instead. */ @Deprecated protected ThrowablePatternConverter( @@ -71,7 +71,7 @@ protected ThrowablePatternConverter( final String style, @Nullable final String[] options, @Nullable final Configuration config) { - this(name, style, options, config, null); + this(name, style, options, config, null, null); } /** @@ -89,8 +89,8 @@ protected ThrowablePatternConverter( final String style, @Nullable final String[] options, @Nullable final Configuration config, - @Nullable - final Function> stackTraceRendererFactory) { + @Nullable final ThrowablePropertyRendererFactory propertyRendererFactory, + @Nullable final ThrowableStackTraceRendererFactory stackTraceRendererFactory) { // Process `name`, `style`, and `options` super(name, style); @@ -103,16 +103,8 @@ protected ThrowablePatternConverter( this.formatters = Collections.unmodifiableList(suffixFormatters); // Create the effective renderer - final ThrowablePropertyRenderer propertyRenderer = ThrowablePropertyRenderer.fromOptions(options); - if (propertyRenderer != null) { - this.renderer = propertyRenderer; - } else { - final Function> effectiveRendererFactory = - stackTraceRendererFactory != null - ? stackTraceRendererFactory - : ThrowablePatternConverter::createRenderer; - this.renderer = effectiveRendererFactory.apply(this.options); - } + this.renderer = + createEffectiveRenderer(options, this.options, propertyRendererFactory, stackTraceRendererFactory); } /** @@ -124,7 +116,7 @@ protected ThrowablePatternConverter( */ public static ThrowablePatternConverter newInstance( @Nullable final Configuration config, @Nullable final String[] options) { - return new ThrowablePatternConverter("Throwable", "throwable", options, config, null); + return new ThrowablePatternConverter("Throwable", "throwable", options, config, null, null); } /** @@ -137,18 +129,10 @@ public void format(final LogEvent event, final StringBuilder buffer) { final Throwable throwable = event.getThrown(); if (throwable != null) { final String lineSeparator = effectiveLineSeparatorProvider.apply(event); - ensureWhitespaceSuffix(buffer); renderer.renderThrowable(buffer, throwable, lineSeparator); } } - private static void ensureWhitespaceSuffix(final StringBuilder buffer) { - final int bufferLength = buffer.length(); - if (bufferLength > 0 && !Character.isWhitespace(buffer.charAt(bufferLength - 1))) { - buffer.append(' '); - } - } - /** * Indicates this converter handles {@link Throwable}s. * @@ -234,8 +218,25 @@ private static Function createEffectiveLineSeparator( } } - private static ThrowableStackTraceRenderer createRenderer(final ThrowableFormatOptions options) { - return new ThrowableStackTraceRenderer<>(options.getIgnorePackages(), options.getLines()); + private static ThrowableRenderer createEffectiveRenderer( + final String[] rawOptions, + final ThrowableFormatOptions options, + @Nullable final ThrowablePropertyRendererFactory propertyRendererFactory, + @Nullable final ThrowableStackTraceRendererFactory stackTraceRendererFactory) { + + // Try to create a property renderer first + final ThrowablePropertyRendererFactory effectivePropertyRendererFactory = + propertyRendererFactory != null ? propertyRendererFactory : ThrowablePropertyRendererFactory.INSTANCE; + final ThrowableRenderer propertyRenderer = effectivePropertyRendererFactory.createPropertyRenderer(rawOptions); + if (propertyRenderer != null) { + return propertyRenderer; + } + + // Create a stack trace renderer + final ThrowableStackTraceRendererFactory effectiveStackTraceRendererFactory = stackTraceRendererFactory != null + ? stackTraceRendererFactory + : ThrowableStackTraceRendererFactory.INSTANCE; + return effectiveStackTraceRendererFactory.createStackTraceRenderer(options); } /** diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowablePropertyRenderer.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowablePropertyRenderer.java deleted file mode 100644 index 62fce22e67b..00000000000 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowablePropertyRenderer.java +++ /dev/null @@ -1,98 +0,0 @@ -/* - * 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.core.pattern; - -import org.apache.logging.log4j.core.impl.ThrowableFormatOptions; -import org.jspecify.annotations.NullMarked; -import org.jspecify.annotations.Nullable; - -@NullMarked -enum ThrowablePropertyRenderer implements ThrowableRenderer { - MESSAGE(ThrowableFormatOptions.MESSAGE, (buffer, throwable, lineSeparator) -> { - final String message = throwable.getMessage(); - buffer.append(message); - buffer.append(lineSeparator); - }), - LOCALIZED_MESSAGE(ThrowableFormatOptions.LOCALIZED_MESSAGE, (buffer, throwable, lineSeparator) -> { - final String localizedMessage = throwable.getLocalizedMessage(); - buffer.append(localizedMessage); - buffer.append(lineSeparator); - }), - CLASS_NAME(ThrowableFormatOptions.CLASS_NAME, ((buffer, throwable, lineSeparator) -> { - @Nullable final StackTraceElement[] stackTraceElements = throwable.getStackTrace(); - if (stackTraceElements != null && stackTraceElements.length > 0) { - final StackTraceElement throwingMethod = stackTraceElements[0]; - final String className = throwingMethod.getClassName(); - buffer.append(className); - buffer.append(lineSeparator); - } - })), - METHOD_NAME(ThrowableFormatOptions.METHOD_NAME, ((buffer, throwable, lineSeparator) -> { - @Nullable final StackTraceElement[] stackTraceElements = throwable.getStackTrace(); - if (stackTraceElements != null && stackTraceElements.length > 0) { - final StackTraceElement throwingMethod = stackTraceElements[0]; - final String methodName = throwingMethod.getMethodName(); - buffer.append(methodName); - buffer.append(lineSeparator); - } - })), - LINE_NUMBER(ThrowableFormatOptions.LINE_NUMBER, ((buffer, throwable, lineSeparator) -> { - @Nullable final StackTraceElement[] stackTraceElements = throwable.getStackTrace(); - if (stackTraceElements != null && stackTraceElements.length > 0) { - final StackTraceElement throwingMethod = stackTraceElements[0]; - final int lineNumber = throwingMethod.getLineNumber(); - buffer.append(lineNumber); - buffer.append(lineSeparator); - } - })), - FILE_NAME(ThrowableFormatOptions.FILE_NAME, ((buffer, throwable, lineSeparator) -> { - @Nullable final StackTraceElement[] stackTraceElements = throwable.getStackTrace(); - if (stackTraceElements != null && stackTraceElements.length > 0) { - final StackTraceElement throwingMethod = stackTraceElements[0]; - final String fileName = throwingMethod.getFileName(); - buffer.append(fileName); - buffer.append(lineSeparator); - } - })); - - private final String name; - - private final ThrowableRenderer delegate; - - ThrowablePropertyRenderer(final String name, final ThrowableRenderer delegate) { - this.name = name; - this.delegate = delegate; - } - - @Override - public void renderThrowable(final StringBuilder buffer, final Throwable throwable, final String lineSeparator) { - delegate.renderThrowable(buffer, throwable, lineSeparator); - } - - @Nullable - static ThrowablePropertyRenderer fromOptions(@Nullable final String[] options) { - if (options != null && options.length > 0) { - final String name = options[0]; - for (final ThrowablePropertyRenderer renderer : values()) { - if (renderer.name.equalsIgnoreCase(name)) { - return renderer; - } - } - } - return null; - } -} diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowablePropertyRendererFactory.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowablePropertyRendererFactory.java new file mode 100644 index 00000000000..c0fc7611176 --- /dev/null +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowablePropertyRendererFactory.java @@ -0,0 +1,120 @@ +/* + * 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.core.pattern; + +import java.util.HashMap; +import java.util.Map; +import java.util.function.Function; +import org.apache.logging.log4j.core.impl.ThrowableFormatOptions; +import org.jspecify.annotations.NullMarked; +import org.jspecify.annotations.Nullable; + +/** + * A factory of {@link ThrowableRenderer} implementations for extracting certain properties from a {@link Throwable}. + */ +@NullMarked +class ThrowablePropertyRendererFactory { + + private static final ThrowableRenderer MESSAGE_RENDERER = (buffer, throwable, lineSeparator) -> { + final String message = throwable.getMessage(); + buffer.append(message); + }; + + private static final ThrowableRenderer LOCALIZED_MESSAGE_RENDERER = (buffer, throwable, lineSeparator) -> { + final String localizedMessage = throwable.getLocalizedMessage(); + buffer.append(localizedMessage); + }; + + private static final Function THROWING_METHOD_EXTRACTOR = throwable -> { + @Nullable final StackTraceElement[] stackTraceElements = throwable.getStackTrace(); + return (stackTraceElements != null && stackTraceElements.length > 0) ? stackTraceElements[0] : null; + }; + + static final ThrowablePropertyRendererFactory INSTANCE = + new ThrowablePropertyRendererFactory(THROWING_METHOD_EXTRACTOR); + + private final Map rendererByPropertyName; + + ThrowablePropertyRendererFactory(final Function throwingMethodExtractor) { + this.rendererByPropertyName = createRendererByPropertyName(throwingMethodExtractor); + } + + private static Map createRendererByPropertyName( + final Function throwingMethodExtractor) { + final Map map = new HashMap<>(); + map.put(ThrowableFormatOptions.MESSAGE, MESSAGE_RENDERER); + map.put(ThrowableFormatOptions.LOCALIZED_MESSAGE, LOCALIZED_MESSAGE_RENDERER); + map.put(ThrowableFormatOptions.CLASS_NAME, createClassNameRenderer(throwingMethodExtractor)); + map.put(ThrowableFormatOptions.METHOD_NAME, createMethodNameRenderer(throwingMethodExtractor)); + map.put(ThrowableFormatOptions.LINE_NUMBER, createLineNumberRenderer(throwingMethodExtractor)); + map.put(ThrowableFormatOptions.FILE_NAME, createFileNameRenderer(throwingMethodExtractor)); + return map; + } + + private static ThrowableRenderer createClassNameRenderer( + final Function throwingMethodExtractor) { + return (buffer, throwable, lineSeparator) -> { + @Nullable final StackTraceElement throwingMethod = throwingMethodExtractor.apply(throwable); + if (throwingMethod != null) { + final String className = throwingMethod.getClassName(); + buffer.append(className); + } + }; + } + + private static ThrowableRenderer createMethodNameRenderer( + final Function throwingMethodExtractor) { + return (buffer, throwable, lineSeparator) -> { + @Nullable final StackTraceElement throwingMethod = throwingMethodExtractor.apply(throwable); + if (throwingMethod != null) { + final String methodName = throwingMethod.getMethodName(); + buffer.append(methodName); + } + }; + } + + private static ThrowableRenderer createLineNumberRenderer( + final Function throwingMethodExtractor) { + return (buffer, throwable, lineSeparator) -> { + @Nullable final StackTraceElement throwingMethod = throwingMethodExtractor.apply(throwable); + if (throwingMethod != null) { + final int lineNumber = throwingMethod.getLineNumber(); + buffer.append(lineNumber); + } + }; + } + + private static ThrowableRenderer createFileNameRenderer( + final Function throwingMethodExtractor) { + return (buffer, throwable, lineSeparator) -> { + @Nullable final StackTraceElement throwingMethod = throwingMethodExtractor.apply(throwable); + if (throwingMethod != null) { + final String fileName = throwingMethod.getFileName(); + buffer.append(fileName); + } + }; + } + + @Nullable + final ThrowableRenderer createPropertyRenderer(@Nullable final String[] options) { + if (options != null && options.length > 0) { + final String propertyName = options[0]; + return rendererByPropertyName.get(propertyName); + } + return null; + } +} diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableStackTraceRenderer.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableStackTraceRenderer.java index b16e9b98362..a6211147a83 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableStackTraceRenderer.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableStackTraceRenderer.java @@ -16,6 +16,8 @@ */ package org.apache.logging.log4j.core.pattern; +import static org.apache.logging.log4j.util.Strings.LINE_SEPARATOR; + import java.util.HashMap; import java.util.HashSet; import java.util.List; @@ -53,6 +55,7 @@ public final void renderThrowable( if (maxLineCount > 0) { try { C context = createContext(throwable); + ensureNewlineSuffix(buffer); renderThrowable(buffer, throwable, context, new HashSet<>(), lineSeparator); } catch (final Exception error) { if (error != MAX_LINE_COUNT_EXCEEDED) { @@ -62,6 +65,13 @@ public final void renderThrowable( } } + private static void ensureNewlineSuffix(final StringBuilder buffer) { + final int bufferLength = buffer.length(); + if (bufferLength > 0 && buffer.charAt(bufferLength - 1) != '\n') { + buffer.append(LINE_SEPARATOR); + } + } + @SuppressWarnings("unchecked") C createContext(final Throwable throwable) { final Map metadataByThrowable = Context.Metadata.ofThrowable(throwable); diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableStackTraceRendererFactory.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableStackTraceRendererFactory.java new file mode 100644 index 00000000000..4e6fee7fcc9 --- /dev/null +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableStackTraceRendererFactory.java @@ -0,0 +1,33 @@ +/* + * 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.core.pattern; + +import org.apache.logging.log4j.core.impl.ThrowableFormatOptions; + +/** + * A {@link ThrowableStackTraceRenderer} factory contract. + */ +class ThrowableStackTraceRendererFactory { + + static final ThrowableStackTraceRendererFactory INSTANCE = new ThrowableStackTraceRendererFactory(); + + ThrowableStackTraceRendererFactory() {} + + ThrowableStackTraceRenderer createStackTraceRenderer(final ThrowableFormatOptions options) { + return new ThrowableStackTraceRenderer<>(options.getIgnorePackages(), options.getLines()); + } +} diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/Throwables.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/Throwables.java index 226b0f10cbe..7c97d495ba4 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/Throwables.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/Throwables.java @@ -16,6 +16,8 @@ */ package org.apache.logging.log4j.core.util; +import static java.util.Objects.requireNonNull; + import edu.umd.cs.findbugs.annotations.SuppressFBWarnings; import java.io.IOException; import java.io.InterruptedIOException; @@ -24,7 +26,9 @@ import java.io.StringReader; import java.io.StringWriter; import java.util.ArrayList; +import java.util.HashSet; import java.util.List; +import java.util.Set; /** * Helps with Throwable objects. @@ -34,31 +38,22 @@ public final class Throwables { private Throwables() {} /** - * Returns the deepest cause of the given {@code throwable}. + * Extracts the deepest exception in the causal chain of the given {@code throwable}. + * Circular references will be handled and ignored. * - * @param throwable the throwable to navigate - * @return the deepest throwable or the given throwable + * @param throwable a throwable to navigate + * @return the deepest exception in the causal chain */ public static Throwable getRootCause(final Throwable throwable) { - - // Keep a second pointer that slowly walks the causal chain. If the fast - // pointer ever catches the slower pointer, then there's a loop. - Throwable slowPointer = throwable; - boolean advanceSlowPointer = false; - - Throwable parent = throwable; - Throwable cause; - while ((cause = parent.getCause()) != null) { - parent = cause; - if (parent == slowPointer) { - throw new IllegalArgumentException("loop in causal chain"); - } - if (advanceSlowPointer) { - slowPointer = slowPointer.getCause(); - } - advanceSlowPointer = !advanceSlowPointer; // only advance every other iteration + requireNonNull(throwable, "throwable"); + final Set visitedThrowables = new HashSet<>(); + Throwable prevCause = throwable; + visitedThrowables.add(prevCause); + Throwable nextCause; + while ((nextCause = prevCause.getCause()) != null && visitedThrowables.add(nextCause)) { + prevCause = nextCause; } - return parent; + return prevCause; } /** diff --git a/log4j-layout-template-json/src/main/java/org/apache/logging/log4j/layout/template/json/resolver/StackTraceStringResolver.java b/log4j-layout-template-json/src/main/java/org/apache/logging/log4j/layout/template/json/resolver/StackTraceStringResolver.java index dddf66f7277..5a3e727a9c4 100644 --- a/log4j-layout-template-json/src/main/java/org/apache/logging/log4j/layout/template/json/resolver/StackTraceStringResolver.java +++ b/log4j-layout-template-json/src/main/java/org/apache/logging/log4j/layout/template/json/resolver/StackTraceStringResolver.java @@ -16,6 +16,8 @@ */ package org.apache.logging.log4j.layout.template.json.resolver; +import static org.apache.logging.log4j.util.Strings.LINE_SEPARATOR; + import java.util.List; import java.util.function.Consumer; import java.util.function.Supplier; @@ -126,7 +128,7 @@ private void truncate( final int truncationPointIndex = findTruncationPointIndex(srcWriter, startIndex, endIndex, sequencePointer); if (truncationPointIndex > 0) { dstWriter.append(srcWriter, startIndex, truncationPointIndex); - dstWriter.append(System.lineSeparator()); + dstWriter.append(LINE_SEPARATOR); dstWriter.append(truncationSuffix); } @@ -137,7 +139,7 @@ private void truncate( // Copy the label to avoid stepping over it again. if (labeledLineStartIndex > 0) { - dstWriter.append(System.lineSeparator()); + dstWriter.append(LINE_SEPARATOR); startIndex = labeledLineStartIndex; for (; ; ) { final char c = srcWriter.charAt(startIndex++); diff --git a/src/site/antora/modules/ROOT/pages/manual/pattern-layout.adoc b/src/site/antora/modules/ROOT/pages/manual/pattern-layout.adoc index 57c29d892f8..c7544624773 100644 --- a/src/site/antora/modules/ROOT/pages/manual/pattern-layout.adoc +++ b/src/site/antora/modules/ROOT/pages/manual/pattern-layout.adoc @@ -142,7 +142,7 @@ xref:manual/lookups.adoc#event-context[event evaluation context]. [WARNING] ==== -If the provided pattern does not contain an exception converter and <> is not disabled, an implicit <> is appended to the pattern. +If the provided pattern does not contain an exception converter and <> is not disabled, an implicit <> is appended to the pattern. ==== [#plugin-attr-patternSelector] @@ -176,7 +176,7 @@ If configured, the `replace` element must specify the regular expression to matc |Default value |`true` |=== -If `true` and the user-provided pattern does not contain an exception converter, an implicit <> pattern is appended. +If `true` and the user-provided pattern does not contain an exception converter, an implicit <> pattern is appended. This means that if you do not include a way to output exceptions in your pattern, the default exception formatter will be added to the end of the pattern. Setting this to `false` disables this behavior and allows you to exclude exceptions from your pattern output. @@ -599,69 +599,76 @@ equals{pattern}{test}{substitution} equalsIgnoreCase{pattern}{test}{substitution} ---- -For example, `%equals{[%marker]}{[]}\{}` will replace `[]` strings produced by events without markers with an empty string. +For example, `%equals{[%marker]}{[]}{}` will replace `[]` strings produced by events without markers with an empty string. The pattern can be arbitrarily complex and in particular can contain multiple conversion keywords. [#converter-exception] ==== Exception -Outputs the `Throwable` attached to the log event +Outputs information extracted from the `Throwable` attached to the log event. +It features two modes: -.link:../javadoc/log4j-core/org/apache/logging/log4j/core/pattern/ThrowablePatternConverter.html[`ThrowablePatternConverter`] specifier grammar +. <> (the default mode) +. <> (message, class name, line number, etc.) + +[WARNING] +==== +Exception converter is not garbage-free. +==== + +[#converter-exception-stack-trace] +===== Exception stack trace + +In this mode, the exception stack trace will be rendered according to the configuration provided. + +[IMPORTANT] +==== +All rendered exception stack traces are ensured to be prefixed with a new line obtained using `System.lineSeparator()`. +==== + +link:../javadoc/log4j-core/org/apache/logging/log4j/core/pattern/ThrowablePatternConverter.html[`ThrowablePatternConverter`] specifier grammar **for rendering stack traces**: [source,text] ---- ex|exception|throwable { "none" - | "full" - | depth | "short" - | "short.className" - | "short.fileName" - | "short.lineNumber" - | "short.methodName" - | "short.message" - | "short.localizedMessage" + | depth + | "full" } {filters(package,package,...)} + {separator(text)} {suffix(pattern)} - {separator(separator)} ---- -By default this will output the full stack trace as one would normally find with a call to `Throwable#printStackTrace()`. - -You can follow the throwable conversion word with an option in the form `%throwable\{option}`. - -`%throwable\{short}` outputs the first line of the `Throwable`. - -`%throwable{short.className}` outputs the name of the class where the exception occurred. - -`%throwable{short.methodName}` outputs the name of the method where the exception occurred. +If this mode is employed without any configuration, the output will be identical to the one obtained from `Throwable#printStackTrace()`. -`%throwable{short.fileName}` outputs the name of the file containing the class where the exception occurred. +`none`:: Suppress the output of the converter -`%throwable{short.lineNumber}` outputs the line number of the file containing the class where the exception occurred. +`short`:: Outputs the first line of the stack trace (analogous to `%ex\{1}`) -`%throwable{short.message}` outputs the message. +`depth`:: Outputs the first `depth` lines of the stack trace (`%ex\{0}` is analogous to `%ex\{none}`) -`%throwable{short.localizedMessage}` outputs the localized message. +`full`:: Outputs the complete stack trace (analogous to no configuration) -`%throwable\{n}` outputs the first `n` lines of the stack trace. - -Specifying `%throwable\{none}` or `%throwable\{0}` suppresses output of the exception. - -Use `{filters(packages)}`, where `packages` is a list of package names, to suppress matching stack frames from stack traces. +`filters(package,package,...)`:: Suppresses stack trace elements of classes located in packages whose names start with the package names provided. +Suppressed stack trace elements will be denoted in the output. +For instance, `%ex{filters(org.junit)}` can be used to suppress JUnit classes in the rendered stack trace. +`separator(text)`:: +`suffix(pattern)`:: ++ +-- You can change the used line separator in multiple ways: -* Use `{separator(separator)}` to set the separator string literal. +* Use `separator(text)` to set the separator string literal. It defaults to `System.lineSeparator()`. -The contents of `separator` will be rendered verbatim without being subject to any processing. +The contents of `text` will be rendered verbatim without being subject to any processing. -* `{suffix(pattern)}` is identical to `{separator(separator)}` with the exception that the provided `pattern` will be processed as a xref:manual/pattern-layout.adoc[] conversion pattern before being rendered. +* `suffix(pattern)` is identical to `{separator(text)}` with the exception that the provided `pattern` will be processed as a xref:manual/pattern-layout.adoc[] conversion pattern before being rendered. Exception-rendering directives in the `pattern` (`%ex`, `%rEx`, etc.) will be discarded. -`{separator(...)}` and `{suffix(pattern)}` get concatenated to produce _the effective line separator_ as follows: +`{separator(text)}` and `{suffix(pattern)}` get concatenated to produce _the effective line separator_ as follows: [source,java] ---- @@ -673,38 +680,52 @@ String effectiveLineSeparator(String separator, String suffix, LogEvent event) { } ---- -[WARNING] +[TIP] ==== -Exception converter is not garbage-free. +You are strongly advised to avoid using both `separator(text)` and `suffix(pattern)` at the same time; simply use one instead. ==== +-- -[#converter-exception-extended] -==== Exception (Extended) +[#converter-exception-property] +===== Exception property -The same as <>, but also includes class packaging information +In this mode, extracted attributes of the `Throwable` are injected _verbatim_. +That is, no newlines, suffixes, prefixes, etc. will be added. -.link:../javadoc/log4j-core/org/apache/logging/log4j/core/pattern/ThrowablePatternConverter.html[`ThrowablePatternConverter`] specifier grammar +link:../javadoc/log4j-core/org/apache/logging/log4j/core/pattern/ThrowablePatternConverter.html[`ThrowablePatternConverter`] specifier grammar **for extracting properties**: [source,text] ---- -xEx|xException|xThrowable - { "none" - | "full" - | depth - | "short" - | "short.className" +ex|exception|throwable + { "short.className" | "short.fileName" | "short.lineNumber" | "short.methodName" | "short.message" | "short.localizedMessage" } - {filters(package,package,...)} - {suffix(pattern)} - {separator(separator)} ---- -Different from <>, at the end of each stack element of the exception, a string containing the name of the JAR file that contains the class or the directory the class is located in and the `Implementation-Version` as found in that JAR's manifest will be added. -If the information is uncertain, then the class packaging data will be preceded by a `~` (tilde) character. +`short.className`:: Class name of the first stack trace element in the causal chain +`short.fileName`:: File name of the first stack trace element in the causal chain +`short.lineNumber`:: Line number of the first stack trace element in the causal chain +`short.methodName`:: Method name of the first stack trace element in the causal chain +`short.message`:: Exception message +`short.message`:: Localized exception message + +[#converter-exception-extended] +==== Exception (Extended) + +The same as <>, but additionally includes class packaging information in the rendered stack traces. + +.link:../javadoc/log4j-core/org/apache/logging/log4j/core/pattern/ExtendedThrowablePatternConverter.html[`ExtendedThrowablePatternConverter`] specifier grammar +[source,text] +---- +xEx|xException|xThrowable + [... same as the exception converter grammar ...] +---- + +Each stack trace element is suffixed with a string containing the name of the JAR file that contains the class (or the directory the class is located in) and the `Implementation-Version` as found in that JAR's manifest. +If the information is uncertain, then the class packaging information will be preceded by a `~` (tilde) character. [#converter-file] ==== File @@ -1194,28 +1215,21 @@ For instance, `%replace{%logger %msg}{\.}{/}` will replace all dots in the logge [#converter-rootException] ==== Root exception -The same as <>, but the stack trace is printed starting with the first exception in the causal chain that was thrown followed by each subsequent wrapping exception +Same as <>, but the stack trace causal chain is processed in reverse order. .link:../javadoc/log4j-core/org/apache/logging/log4j/core/pattern/RootThrowablePatternConverter.html[`RootThrowablePatternConverter`] specifier grammar [source,text] ---- rEx|rException|rThrowable - { "none" - | "full" - | depth - | "short" - | "short.className" - | "short.fileName" - | "short.lineNumber" - | "short.methodName" - | "short.message" - | "short.localizedMessage" - } - {filters(package,package,...)} - {suffix(pattern)} - {separator(separator)} + [... same as the exception converter grammar ...] ---- +[IMPORTANT] +==== +Note that the inverted causal chain will not only affect the stack trace, but also extracted properties. +That is, for instance, `%rEx{short.className}` and `%ex{short.className}` might yield different results. +==== + [#converter-seq] ==== Sequence number