Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -25,12 +25,15 @@
import java.io.PrintStream;
import java.nio.charset.Charset;
import java.nio.charset.StandardCharsets;
import java.util.Arrays;
import java.util.List;
import java.util.concurrent.CountDownLatch;
import java.util.concurrent.ExecutorService;
import java.util.concurrent.Executors;
import java.util.concurrent.atomic.AtomicInteger;
import java.util.concurrent.locks.LockSupport;
import java.util.function.Consumer;
import java.util.function.Function;
import java.util.stream.Collectors;
import java.util.stream.IntStream;
import java.util.stream.Stream;
Expand Down Expand Up @@ -443,64 +446,101 @@ private static String normalizeStackTrace(final String stackTrace, final String
.replaceAll(" ~\\[\\?:[^]]+](\\Q" + conversionEnding + "\\E|$)", " ~[?:0]$1");
}

@RepeatedTest(10)
@Issue("https://github.com/apache/logging-log4j2/issues/3940")
void concurrent_stack_trace_mutation_should_not_cause_failure() throws Exception {
final int stackTracePerThreadCount = 100;
formatThrowableWhileMutatingConcurrently(threadIndex -> {
final List<StackTraceElement[]> stackTraces = createExceptionsOfDifferentDepths().stream()
.map(Throwable::getStackTrace)
.collect(Collectors.toList());
return exception -> {
for (int stackTraceIndex = 0; stackTraceIndex < stackTracePerThreadCount; stackTraceIndex++) {
exception.setStackTrace(stackTraces.get(stackTraceIndex));
// Give some time slack to increase randomness
LockSupport.parkNanos(1);
}
};
});
}

@RepeatedTest(10)
@Issue("https://github.com/apache/logging-log4j2/issues/3929")
void concurrent_suppressed_mutation_should_not_cause_failure() throws Exception {
formatThrowableWhileMutatingConcurrently(threadIndex -> {
final List<Exception> exceptions = createExceptionsOfDifferentDepths();
return exception -> exceptions.forEach(suppressed -> {
exception.addSuppressed(suppressed);
// Give some time slack to increase randomness
LockSupport.parkNanos(1);
});
});
}

