Skip to content

Commit 0784be4

Browse files
vyalan0428appkarwasz
authored
Prefix stack traces with a newline in Pattern Layout (#3073)
- 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}) - Ports #3045 Co-authored-by: AlanYu <[email protected]> Co-authored-by: Piotr P. Karwasz <[email protected]>
1 parent cd5f01e commit 0784be4

File tree

32 files changed

+899
-789
lines changed

32 files changed

+899
-789
lines changed

‎log4j-async-logger/src/test/java/org/apache/logging/log4j/async/logger/AsyncLoggerTestArgumentFreedOnErrorTest.java

+28-36
Original file line numberDiff line numberDiff line change
@@ -16,63 +16,55 @@
1616
*/
1717
package org.apache.logging.log4j.async.logger;
1818

19-
import static org.junit.jupiter.api.Assertions.assertTrue;
19+
import static org.apache.logging.log4j.core.test.internal.GcHelper.awaitGarbageCollection;
2020

21-
import java.util.concurrent.CountDownLatch;
22-
import java.util.concurrent.TimeUnit;
23-
import org.apache.logging.log4j.LogManager;
24-
import org.apache.logging.log4j.core.GarbageCollectionHelper;
21+
import org.apache.logging.log4j.core.Logger;
22+
import org.apache.logging.log4j.core.LoggerContext;
2523
import org.apache.logging.log4j.core.test.TestConstants;
26-
import org.apache.logging.log4j.core.test.junit.ContextSelectorType;
2724
import org.apache.logging.log4j.message.Message;
25+
import org.apache.logging.log4j.plugins.di.DI;
2826
import org.apache.logging.log4j.test.junit.SetTestProperty;
27+
import org.apache.logging.log4j.test.junit.UsingStatusListener;
2928
import org.apache.logging.log4j.util.StringBuilderFormattable;
3029
import org.junit.jupiter.api.Tag;
3130
import org.junit.jupiter.api.Test;
31+
import org.junit.jupiter.api.TestInfo;
3232

