logging-log4j2 icon indicating copy to clipboard operation
logging-log4j2 copied to clipboard

ThrowableStackTraceRenderer HashMap key collision causes ArrayIndexOutOfBoundsException with custom exception equals() methods

Open shinstev333 opened this issue 3 months ago • 2 comments

Description

The ThrowableStackTraceRenderer class in Log4j 2.25.1 throws ArrayIndexOutOfBoundsException when rendering exception chains containing multiple exceptions with custom equals() methods that compare by message content rather than object identity. This occurs because the renderer uses Map<Throwable, Context.Metadata> for storing stack trace metadata, and HashMap key collisions cause metadata calculated for one exception (with longer stack trace) to be incorrectly applied to another exception (with shorter stack trace).

Root Cause: When exception classes override equals() to compare by message/type instead of object identity, different exception objects with identical messages but different stack trace lengths are treated as the same HashMap key. This causes the renderer to attempt accessing stack trace elements beyond the actual array bounds.

Affected Components: This issue affects multiple throwable rendering classes:

  • ThrowableStackTraceRenderer
  • ThrowableExtendedStackTraceRenderer
  • ThrowableInvertedStackTraceRenderer
  • ThrowableProxy
  • Throwables utility class

All these classes assume object identity for Throwable objects but break when custom equals() implementations are used.

Configuration

Version: 2.25.1

Operating system: macOS

JDK: JDK 17

Log4j Configuration:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="DEBUG" shutdownHook="disable">
    <Appenders>
        <Console name="STDOUT" target="SYSTEM_OUT">
            <PatternLayout pattern="%d{ISO8601} %highlight{[%p]} %X{RequestId} (%t) %c: %m%n" disableAnsi="false"/>
        </Console>
    </Appenders>
    <Loggers>
        <Root level="INFO">
            <AppenderRef ref="STDOUT"/>
        </Root>
    </Loggers>
</Configuration>

System Properties:

systemProperty("java.util.logging.manager", "org.apache.logging.log4j.jul.LogManager")

Logs

2025-09-18T20:19:33.145604Z main DEBUG LoggerContext[name=42110406, org.apache.logging.log4j.core.LoggerContext@3a44431a] started OK.
2025-09-18T20:19:33.148982Z main ERROR An exception occurred processing Appender STDOUT
java.lang.ArrayIndexOutOfBoundsException: Index 2 out of bounds for length 2
    at org.apache.logging.log4j.core.pattern.ThrowableStackTraceRenderer.renderStackTraceElements(ThrowableStackTraceRenderer.java:169)
    at org.apache.logging.log4j.core.pattern.ThrowableStackTraceRenderer.renderThrowable(ThrowableStackTraceRenderer.java:110)
    at org.apache.logging.log4j.core.pattern.ThrowableStackTraceRenderer.renderThrowable(ThrowableStackTraceRenderer.java:87)
    at org.apache.logging.log4j.core.pattern.ThrowableStackTraceRenderer.renderThrowable(ThrowableStackTraceRenderer.java:59)
    at org.apache.logging.log4j.core.pattern.ThrowablePatternConverter.format(ThrowablePatternConverter.java:130)
    at org.apache.logging.log4j.core.layout.PatternLayout$NoFormatPatternSerializer.toSerializable(PatternLayout.java:354)
    at org.apache.logging.log4j.core.layout.PatternLayout.toText(PatternLayout.java:251)
    at org.apache.logging.log4j.core.layout.PatternLayout.encode(PatternLayout.java:237)
    at org.apache.logging.log4j.core.layout.PatternLayout.encode(PatternLayout.java:57)
    at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.directEncodeEvent(AbstractOutputStreamAppender.java:227)
    at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.tryAppend(AbstractOutputStreamAppender.java:220)
    at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:211)
    at org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:160)
    at org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:133)
    at org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:124)
    at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:88)
    at org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:711)
    at org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:669)
    at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:645)
    at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:589)
    at org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:92)
    at org.apache.logging.log4j.core.Logger.log(Logger.java:187)
    at org.apache.logging.log4j.spi.AbstractLogger.tryLogMessage(AbstractLogger.java:2970)
    at org.apache.logging.log4j.spi.AbstractLogger.logMessageTrackRecursion(AbstractLogger.java:2922)
    at org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2904)
    at org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:2648)
    at org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:2587)
    at org.apache.logging.log4j.spi.AbstractLogger.error(AbstractLogger.java:824)
    at com.Log4jArrayIndexOutOfBoundsException.logAndEmitErrorMetric(Log4jArrayIndexOutOfBoundsException.java:58)
    at com.Log4jArrayIndexOutOfBoundsException.simpleReproduction(Log4jArrayIndexOutOfBoundsException.java:19)
    at com.Log4jArrayIndexOutOfBoundsException.main(Log4jArrayIndexOutOfBoundsException.java:12)