private void formatThrowableWhileMutatingConcurrently(
Function<Integer, Consumer<Throwable>> throwableMutatorFactory) throws Exception {

// Test constants
final int threadCount = Math.max(8, Runtime.getRuntime().availableProcessors());
final ExecutorService executor = Executors.newFixedThreadPool(threadCount);
final Exception exception = new Exception();
final CountDownLatch startLatch =
new CountDownLatch(threadCount + /* the main thread invoking the rendering: */ 1);
final int exceptionPerThreadCount = 100;
final AtomicInteger runningThreadCountRef = new AtomicInteger(threadCount);

// Schedule threads that will start adding suppressed exceptions with the start signal
for (int threadIndex = 0; threadIndex < threadCount; threadIndex++) {
final int threadIndex_ = threadIndex;
executor.submit(() -> {
try {
List<Exception> exceptions = IntStream.range(0, exceptionPerThreadCount)
.mapToObj(exceptionIndex -> new Exception(threadIndex_ + "-" + exceptionIndex))
.collect(Collectors.toList());
startLatch.countDown();
startLatch.await();
for (int exceptionIndex = 0; exceptionIndex < exceptionPerThreadCount; exceptionIndex++) {
exception.addSuppressed(exceptions.get(exceptionIndex));
// Give some time slack to increase randomness
LockSupport.parkNanos(1);
try {
final Exception exception = new Exception();
final CountDownLatch startLatch =
new CountDownLatch(threadCount + /* the main thread invoking the rendering: */ 1);
final AtomicInteger runningThreadCountRef = new AtomicInteger(threadCount);

// Schedule threads that will start mutating the exception with the start signal
for (int threadIndex = 0; threadIndex < threadCount; threadIndex++) {
final Consumer<Throwable> exceptionMutator = throwableMutatorFactory.apply(threadIndex);
executor.submit(() -> {
try {
startLatch.countDown();
startLatch.await();
exceptionMutator.accept(exception);
} catch (InterruptedException ignored) {
// Restore the interrupt
Thread.currentThread().interrupt();
} finally {
runningThreadCountRef.decrementAndGet();
}
} catch (InterruptedException ignored) {
// Restore the interrupt
Thread.currentThread().interrupt();
} finally {
runningThreadCountRef.decrementAndGet();
}
});
});
}

// Create the formatter
final List<PatternFormatter> patternFormatters = PATTERN_PARSER.parse(patternPrefix, false, true, true);
assertThat(patternFormatters).hasSize(1);
final PatternFormatter patternFormatter = patternFormatters.get(0);

// Create the log event and the layout buffer
final LogEvent logEvent = Log4jLogEvent.newBuilder()
.setThrown(exception)
.setLevel(LEVEL)
.build();
final StringBuilder buffer = new StringBuilder(16384);

// Trigger the start latch and format the exception
startLatch.countDown();
startLatch.await();
while (runningThreadCountRef.get() > 0) {
// Give some time slack to increase randomness
LockSupport.parkNanos(1);
patternFormatter.format(logEvent, buffer);
buffer.setLength(0);
}
} finally {
executor.shutdownNow();
}
}

// Create the formatter
final List<PatternFormatter> patternFormatters = PATTERN_PARSER.parse(patternPrefix, false, true, true);
assertThat(patternFormatters).hasSize(1);
final PatternFormatter patternFormatter = patternFormatters.get(0);

// Create the log event and the layout buffer
final LogEvent logEvent = Log4jLogEvent.newBuilder()
.setThrown(exception)
.setLevel(LEVEL)
.build();
final StringBuilder buffer = new StringBuilder(16384);

// Trigger the start latch and format the exception
startLatch.countDown();
startLatch.await();
while (runningThreadCountRef.get() > 0) {
// Give some time slack to increase randomness
LockSupport.parkNanos(1);
patternFormatter.format(logEvent, buffer);
buffer.setLength(0);
}
private static List<Exception> createExceptionsOfDifferentDepths() {
final StackTraceElement[] stackTrace = new Exception().getStackTrace();
return IntStream.range(0, stackTrace.length)
.mapToObj(depth -> {
final Exception exception = new Exception();
exception.setStackTrace(Arrays.copyOfRange(stackTrace, 0, depth));
return exception;
})
.collect(Collectors.toList());
}
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -132,7 +132,7 @@ private static Map<String, ClassResourceInfo> createClassResourceInfoByName(
Class<?> executionStackTraceElementClass =
executionStackTrace.isEmpty() ? null : executionStackTrace.peekLast();
ClassLoader lastLoader = null;
final StackTraceElement[] stackTraceElements = throwable.getStackTrace();
final StackTraceElement[] stackTraceElements = metadata.stackTrace;
for (int throwableStackIndex = metadata.stackLength - 1;
throwableStackIndex >= 0;
--throwableStackIndex) {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -74,7 +74,7 @@ private void renderThrowable(
}
renderThrowableMessage(buffer, throwable);
buffer.append(lineSeparator);
renderStackTraceElements(buffer, throwable, context, metadata, prefix, lineSeparator);
renderStackTraceElements(buffer, context, metadata, prefix, lineSeparator);
renderSuppressed(buffer, metadata.suppressed, context, visitedThrowables, prefix + '\t', lineSeparator);
}
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -98,7 +98,7 @@ private void renderThrowable(
final Context.Metadata metadata = context.metadataByThrowable.get(throwable);
renderThrowableMessage(buffer, throwable);
buffer.append(lineSeparator);
renderStackTraceElements(buffer, throwable, context, metadata, prefix, lineSeparator);
renderStackTraceElements(buffer, context, metadata, prefix, lineSeparator);
renderSuppressed(buffer, metadata.suppressed, context, visitedThrowables, prefix + '\t', lineSeparator);
renderCause(buffer, throwable.getCause(), context, visitedThrowables, prefix, lineSeparator);
}
Expand Down Expand Up @@ -148,13 +148,12 @@ static void renderThrowableMessage(final StringBuilder buffer, final Throwable t

final void renderStackTraceElements(
final StringBuilder buffer,
final Throwable throwable,
final C context,
final Context.Metadata metadata,
final String prefix,
final String lineSeparator) {
context.ignoredStackTraceElementCount = 0;
final StackTraceElement[] stackTraceElements = throwable.getStackTrace();
final StackTraceElement[] stackTraceElements = metadata.stackTrace;
for (int i = 0; i < metadata.stackLength; i++) {
renderStackTraceElement(buffer, stackTraceElements[i], context, prefix, lineSeparator);
}
Expand Down Expand Up @@ -268,6 +267,15 @@ static final class Metadata {
*/
final int stackLength;

/**
* The stack trace of this {@link Throwable}.
* This needs to be captured separately since {@link Throwable#getStackTrace()} can change.
*
* @see <a href="https://github.com/apache/logging-log4j2/issues/3940">#3940</a>
* @see <a href="https://github.com/apache/logging-log4j2/pull/3955">#3955</a>
*/
final StackTraceElement[] stackTrace;

/**
* The suppressed exceptions attached to this {@link Throwable}.
* This needs to be captured separately since {@link Throwable#getSuppressed()} can change.
Expand All @@ -277,9 +285,14 @@ static final class Metadata {
*/
final Throwable[] suppressed;

private Metadata(final int commonElementCount, final int stackLength, final Throwable[] suppressed) {
private Metadata(
final int commonElementCount,
final int stackLength,
final StackTraceElement[] stackTrace,
final Throwable[] suppressed) {
this.commonElementCount = commonElementCount;
this.stackLength = stackLength;
this.stackTrace = stackTrace;
this.suppressed = suppressed;
}

Expand Down Expand Up @@ -339,7 +352,7 @@ private static Metadata populateMetadata(
commonElementCount = 0;
stackLength = currentTrace.length;
}
return new Metadata(commonElementCount, stackLength, suppressed);
return new Metadata(commonElementCount, stackLength, currentTrace, suppressed);
}
}
}
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,13 @@
<?xml version="1.0" encoding="UTF-8"?>
<entry xmlns="https://logging.apache.org/xml/ns"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="
https://logging.apache.org/xml/ns
https://logging.apache.org/xml/ns/log4j-changelog-0.xsd"
type="fixed">
<issue id="3940" link="https://github.com/apache/logging-log4j2/issues/3940"/>
<issue id="3955" link="https://github.com/apache/logging-log4j2/pull/3955"/>
<description format="asciidoc">
Fixes `ArrayIndexOutOfBoundsException` thrown by `ThrowableStackTraceRenderer` when the stack trace is mutated concurrently.
</description>
</entry>