Skip to content

Commit 981ae1e

Browse files
vyalan0428appkarwasz
authored
Consolidate stack trace rendering in Pattern Layout (#3047)
Co-authored-by: AlanYu <[email protected]> Co-authored-by: Piotr P. Karwasz <[email protected]>
1 parent 3ee4c38 commit 981ae1e

File tree

48 files changed

+2249
-2837
lines changed

Some content is hidden

Large Commits have some content hidden by default. Use the searchbox below for content that may be hidden.

48 files changed

+2249
-2837
lines changed

‎log4j-async-logger/src/main/java/org/apache/logging/log4j/async/logger/RingBufferLogEvent.java

Lines changed: 1 addition & 23 deletions
Original file line numberDiff line numberDiff line change
@@ -27,7 +27,6 @@
2727
import org.apache.logging.log4j.core.impl.ContextDataFactory;
2828
import org.apache.logging.log4j.core.impl.Log4jLogEvent;
2929
import org.apache.logging.log4j.core.impl.MementoMessage;
30-
import org.apache.logging.log4j.core.impl.ThrowableProxy;
3130
import org.apache.logging.log4j.core.time.Clock;
3231
import org.apache.logging.log4j.core.time.Instant;
3332
import org.apache.logging.log4j.core.time.MutableInstant;
@@ -82,7 +81,6 @@ public RingBufferLogEvent newInstance() {
8281
private StringBuilder messageText;
8382
private Object[] parameters;
8483
private Throwable thrown;
85-
private ThrowableProxy thrownProxy;
8684
private StringMap contextData = ContextDataFactory.createContextData();
8785
private Marker marker;
8886
private String fqcn;
@@ -116,7 +114,6 @@ public void setValues(
116114
initTime(clock);
117115
this.nanoTime = nanoClock.nanoTime();
118116
this.thrown = aThrowable;
119-
this.thrownProxy = null;
120117
this.marker = aMarker;
121118
this.fqcn = theFqcn;
122119
this.location = aLocation;
@@ -354,12 +351,6 @@ public CharSequence subSequence(final int start, final int end) {
354351

355352
@Override
356353
public Throwable getThrown() {
357-
// after deserialization, thrown is null but thrownProxy may be non-null
358-
if (thrown == null) {
359-
if (thrownProxy != null) {
360-
thrown = thrownProxy.getThrowable();
361-
}
362-
}
363354
return thrown;
364355
}
365356

@@ -368,17 +359,6 @@ public void setThrown(final Throwable thrown) {
368359
this.thrown = thrown;
369360
}
370361

371-
@Override
372-
public ThrowableProxy getThrownProxy() {
373-
// lazily instantiate the (expensive) ThrowableProxy
374-
if (thrownProxy == null) {
375-
if (thrown != null) {
376-
thrownProxy = new ThrowableProxy(thrown);
377-
}
378-
}
379-
return this.thrownProxy;
380-
}
381-
382362
@Override
383363
public StringMap getContextData() {
384364
return contextData;
@@ -487,7 +467,6 @@ public void clear() {
487467
this.loggerName = null;
488468
clearMessage();
489469
this.thrown = null;
490-
this.thrownProxy = null;
491470
clearContextData();
492471
this.marker = null;
493472
this.fqcn = null;
@@ -546,8 +525,7 @@ public void initializeBuilder(final Log4jLogEvent.Builder builder) {
546525
.setThreadId(threadId) //
547526
.setThreadName(threadName) //
548527
.setThreadPriority(threadPriority) //
549-
.setThrown(getThrown()) // may deserialize from thrownProxy
550-
.setThrownProxy(thrownProxy) // avoid unnecessarily creating thrownProxy
528+
.setThrown(getThrown()) //
551529
.setInstant(instant) //
552530
;
553531
}

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

Lines changed: 0 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -235,7 +235,6 @@ void testCreateMementoReturnsCopy() {
235235
assertThat(actual.getInstant().getNanoOfMillisecond())
236236
.isEqualTo(evt.getInstant().getNanoOfMillisecond());
237237
assertThat(actual.getSource()).isEqualTo(evt.getSource());
238-
assertThat(actual.getThrownProxy()).isEqualTo(evt.getThrownProxy());
239238
}
240239

241240
@Test

‎log4j-core-test/pom.xml

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -65,6 +65,12 @@
6565

6666
<dependencies>
6767

68+
<dependency>
69+
<groupId>org.jspecify</groupId>
70+
<artifactId>jspecify</artifactId>
71+
<scope>provided</scope>
72+
</dependency>
73+
6874
<!-- Used for OSGi bundle support -->
6975
<dependency>
7076
<groupId>org.osgi</groupId>

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

Lines changed: 2 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -28,7 +28,6 @@
2828
import org.apache.logging.log4j.core.LogEvent;
2929
import org.apache.logging.log4j.core.impl.ContextDataFactory;
3030
import org.apache.logging.log4j.core.impl.Log4jLogEvent;
31-
import org.apache.logging.log4j.core.impl.ThrowableProxy;
3231
import org.apache.logging.log4j.message.SimpleMessage;
3332
import org.apache.logging.log4j.spi.DefaultThreadContextStack;
3433
import org.apache.logging.log4j.util.StringMap;
@@ -56,7 +55,6 @@ public static Log4jLogEvent createLogEvent() {
5655
final IOException ioException = new IOException("testIOEx", cause);
5756
ioException.addSuppressed(new IndexOutOfBoundsException("I am suppressed exception 1"));
5857
ioException.addSuppressed(new IndexOutOfBoundsException("I am suppressed exception 2"));
59-
final ThrowableProxy throwableProxy = new ThrowableProxy(ioException);
6058
final StringMap contextData = ContextDataFactory.createContextData();
6159
contextData.putValue("MDC.A", "A_Value");
6260
contextData.putValue("MDC.B", "B_Value");
@@ -71,7 +69,6 @@ public static Log4jLogEvent createLogEvent() {
7169
.setLevel(Level.DEBUG) //
7270
.setMessage(new SimpleMessage("Msg")) //
7371
.setThrown(ioException) //
74-
.setThrownProxy(throwableProxy) //
7572
.setContextData(contextData) //
7673
.setContextStack(contextStack) //
7774
.setThreadName("MyThreadName") //
@@ -103,14 +100,11 @@ public static void assertEqualLogEvents(
103100
assertEquals(expected.getThreadName(), actual.getThreadName());
104101
assertNotNull("original should have an exception", expected.getThrown());
105102
assertNull("exception should not be serialized", actual.getThrown());
106-
if (includeStacktrace) { // TODO should compare the rest of the ThrowableProxy
107-
assertEquals(expected.getThrownProxy(), actual.getThrownProxy());
108-
}
109103
assertEquals(expected.isEndOfBatch(), actual.isEndOfBatch());
110104
assertEquals(expected.isIncludeLocation(), actual.isIncludeLocation());
111105

112-
// original: non-null thrown & null thrownProxy
113-
// deserialized: null thrown & non-null thrownProxy
106+
// original: non-null thrown
107+
// deserialized: null thrown
114108
assertNotEquals(expected.hashCode(), actual.hashCode());
115109
assertNotEquals(expected, actual);
116110
}

‎log4j-core-test/src/test/java/foo/TestFriendlyException.java

Lines changed: 155 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,155 @@
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 foo;
18+
19+
import static org.assertj.core.api.Assertions.assertThat;
20+
21+
import java.net.Socket;
22+
import java.util.Arrays;
23+
import java.util.stream.Stream;
24+
import org.apache.logging.log4j.util.Constants;
25+
26+
/**
27+
* A testing friendly exception featuring
28+
* <ul>
29+
* <li>Distinct localized message</li>
30+
* <li>Non-Log4j package origin<sup>1</sup></li>
31+
* <li>Sufficient causal chain depth</li>
32+
* <li>Cyclic causal chain</li>
33+
* <li>Suppressed exceptions</li>
34+
* <li>Clutter-free stack trace (i.e., elements from JUnit, JDK, etc.)</li>
35+
* <li>Stack trace elements from named modules<sup>2</sup></li>
36+
* </ul>
37+
* <p>
38+
* <sup>1</sup> Helps with observing stack trace manipulation effects of Log4j.
39+
* </p>
40+
* <p>
41+
* <sup>2</sup> Helps with testing module name serialization.
42+
* </p>
43+
*/
44+
public final class TestFriendlyException extends RuntimeException {
45+
46+
static {
47+
// Ensure the distinct packaging
48+
assertThat(TestFriendlyException.class.getPackage().getName()).doesNotStartWith("org.apache");
49+
}
50+
51+
public static final StackTraceElement NAMED_MODULE_STACK_TRACE_ELEMENT = namedModuleStackTraceElement();
52+
53+
@SuppressWarnings("resource")
54+
private static StackTraceElement namedModuleStackTraceElement() {
55+
try {
56+
new Socket("0.0.0.0", -1);
57+
} catch (final Exception error) {
58+
final StackTraceElement[] stackTraceElements = error.getStackTrace();
59+
final String socketClassName = Socket.class.getCanonicalName();
60+
for (final StackTraceElement stackTraceElement : stackTraceElements) {
61+
if (stackTraceElement.getClassName().equals(socketClassName)) {
62+
if (Constants.JAVA_MAJOR_VERSION > 8) {
63+
final String stackTraceElementString = stackTraceElement.toString();
64+
assertThat(stackTraceElementString).startsWith("java.base/");
65+
}
66+
return stackTraceElement;
67+
}
68+
}
69+
}
70+
throw new IllegalStateException("should not have reached here");
71+
}
72+
73+
private static final String[] EXCLUDED_CLASS_NAME_PREFIXES = {
74+
"java.lang", "jdk.internal", "org.junit", "sun.reflect"
75+
};
76+
77+
public static final TestFriendlyException INSTANCE = create("r", 0, 2, new boolean[] {false}, new boolean[] {true});
78+
79+
private static TestFriendlyException create(
80+
final String name,
81+
final int depth,
82+
final int maxDepth,
83+
final boolean[] circular,
84+
final boolean[] namedModuleAllowed) {
85+
final TestFriendlyException error = new TestFriendlyException(name, namedModuleAllowed);
86+
if (depth < maxDepth) {
87+
final TestFriendlyException cause = create(name + "_c", depth + 1, maxDepth, circular, namedModuleAllowed);
88+
error.initCause(cause);
89+
final TestFriendlyException suppressed =
90+
create(name + "_s", depth + 1, maxDepth, circular, namedModuleAllowed);
91+
error.addSuppressed(suppressed);
92+
final boolean circularAllowed = depth + 1 == maxDepth && !circular[0];
93+
if (circularAllowed) {
94+
cause.initCause(error);
95+
suppressed.initCause(error);
96+
circular[0] = true;
97+
}
98+
}
99+
return error;
100+
}
101+
102+
private TestFriendlyException(final String message, final boolean[] namedModuleAllowed) {
103+
super(message);
104+
removeExcludedStackTraceElements(namedModuleAllowed);
105+
}
106+
107+
private void removeExcludedStackTraceElements(final boolean[] namedModuleAllowed) {
108+
final StackTraceElement[] oldStackTrace = getStackTrace();
109+
final boolean[] seenExcludedStackTraceElement = {false};
110+
final StackTraceElement[] newStackTrace = Arrays.stream(oldStackTrace)
111+
.flatMap(stackTraceElement ->
112+
mapStackTraceElement(stackTraceElement, namedModuleAllowed, seenExcludedStackTraceElement))
113+
.toArray(StackTraceElement[]::new);
114+
setStackTrace(newStackTrace);
115+
}
116+
117+
private static Stream<StackTraceElement> mapStackTraceElement(
118+
final StackTraceElement stackTraceElement,
119+
final boolean[] namedModuleAllowed,
120+
final boolean[] seenExcludedStackTraceElement) {
121+
final Stream<StackTraceElement> filteredStackTraceElement =
122+
filterStackTraceElement(stackTraceElement, seenExcludedStackTraceElement);
123+
final Stream<StackTraceElement> javaBaseIncludedStackTraceElement =
124+
namedModuleIncludedStackTraceElement(namedModuleAllowed);
125+
return Stream.concat(javaBaseIncludedStackTraceElement, filteredStackTraceElement);
126+
}
127+
128+
private static Stream<StackTraceElement> filterStackTraceElement(
129+
final StackTraceElement stackTraceElement, final boolean[] seenExcludedStackTraceElement) {
130+
if (seenExcludedStackTraceElement[0]) {
131+
return Stream.empty();
132+
}
133+
final String className = stackTraceElement.getClassName();
134+
for (final String excludedClassNamePrefix : EXCLUDED_CLASS_NAME_PREFIXES) {
135+
if (className.startsWith(excludedClassNamePrefix)) {
136+
seenExcludedStackTraceElement[0] = true;
137+
return Stream.empty();
138+
}
139+
}
140+
return Stream.of(stackTraceElement);
141+
}
142+
143+
private static Stream<StackTraceElement> namedModuleIncludedStackTraceElement(final boolean[] namedModuleAllowed) {
144+
if (!namedModuleAllowed[0]) {
145+
return Stream.of();
146+
}
147+
namedModuleAllowed[0] = false;
148+
return Stream.of(NAMED_MODULE_STACK_TRACE_ELEMENT);
149+
}
150+
151+
@Override
152+
public String getLocalizedMessage() {
153+
return getMessage() + " [localized]";
154+
}
155+
}

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

Lines changed: 8 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -18,6 +18,7 @@
1818

1919
import static org.hamcrest.MatcherAssert.assertThat;
2020
import static org.hamcrest.Matchers.containsString;
21+
import static org.hamcrest.Matchers.is;
2122
import static org.junit.jupiter.api.Assertions.assertNull;
2223
import static org.junit.jupiter.api.Assertions.assertTrue;
2324

@@ -61,15 +62,20 @@ public void testParametersAreNotLeaked() throws Exception {
6162
final String line1 = reader.readLine();
6263
final String line2 = reader.readLine();
6364
final String line3 = reader.readLine();
65+
// line4 is empty line because of the line separator after throwable pattern
6466
final String line4 = reader.readLine();
6567
final String line5 = reader.readLine();
68+
final String line6 = reader.readLine();
69+
final String line7 = reader.readLine();
6670
reader.close();
6771
file.delete();
6872
assertThat(line1, containsString("Message with parameter paramValue"));
6973
assertThat(line2, containsString("paramValue"));
7074
assertThat(line3, containsString("paramValue"));
71-
assertThat(line4, containsString("paramValue"));
72-
assertNull(line5, "Expected only three lines");
75+
assertThat(line4, is(""));
76+
assertThat(line5, containsString("paramValue"));
77+
assertThat(line6, is(""));
78+
assertNull(line7, "Expected only six lines");
7379
try (final GarbageCollectionHelper gcHelper = new GarbageCollectionHelper()) {
7480
gcHelper.run();
7581
assertTrue(latch.await(30, TimeUnit.SECONDS), "Parameter should have been garbage collected");

‎log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/rewrite/MapRewritePolicyTest.java

Lines changed: 1 addition & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -19,7 +19,6 @@
1919
import static org.apache.logging.log4j.core.test.hamcrest.MapMatchers.hasSize;
2020
import static org.hamcrest.MatcherAssert.assertThat;
2121
import static org.hamcrest.Matchers.hasEntry;
22-
import static org.junit.jupiter.api.Assertions.assertArrayEquals;
2322
import static org.junit.jupiter.api.Assertions.assertEquals;
2423

2524
import java.util.ArrayList;
@@ -170,10 +169,7 @@ private void compareLogEvents(final LogEvent orig, final LogEvent changed) {
170169
assertEquals(orig.getMarker(), changed.getMarker(), "Marker changed");
171170
assertEquals(orig.getLoggerFqcn(), changed.getLoggerFqcn(), "FQCN changed");
172171
assertEquals(orig.getLevel(), changed.getLevel(), "Level changed");
173-
assertArrayEquals(
174-
orig.getThrown() == null ? null : orig.getThrownProxy().getExtendedStackTrace(),
175-
changed.getThrown() == null ? null : changed.getThrownProxy().getExtendedStackTrace(),
176-
"Throwable changed");
172+
assertEquals(orig.getThrown(), changed.getThrown(), "Throwable changed");
177173
assertEquals(orig.getContextData(), changed.getContextData(), "ContextData changed");
178174
assertEquals(orig.getContextStack(), changed.getContextStack(), "ContextStack changed");
179175
assertEquals(orig.getThreadName(), changed.getThreadName(), "ThreadName changed");

‎log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/rolling/RollingAppenderOnStartupTest.java

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -50,8 +50,8 @@ public class RollingAppenderOnStartupTest {
5050

5151
@BeforeAll
5252
static void setUp() throws IOException {
53-
final Path target =
54-
Files.copy(SOURCE.resolve(FILENAME), loggingPath.resolve(FILENAME), StandardCopyOption.COPY_ATTRIBUTES);
53+
final Path target = Files.copy(
54+
SOURCE.resolve(FILENAME), loggingPath.resolve(FILENAME), StandardCopyOption.REPLACE_EXISTING);
5555
final FileTime newTime = FileTime.from(Instant.now().minus(1, ChronoUnit.DAYS));
5656
final BasicFileAttributeView attrs = Files.getFileAttributeView(target, BasicFileAttributeView.class);
5757
attrs.setTimes(newTime, newTime, newTime);

‎log4j-core-test/src/test/java/org/apache/logging/log4j/core/impl/MutableLogEventTest.java

Lines changed: 0 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -76,7 +76,6 @@ public void testToImmutable() {
7676

7777
@Test
7878
public void testInitFromCopiesAllFields() {
79-
// private ThrowableProxy thrownProxy;
8079
final Log4jLogEvent source = Log4jLogEvent.newBuilder() //
8180
.setContextData(CONTEXT_DATA) //
8281
.setContextStack(STACK) //
@@ -112,7 +111,6 @@ public void testInitFromCopiesAllFields() {
112111
assertEquals(source.getThreadName(), mutable.getThreadName(), "tname");
113112
assertEquals(source.getThreadPriority(), mutable.getThreadPriority(), "tpriority");
114113
assertEquals(source.getThrown(), mutable.getThrown(), "throwns");
115-
assertEquals(source.getThrownProxy(), mutable.getThrownProxy(), "proxy");
116114
assertEquals(source.getTimeMillis(), mutable.getTimeMillis(), "millis");
117115
}
118116

@@ -216,7 +214,6 @@ public void testClear() {
216214
assertEquals(0, mutable.getTimeMillis(), "timeMs");
217215

218216
assertNull(mutable.getSource(), "source");
219-
assertNull(mutable.getThrownProxy(), "thrownProxy");
220217

221218
mutable.setContextData(CONTEXT_DATA);
222219
mutable.setContextStack(STACK);
@@ -250,7 +247,6 @@ public void testClear() {
250247
assertNotEquals(0, mutable.getTimeMillis(), "timeMs");
251248

252249
assertNotNull(mutable.getSource(), "source");
253-
assertNotNull(mutable.getThrownProxy(), "thrownProxy");
254250

255251
mutable.clear();
256252
assertEquals(0, mutable.getContextData().size(), "context map");
@@ -263,7 +259,6 @@ public void testClear() {
263259
assertNull(mutable.getThrown(), "thrwn");
264260

265261
assertNull(mutable.getSource(), "source");
266-
assertNull(mutable.getThrownProxy(), "thrownProxy");
267262

268263
// primitive fields are NOT reset:
269264
assertTrue(mutable.isEndOfBatch(), "end of batch");

0 commit comments

Comments
 (0)