3333
@Tag("async")
34-
@SetTestProperty(key = TestConstants.GC_ENABLE_DIRECT_ENCODERS, value = "true")
35-
@SetTestProperty(key = TestConstants.ASYNC_FORMAT_MESSAGES_IN_BACKGROUND, value = "true")
36-
@ContextSelectorType(AsyncLoggerContextSelector.class)
37-
public class AsyncLoggerTestArgumentFreedOnErrorTest {
34+
class AsyncLoggerArgumentFreedOnErrorTest {
3835

39-
// LOG4J2-2725: events are cleared even after failure
36+
/**
37+
* Tests events are cleared even after failure.
38+
*
39+
* @see <a href="https://issues.apache.org/jira/browse/LOG4J2-2725">LOG4J2-2725</a>
40+
*/
4041
@Test
41-
public void testMessageIsGarbageCollected() throws Exception {
42-
final AsyncLogger log = (AsyncLogger) LogManager.getLogger("com.foo.Bar");
43-
final CountDownLatch garbageCollectionLatch = new CountDownLatch(1);
44-
log.fatal(new ThrowingMessage(garbageCollectionLatch));
45-
try (final GarbageCollectionHelper gcHelper = new GarbageCollectionHelper()) {
46-
gcHelper.run();
47-
assertTrue(
48-
garbageCollectionLatch.await(30, TimeUnit.SECONDS), "Parameter should have been garbage collected");
49-
}
42+
@UsingStatusListener // Suppresses `StatusLogger` output, unless there is a failure
43+
@SetTestProperty(key = TestConstants.GC_ENABLE_DIRECT_ENCODERS, value = "true")
44+
@SetTestProperty(key = TestConstants.ASYNC_FORMAT_MESSAGES_IN_BACKGROUND, value = "true")
45+
void parameters_throwing_exception_should_be_garbage_collected(final TestInfo testInfo) throws Exception {
46+
awaitGarbageCollection(() -> {
47+
final String loggerContextName = String.format("%s-LC", testInfo.getDisplayName());
48+
try (final LoggerContext loggerContext =
49+
new AsyncLoggerContext(loggerContextName, null, null, DI.createInitializedFactory())) {
50+
loggerContext.start();
51+
final Logger logger = loggerContext.getRootLogger();
52+
final ThrowingMessage parameter = new ThrowingMessage();
53+
logger.fatal(parameter);
54+
return parameter;
55+
}
56+
});
5057
}
5158

5259
private static class ThrowingMessage implements Message, StringBuilderFormattable {
5360

54-
private final CountDownLatch latch;
55-
56-
ThrowingMessage(final CountDownLatch latch) {
57-
this.latch = latch;
58-
}
59-
60-
@Override
61-
protected void finalize() throws Throwable {
62-
latch.countDown();
63-
super.finalize();
64-
}
61+
private ThrowingMessage() {}
6562

6663
@Override
6764
public String getFormattedMessage() {
6865
throw new Error("Expected");
6966
}
7067

71-
@Override
72-
public String getFormat() {
73-
return "";
74-
}
75-
7668
@Override
7769
public Object[] getParameters() {
7870
return new Object[0];

‎log4j-async-logger/src/test/java/org/apache/logging/log4j/async/logger/QueueFullAsyncLogger3Test.java

+21-61
Original file line numberDiff line numberDiff line change
@@ -16,29 +16,32 @@
1616
*/
1717
package org.apache.logging.log4j.async.logger;
1818

19-
import static java.util.concurrent.TimeUnit.SECONDS;
19+
import static org.apache.logging.log4j.async.logger.QueueFullAsyncAbstractTest.assertAsyncLogger;
2020
import static org.apache.logging.log4j.core.test.TestConstants.ASYNC_FORMAT_MESSAGES_IN_BACKGROUND;
2121
import static org.apache.logging.log4j.core.test.TestConstants.ASYNC_LOGGER_RING_BUFFER_SIZE;
2222
import static org.apache.logging.log4j.core.test.TestConstants.ASYNC_QUEUE_FULL_POLICY_CLASS_NAME;
23+
import static org.apache.logging.log4j.core.test.internal.GcHelper.awaitGarbageCollection;
2324
import static org.assertj.core.api.Assertions.assertThat;
24-
import static org.junit.Assert.assertTrue;
2525

26+
import java.util.List;
2627
import java.util.concurrent.CountDownLatch;
28+
import java.util.stream.Collectors;
29+
import java.util.stream.IntStream;
2730
import org.apache.logging.log4j.Logger;
28-
import org.apache.logging.log4j.core.GarbageCollectionHelper;
2931
import org.apache.logging.log4j.core.LoggerContext;
3032
import org.apache.logging.log4j.core.async.AsyncQueueFullPolicyFactory;
3133
import org.apache.logging.log4j.core.async.DiscardingAsyncQueueFullPolicy;
3234
import org.apache.logging.log4j.core.impl.CoreProperties;
3335
import org.apache.logging.log4j.core.test.async.BlockingAppender;
36+
import org.apache.logging.log4j.core.test.async.QueueFullAbstractTest;
3437
import org.apache.logging.log4j.core.test.junit.ContextSelectorType;
3538
import org.apache.logging.log4j.core.test.junit.LoggerContextSource;
3639
import org.apache.logging.log4j.core.test.junit.Named;
3740
import org.apache.logging.log4j.message.Message;
41+
import org.apache.logging.log4j.message.SimpleMessage;
3842
import org.apache.logging.log4j.status.StatusLogger;
3943
import org.apache.logging.log4j.test.junit.SetTestProperty;
4044
import org.junit.jupiter.api.Test;
41-
import org.junit.jupiter.api.Timeout;
4245

4346
/**
4447
* Tests queue full scenarios with pure AsyncLoggers (all loggers async).
@@ -47,7 +50,7 @@
4750
@SetTestProperty(key = ASYNC_LOGGER_RING_BUFFER_SIZE, value = "128")
4851
@SetTestProperty(key = ASYNC_FORMAT_MESSAGES_IN_BACKGROUND, value = "true")
4952
@SetTestProperty(key = ASYNC_QUEUE_FULL_POLICY_CLASS_NAME, value = "Discard")
50-
public class QueueFullAsyncLogger3Test extends QueueFullAsyncAbstractTest {
53+
class QueueFullAsyncLogger3Test extends QueueFullAbstractTest {
5154

5255
@Override
5356
protected void checkConfig(final LoggerContext ctx) {
@@ -60,64 +63,21 @@ protected void checkConfig(final LoggerContext ctx) {
6063
}
6164

6265
@Test
63-
@Timeout(value = 15, unit = SECONDS)
6466
@LoggerContextSource
65-
public void discardedMessagesShouldBeGarbageCollected(
67+
void discarded_messages_should_be_garbage_collected(
6668
final LoggerContext ctx, final @Named(APPENDER_NAME) BlockingAppender blockingAppender)
6769
throws InterruptedException {
68-
checkConfig(ctx);
69-
final Logger logger = ctx.getLogger(getClass());
70-
71-
blockingAppender.logEvents = null;
72-
blockingAppender.countDownLatch = new CountDownLatch(1);
73-
final int count = 200;
74-
final CountDownLatch garbageCollectionLatch = new CountDownLatch(count);
75-
for (int i = 0; i < count; i++) {
76-
logger.info(new CountdownOnGarbageCollectMessage(garbageCollectionLatch));
77-
}
78-
blockingAppender.countDownLatch.countDown();
79-
80-
final GarbageCollectionHelper gcHelper = new GarbageCollectionHelper();
81-
gcHelper.run();
82-
try {
83-
assertTrue("Parameter should have been garbage collected", garbageCollectionLatch.await(30, SECONDS));
84-
} finally {
85-
gcHelper.close();
86-
}
87-
}
88-
89-
private static final class CountdownOnGarbageCollectMessage implements Message {
90-
91-
private final CountDownLatch latch;
92-
93-
CountdownOnGarbageCollectMessage(final CountDownLatch latch) {
94-
this.latch = latch;
95-
}
96-
97-
@Override
98-
public String getFormattedMessage() {
99-
return "formatted";
100-
}
101-
102-
@Override
103-
public String getFormat() {
104-
return null;
105-
}
106-
107-
@Override
108-
public Object[] getParameters() {
109-
return org.apache.logging.log4j.util.Constants.EMPTY_OBJECT_ARRAY;
110-
}
111-
112-
@Override
113-
public Throwable getThrowable() {
114-
return null;
115-
}
116-
117-
@Override
118-
protected void finalize() throws Throwable {
119-
latch.countDown();
120-
super.finalize();
121-
}
70+
awaitGarbageCollection(() -> {
71+
checkConfig(ctx);
72+
final Logger logger = ctx.getLogger(getClass());
73+
blockingAppender.logEvents = null;
74+
blockingAppender.countDownLatch = new CountDownLatch(1);
75+
final List<Message> messages = IntStream.range(0, 200)
76+
.mapToObj(messageIndex -> new SimpleMessage("message " + messageIndex))
77+
.collect(Collectors.toList());
78+
messages.forEach(logger::info);
79+
blockingAppender.countDownLatch.countDown();
80+
return messages;
81+
});
12282
}
12383
}

‎log4j-core-test/src/main/java/org/apache/logging/log4j/core/GarbageCollectionHelper.java

-68
This file was deleted.

‎log4j-core-test/src/main/java/org/apache/logging/log4j/core/test/internal/GcHelper.java

+54
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,54 @@
1+
/*
2+
* Licensed to the Apache Software Foundation (ASF) under one or more
3+
* contributor license agreements. See the NOTICE file distributed with
4+
* this work for additional information regarding copyright ownership.
5+
* The ASF licenses this file to you under the Apache License, Version 2.0
6+
* (the "License"); you may not use this file except in compliance with
7+
* the License. You may obtain a copy of the License at
8+
*
9+
* http://www.apache.org/licenses/LICENSE-2.0
10+
*
11+
* Unless required by applicable law or agreed to in writing, software
12+
* distributed under the License is distributed on an "AS IS" BASIS,
13+
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
14+
* See the License for the specific language governing permissions and
15+
* limitations under the License.
16+
*/
17+
package org.apache.logging.log4j.core.test.internal;
18+
19+
import java.lang.ref.PhantomReference;
20+
import java.lang.ref.Reference;
21+
import java.lang.ref.ReferenceQueue;
22+
import org.junit.jupiter.api.function.ThrowingSupplier;
23+
24+
public final class GcHelper {
25+
26+
private GcHelper() {}
27+
28+
/**
29+
* Waits for the value to be garbage collected.
30+
*
31+
* @param valueSupplier a value provider
32+
*/
33+
@SuppressWarnings({"unused", "UnusedAssignment"})
34+
public static void awaitGarbageCollection(final ThrowingSupplier<?> valueSupplier) throws InterruptedException {
35+
36+
// Create the reference queue
37+
final ReferenceQueue<Object> refQueue = new ReferenceQueue<>();
38+
final Reference<?> ref;
39+
try {
40+
final Object value = valueSupplier.get();
41+
ref = new PhantomReference<>(value, refQueue);
42+
} catch (final Throwable error) {
43+
throw new RuntimeException("failed obtaining value", error);
44+
}
45+
46+
// Wait for the garbage collection
47+
try (final GcPressureGenerator ignored = GcPressureGenerator.ofStarted()) {
48+
final Reference<?> removedRef = refQueue.remove(30_000L);
49+
if (removedRef == null) {
50+
throw new AssertionError("garbage collector did not reclaim the value");
51+
}
52+
}
53+
}
54+
}

0 commit comments

Comments
 (0)