ArrayIndexOutOfBoundsException is thrown when using JsonTemplateLayout and pointMatcherStrings to truncate stack trace

[mv-wj]

Description

ArrayIndexOutOfBoundsException is thrown in org.apache.logging.log4j.layout.template.json.util.TruncatingBufferedWriter with JsonTemplateLayout that uses StackTraceStringResolver.

Configuration

Version: 2.23.1

Operating system: Windows 11

JDK: Eclipse Temurin 17.0.9

Logs

Stack trace of ArrayIndexOutOfBoundsException:

ERROR An exception occurred processing Appender CONSOLE java.lang.ArrayIndexOutOfBoundsException: Index 600 out of bounds for length 600
	at org.apache.logging.log4j.layout.template.json.util.TruncatingBufferedWriter.charAt(TruncatingBufferedWriter.java:208)
	at org.apache.logging.log4j.layout.template.json.util.TruncatingBufferedPrintWriter.charAt(TruncatingBufferedPrintWriter.java:65)
	at org.apache.logging.log4j.layout.template.json.resolver.StackTraceStringResolver.findLineStartIndex(StackTraceStringResolver.java:258)
	at org.apache.logging.log4j.layout.template.json.resolver.StackTraceStringResolver.findLabeledLineStartIndex(StackTraceStringResolver.java:205)
	at org.apache.logging.log4j.layout.template.json.resolver.StackTraceStringResolver.truncate(StackTraceStringResolver.java:122)
	at org.apache.logging.log4j.layout.template.json.resolver.StackTraceStringResolver.truncate(StackTraceStringResolver.java:104)
	at org.apache.logging.log4j.layout.template.json.resolver.StackTraceStringResolver.resolve(StackTraceStringResolver.java:83)
	at org.apache.logging.log4j.layout.template.json.resolver.ExceptionResolver.lambda$createStackTraceStringResolver$3(ExceptionResolver.java:289)
	at org.apache.logging.log4j.layout.template.json.resolver.ExceptionResolver.resolve(ExceptionResolver.java:406)
	at org.apache.logging.log4j.layout.template.json.resolver.ExceptionResolver.resolve(ExceptionResolver.java:192)
	at org.apache.logging.log4j.layout.template.json.resolver.TemplateResolver.resolve(TemplateResolver.java:66)
	at org.apache.logging.log4j.layout.template.json.resolver.TemplateResolvers$PrefixedFieldResolverMethod.resolve(TemplateResolvers.java:314)
	at org.apache.logging.log4j.layout.template.json.resolver.TemplateResolvers$MapResolver.resolve(TemplateResolvers.java:370)
	at org.apache.logging.log4j.layout.template.json.JsonTemplateLayout.encode(JsonTemplateLayout.java:268)
	at org.apache.logging.log4j.layout.template.json.JsonTemplateLayout.encode(JsonTemplateLayout.java:60)
	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:705)
	at org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:663)
	at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:639)
	at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:575)
	at org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:92)
	at org.apache.logging.log4j.core.Logger.log(Logger.java:169)
	at org.apache.logging.log4j.spi.AbstractLogger.tryLogMessage(AbstractLogger.java:2906)
	at org.apache.logging.log4j.spi.AbstractLogger.logMessageTrackRecursion(AbstractLogger.java:2859)
	at org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2841)
	at org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:2620)
	at org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:2567)
	at org.apache.logging.log4j.spi.AbstractLogger.error(AbstractLogger.java:808)
	at com.xxxxxx.xx.xxxxxxxxxxxxxxxxxxxxxxxxxxx.controller.RootController.getRoot(RootController.java:24)
	... [truncating remaining stack trace]

log4j2-spring.xml file (note the maxStringLength=200 was only for testing out whether the stack trace would be truncated properly, in reality it would be set much higher). But the ArrayIndexOutOfBoundsException occurs with maxStringLength=200.

<Configuration>
  <Appenders>
    <Console name="CONSOLE">
      <JsonTemplateLayout eventTemplateUri="classpath:LoggingJsonLayout.json" maxStringLength="200" />
    </Console>
  </Appenders>
  <Loggers>
    <Root level="INFO">
      <AppenderRef ref="CONSOLE"/>
    </Root>
  </Loggers>
</Configuration>

Reproduction

In the method findLineStartIndex, the line `buffer.charAt(i) will cause the ArrayIndexOutOfBoundsException if it doesn't find the line break after startIndex.

@Test
void findLineStartIndex_whenLineFeedNotFoundAfterStartIndex_throwsArrayIndexOutOfBoundsException() throws Exception {
  var writer = TruncatingBufferedPrintWriter.ofCapacity(600);
  writer.write("java.lang.RuntimeException: Outer error\n"
      + "\tat com.xxxxxxx.xx.xxxxxxxxxxxxxxxxxxxxxxxxxxx.controller.RootController.getRoot(RootController.java:24)\n"
      + "\tat java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)\n"
      + "\tat java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)\n"
      + "\tat java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)\n"
      + "\tat java.base/java.lang.reflect.Method.invoke(Method.java:568)\n"
      + "\tat org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMe");

  Method method = StackTraceStringResolver.class
      .getDeclaredMethod("findLineStartIndex", CharSequence.class, int.class, int.class);
  method.setAccessible(true);

  assertDoesNotThrow(() -> method.invoke(null, writer, 0, 600));
  assertDoesNotThrow(() -> method.invoke(null, writer, 42, 600));
  assertDoesNotThrow(() -> method.invoke(null, writer, 148, 600));
  assertDoesNotThrow(() -> method.invoke(null, writer, 232, 600));
  assertDoesNotThrow(() -> method.invoke(null, writer, 334, 600));
  assertDoesNotThrow(() -> method.invoke(null, writer, 444, 600));

  var ex = assertThrows(InvocationTargetException.class, () -> method.invoke(null, writer, 508, 600));
  assertInstanceOf(ArrayIndexOutOfBoundsException.class, ex.getCause());
}

[vy]

@mv-wj, could you reproduce the issue with the latest version, i.e., 2.24.1?

[mv-wj]

@mv-wj, could you reproduce the issue with the latest version, i.e., 2.24.1?

Yes, I can confirm the same ArrayIndexOutOfBoundsException occurs under 2.24.1.

The issue appears to be that the iteration taking place in StackTraceStringResolver.findLineStartIndex method is such that it goes beyond the size of buffer (at least that is the case when setting maxStringLength=200 in the config XML).