Getting Exceptions in log4j json template layout when using pointMatcherStrings in stacktrace

[Anshul0507]

Description

Currently, my application produces logs in text format and I need to convert them to json format. The issue with the raw format was that we were getting long exception trails. So our objective was

1. Make sure logs are converted to json
2. We must have stacktrace in the error logs, but the stack trace should be of our application only, java internal stacktrace should not come in logs
3. Any other stacktraces or exceptions should not come in logs. i.e., we must only have json logs separated by \n

Configuration of errorStackTrace in log4j2-template.json
{ "$resolver": "exception", "field": "stackTrace", "stackTrace": { "stringified": { "truncation": { "suffix" : "... [truncated]", "pointMatcherStrings": ["java.base"] } } } }

After using this configuration, I am getting error stacktrace from log4j in my application logs -

2024-09-02 01:23:47,390 http-nio-8080-exec-2 ERROR An exception occurred processing Appender LogToRollingFile java.lang.ArrayIndexOutOfBoundsException: Index 1500 out of bounds for length 1500

Configuration

Version: [2.19.1]

Operating system: [mac OS 14]

JDK: [JDK 17]

Logs

2024-09-02 00:23:47,390 http-nio-8080-exec-2 ERROR An exception occurred processing Appender LogToRollingFile java.lang.ArrayIndexOutOfBoundsException: Index 1500 out of bounds for length 1500
	at org.apache.logging.log4j.layout.template.json.util.TruncatingBufferedWriter.charAt(TruncatingBufferedWriter.java:214)
	at org.apache.logging.log4j.layout.template.json.util.TruncatingBufferedPrintWriter.charAt(TruncatingBufferedPrintWriter.java:69)
	at org.apache.logging.log4j.layout.template.json.resolver.StackTraceStringResolver.findLineStartIndex(StackTraceStringResolver.java:283)
	at org.apache.logging.log4j.layout.template.json.resolver.StackTraceStringResolver.findLabeledLineStartIndex(StackTraceStringResolver.java:226)
	at org.apache.logging.log4j.layout.template.json.resolver.StackTraceStringResolver.truncate(StackTraceStringResolver.java:133)
	at org.apache.logging.log4j.layout.template.json.resolver.StackTraceStringResolver.truncate(StackTraceStringResolver.java:113)
	at org.apache.logging.log4j.layout.template.json.resolver.StackTraceStringResolver.resolve(StackTraceStringResolver.java:91)
	at org.apache.logging.log4j.layout.template.json.resolver.ExceptionResolver.lambda$createStackTraceStringResolver$3(ExceptionResolver.java:307)

Reproduction

We can reproduce it by causing any null pointer exception in a spring boot application.
I don't want anything else in my application logs apart from json bodies. But if I want to use the pointMatcherStrings feature, then I am getting log4j exception stacktrace

[vy]

@Anshul0507, thanks for the report, much appreciated. I am not able to reproduce the issue using the latest version of Log4j, i.e., 2.23.1. Would you mind updating your Log4j dependencies to 2.23.1 and checking if it is still an issue, please?

Reproduction

Downloaded a stock Spring Boot 3.3.3 (which implicitly employs Log4j 2.23.1) application using start.spring.io. I configured the dependencies in pom.xml as follows:

<dependencies>

  <dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter</artifactId>
    <exclusions>
      <exclusion>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-logging</artifactId>
      </exclusion>
    </exclusions>
  </dependency>

  <dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-log4j2</artifactId>
    <scope>runtime</scope>
  </dependency>

  <dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-layout-template-json</artifactId>
    <scope>runtime</scope>
  </dependency>

</dependencies>

Added a test bean:

import org.springframework.stereotype.Component;

import java.net.InetAddress;
import java.net.Socket;

@Component
public class TestBean {

    public TestBean() throws Exception {
        // Trigger an NPE
        new Socket((InetAddress) null, -1);
    }

}

Added following src/main/resources/log4j2.xml:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration 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-config-2.xsd">

  <Appenders>
    <Console name="CONSOLE">
      <JsonTemplateLayout eventTemplateUri="classpath:log4j2-layout.json"/>
    </Console>
  </Appenders>

  <Loggers>
    <Root level="INFO">
      <AppenderRef ref="CONSOLE"/>
    </Root>
  </Loggers>

</Configuration>

Added following src/main/resources/log4j2-layout.json:

{
  "$resolver": "exception",
  "field": "stackTrace",
  "stackTrace": {
    "stringified": {
      "truncation": {
        "suffix": "... [truncated]",
        "pointMatcherStrings": [
          "java.base"
        ]
      }
    }
  }
}

Running Application produces the expected console output without a Log4j failure.

[Anshul0507]

Hey @vy . Thanks for the prompt reply. Its quite weird that I cannot reproduce the issue again. I am still using the same version, did no changes in codebase, still I am not seeing the issue 😃 . I am planning to make the changes live next week on prod with the same configuration.

Thanks again!

[Anshul0507]

Closing the issue as of now. If we re-encounter the issue on prod, then I will make the configurational changes suggested by you and redeploy. If the issue still persists, then will re-open it