问题描述
log4j2 的 jsontemplatelayout 提供了高度灵活的 json 日志输出能力，允许用户通过 json 模板定义日志事件的结构。通常，我们会为异常信息（如堆栈跟踪）专门设置一个字段，例如 exception.stacktrace。然而，在某些配置下，当日志中包含异常时，完整的堆栈跟踪信息除了出现在预期的 exception.stacktrace 字段外，还会意外地附加到其他不相关的自定义字段中，例如使用 pattern 解析器从环境变量中获取值的 service 或 component 字段。
以下是一个可能导致此问题的 log4j2-layout.json 模板示例：
{
"level": {
"$resolver": "level",
"field": "name"
},
"message": {
"$resolver": "message",
"stringified": true
},
"timestamp": {
"$resolver": "timestamp",
"pattern": {
"format": "yyyy-MM-dd'T'HH:mm:ss.SSS'Z'",
"timeZone": "UTC"
}
},
"logger": {
"$resolver": "logger",
"field": "name"
},
"service": {
"$resolver": "pattern",
"pattern": "${env:FOO_SERVICE}"
},
"component": {
"$resolver": "pattern",
"pattern": "${env:FOO_COMPONENT}"
},
"exception": {
"exception_class": {
"$resolver": "exception",
"field": "className"
},
"exception_message": {
"$resolver": "exception",
"field": "message"
},
"stacktrace": {
"$resolver": "exception",
"field": "stackTrace",
"stackTrace": {
"stringified": true
}
}
},
"line_number": {
"$resolver": "source",
"field": "lineNumber"
}
}以及对应的 log4j2.xml 配置：
当记录一个异常时，日志输出可能出现以下情况，其中 service 和 component 字段被意外地追加了堆栈跟踪：
{"level":"INFO","message":"Force trigger exception","timestamp":"2022-11-02T20:37:35.270Z","logger":"foo.example.acme.system.connector.dataset.EchoAPI","service":"example1 java.lang.Exception: This is a forced exception\n\tat ...","component":"example2 java.lang.Exception: This is a forced exception\n\tat ...","exception":{"exception_class":"java.lang.Exception","exception_message":"This is a forced exception","stacktrace":"java.lang.Exception: This is a forced exception\n\tat ..."}}可以看到，service 和 component 字段在它们原本的值（example1 和 example2）后面，被错误地拼接了完整的异常堆栈信息。
根本原因分析
这个问题的根本原因在于 JsonTemplateLayout 如何处理使用 $resolver: "pattern" 的字段，以及 PatternLayout 的默认行为。
当 JsonTemplateLayout 解析 JSON 模板中定义的一个字段，并且该字段使用了 "$resolver": "pattern" 时，它实际上会委托给内部的 PatternLayout 来解析 pattern 表达式。PatternLayout 有一个配置属性叫做 stackTraceEnabled，它默认值为 true。这意味着，如果日志事件中存在异常，PatternLayout 会自动将异常的堆栈跟踪信息附加到它所解析的模式字符串的末尾。
由于这种委托机制，当 JsonTemplateLayout 处理 service 或 component 字段时，即使它们的 pattern 只是简单的环境变量引用（如 ${env:FOO_SERVICE}），PatternLayout 也会检查当前日志事件是否有异常。如果存在，并且 stackTraceEnabled 为 true（默认值），它就会在解析出的环境变量值后面追加堆栈跟踪，从而导致数据污染。
解决方案
解决此问题的关键在于，对于所有使用 "$resolver": "pattern" 的字段，明确地将 stackTraceEnabled 属性设置为 false。这将阻止 PatternLayout 在解析这些特定模式时自动附加堆栈跟踪。
以下是修正后的 log4j2-layout.json 模板示例：
{
"level": {
"$resolver": "level",
"field": "name"
},
"message": {
"$resolver": "message",
"stringified": true
},
"timestamp": {
"$resolver": "timestamp",
"pattern": {
"format": "yyyy-MM-dd'T'HH:mm:ss.SSS'Z'",
"timeZone": "UTC"
}
},
"logger": {
"$resolver": "logger",
"field": "name"
},
"service": {
"$resolver": "pattern",
"pattern": "${env:FOO_SERVICE}",
"stackTraceEnabled": false <-- 添加此行
},
"component": {
"$resolver": "pattern",
"pattern": "${env:FOO_COMPONENT}",
"stackTraceEnabled": false <-- 添加此行
},
"exception": {
"exception_class": {
"$resolver": "exception",
"field": "className"
},
"exception_message": {
"$resolver": "exception",
"field": "message"
},
"stacktrace": {
"$resolver": "exception",
"field": "stackTrace",
"stackTrace": {
"stringified": true
}
}
},
"line_number": {
"$resolver": "source",
"field": "lineNumber"
}
}通过在 service 和 component 字段的配置中添加 "stackTraceEnabled": false，我们明确指示 Log4j2，在使用 pattern 解析器处理这些字段时，即使存在异常，也不要自动附加堆栈跟踪。这样，堆栈跟踪将只出现在专门为它定义的 exception.stacktrace 字段中，保持日志输出的整洁和结构化。
示例代码
为了演示这一解决方案，我们可以创建一个简单的 Java 类来触发日志事件：
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
public class Log4j2ExceptionDemo {
private static final Logger logger = LogManager.getLogger(Log4j2ExceptionDemo.class);
public static void main(String[] args) {
// 设置环境变量 (或在运行前手动设置)
System.setProperty("FOO_SERVICE", "MyServiceApp");
System.setProperty("FOO_COMPONENT", "DataProcessor");
logger.info("This is a normal log message.");
try {
throw new RuntimeException("This is a forced exception for demonstration.");
} catch (Exception e) {
logger.error("An error occurred during processing.", e);
}
}
}确保 log4j2-layout.json 文件位于 classpath 中，并且 log4j2.xml 配置正确引用了它。运行上述 Java 代码，在应用了解决方案的 log4j2-layout.json 配置下，日志输出将如下所示（为简洁，堆栈跟踪已缩短）：
{"level":"INFO","message":"This is a normal log message.","timestamp":"YYYY-MM-DDTHH:MM:SS.SSSZ","logger":"Log4j2ExceptionDemo","service":"MyServiceApp","component":"DataProcessor","line_number":13}
{"level":"ERROR","message":"An error occurred during processing.","timestamp":"YYYY-MM-DDTHH:MM:SS.SSSZ","logger":"Log4j2ExceptionDemo","service":"MyServiceApp","component":"DataProcessor","exception":{"exception_class":"java.lang.RuntimeException","exception_message":"This is a forced exception for demonstration.","stacktrace":"java.lang.RuntimeException: This is a forced exception for demonstration.\n\tat Log4j2ExceptionDemo.main(Log4j2ExceptionDemo.java:20)\n\t..."},"line_number":22}可以看到，在第二条包含异常的日志中，service 和 component 字段不再包含堆栈跟踪，而堆栈跟踪信息被正确地放置在 exception.stacktrace 字段中，达到了预期的效果。
注意事项
- 适用范围：此解决方案仅适用于使用 "$resolver": "pattern" 的字段。对于其他解析器（如 level、message、timestamp、logger、exception、source 等），它们有各自的处理逻辑，通常不会出现这种堆栈跟踪污染问题。
- 默认行为：PatternLayout 的 stackTraceEnabled 默认值为 true。这意味着，如果你不明确设置它为 false，任何通过 pattern 解析器处理的字段都可能在日志事件包含异常时被附加堆栈跟踪。
-
日志调试：当遇到 Log4j2 配置问题时，可以开启 Log4j2 的内部调试日志，通常通过在 log4j2.xml 的
标签中添加 status="debug" 属性，或者设置系统属性 log4j2.debug=true。这有助于理解 Log4j2 如何解析和处理你的配置。
总结
通过理解 JsonTemplateLayout 如何与 PatternLayout 交互以及 PatternLayout 的 stackTraceEnabled 默认行为，我们可以有效解决 Log4j2 JsonTemplateLayout 中堆栈跟踪意外污染其他 JSON 字段的问题。关键在于对所有使用 pattern 解析器的相关字段，明确地将 stackTraceEnabled 设置为 false，从而确保日志输出的结构化和清晰性，便于后续的日志分析和处理。