Reproduction

Complete standalone reproduction:

package com;

import java.util.Objects;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;

public class Log4jArrayIndexOutOfBoundsException {
    private static final Logger LOG = LogManager.getLogger();

    public static void main(String[] args) throws Exception {
        simpleReproduction();
    }

    private static void simpleReproduction() throws Exception {
        String message = "Processing failed";
        Exception deeperStackTrace = createDeepStackTrace(3, message);
        Exception lighterStackTrace = new CustomProcessingException(message, deeperStackTrace);
        logAndEmitErrorMetric(message, lighterStackTrace);
    }

    private static CustomProcessingException createDeepStackTrace(int depth, String message) {
        if (depth <= 0) {
            return new CustomProcessingException(message);
        }
        return createDeepStackTrace(depth - 1, message);  // Recursive to create deep stack
    }

    static class CustomProcessingException extends Exception {
        public CustomProcessingException(String message) {
            super(message);
        }

        public CustomProcessingException(String message, Throwable cause) {
            super(message, cause);
        }

        @Override
        public boolean equals(Object other) {
            if (this == other) {
                return true;
            } else if (!(other instanceof CustomProcessingException)) {
                return false;
            } else {
                CustomProcessingException that = (CustomProcessingException)other;
                return Objects.equals(this.getMessage(), that.getMessage());
            }
        }

        @Override
        public int hashCode() {
            return Objects.hash(getMessage());
        }
    }

    private static void logAndEmitErrorMetric(String message, Exception e) {
        LOG.error(message, e);
    }
}

How the bug occurs:

  1. createDeepStackTrace(3, "Processing failed") creates an exception with 4 stack frames
  2. new CustomProcessingException("Processing failed", deeperStackTrace) creates an exception with 2 stack frames
  3. Both exceptions have identical messages → equals() returns true → HashMap collision
  4. Metadata from deeper exception (stackLength=4) gets applied to lighter exception (actual length=2)
  5. Renderer tries to access stackTrace[2], stackTrace[3]ArrayIndexOutOfBoundsException

Related

This issue is related to but distinct from #3929. Both issues stem from the Map<Throwable, Context.Metadata> design:

  • Issue #3929: NullPointerException due to concurrent mutation of suppressed exceptions
  • This issue: ArrayIndexOutOfBoundsException due to HashMap key collisions with custom equals() methods

Suggested Fix

Replace HashMap<Throwable, Context.Metadata> and HashSet<Throwable> with identity-based collections:

  • Use IdentityHashMap instead of HashMap
  • Use identity-based Set implementation or System.identityHashCode()
  • Ensure object identity is used consistently across all throwable rendering components

Additionally, review all use cases where Throwable objects are used as HashMap/HashSet keys throughout the Log4j codebase and consider updating them to identity-based collections as well. ex. https://github.com/apache/logging-log4j2/blob/7209b27ba4b2a9a9ce7be99b3a8af9bd74de5ad0/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThrowableStackTraceRenderer.java#L284C42-L284C59

This comprehensive approach would prevent custom equals() implementations from causing key collisions and other unexpected behaviors in Log4j's internal data structures across all exception handling components.

shinstev333 avatar Sep 18 '25 20:09 shinstev333

In addition we've been seeing issues in production. Furthermore there is another issue when stacktraces are updated before and after meatadata creation. We've noticed these happening when stacktrace includes usage of guice AOP interceptors. This will also produce array out of bounds exception

shinstev333 avatar Sep 23 '25 20:09 shinstev333

@shinstev333, thanks a lot for the report. I haven't dug into all the details yet, but your analysis and the suggested fix look sound. Would you mind submitting a PR with accompanying tests, please? I suggest you to consider extending following classes for tests:

  • ExtendedThrowablePatternConverterTest
  • RootThrowablePatternConverterTest
  • ThrowablePatternConverterTest

vy avatar Sep 26 '25 11:09 vy