Details
-
Bug
-
Status: Resolved
-
Minor
-
Resolution: Fixed
-
2.14.0
-
None
-
- JDK 8
- Spring Boot 2.3.4
- Log4j2 2.14.0
Description
I have used the new messageParameter resolver of the JsonLayoutTemplate introduced with log4j2 v2.14.0 (see LOG4J2-2936).
I configured a Spring Boot app with the following lo4j2.xml:
<?xml version="1.0" encoding="UTF-8"?> <Configuration> <Appenders> <Console name="console" target="SYSTEM_OUT"> <JsonTemplateLayout eventTemplateUri="classpath:MyCustomLayout.json" /> </Console> </Appenders> <Loggers> <Root level="info"> <AppenderRef ref="console" /> </Root> </Loggers> </Configuration>
and the following custom JSON template layout:
{ "@timestamp": { "$resolver": "timestamp", "pattern": { "format": "yyyy-MM-dd'T'HH:mm:ss.SSS'Z'", "timeZone": "UTC" } }, "level": { "$resolver": "level", "field": "name" }, "message": { "$resolver": "message", "stringified": true }, "thread": { "$resolver": "thread", "field": "name" }, "logger": { "$resolver": "logger", "field": "name" }, "labels": { "$resolver": "mdc", "flatten": true, "stringified": true }, "error.type": { "$resolver": "exception", "field": "className" }, "error.message": { "$resolver": "exception", "field": "message" }, "error.stack_trace": { "$resolver": "exception", "field": "stackTrace", "stringified": true }, "p0": { "$resolver": "messageParameter", "index": 0, "stringified": true }, "p1": { "$resolver": "messageParameter", "index": 1, "stringified": true }, "p2": { "$resolver": "messageParameter", "index": 2, "stringified": true }, "p3": { "$resolver": "messageParameter", "index": 3, "stringified": true }
When the app starts the following NullPointerException occurs:
2020-11-28 18:59:57,926 main ERROR An exception occurred processing Appender console java.lang.ArrayIndexOutOfBoundsException: Array index out of range: 1 at org.apache.logging.log4j.layout.template.json.resolver.MessageParameterResolver.resolve(MessageParameterResolver.java:138) at org.apache.logging.log4j.layout.template.json.resolver.MessageParameterResolver.resolve(MessageParameterResolver.java:74) at org.apache.logging.log4j.layout.template.json.resolver.TemplateResolver.resolve(TemplateResolver.java:39) at org.apache.logging.log4j.layout.template.json.resolver.TemplateResolvers$4.resolve(TemplateResolvers.java:320) at org.apache.logging.log4j.layout.template.json.JsonTemplateLayout.encode(JsonTemplateLayout.java:237) at org.apache.logging.log4j.layout.template.json.JsonTemplateLayout.encode(JsonTemplateLayout.java:52) at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.directEncodeEvent(AbstractOutputStreamAppender.java:197) at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.tryAppend(AbstractOutputStreamAppender.java:190) at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:181) at org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:156) at org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:129) at org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:120) at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:84) at org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:543) at org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:502) at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:485) at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:460) at org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:82) at org.apache.logging.log4j.core.Logger.log(Logger.java:161) at org.apache.logging.log4j.spi.AbstractLogger.tryLogMessage(AbstractLogger.java:2198) at org.apache.logging.log4j.spi.AbstractLogger.logMessageTrackRecursion(AbstractLogger.java:2152) at org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2135) at org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:1994) at org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1852) at org.apache.commons.logging.LogAdapter$Log4jLog.log(LogAdapter.java:270) at org.apache.commons.logging.LogAdapter$Log4jLog.info(LogAdapter.java:230) at org.springframework.boot.StartupInfoLogger.logStarting(StartupInfoLogger.java:55) at org.springframework.boot.SpringApplication.logStartupInfo(SpringApplication.java:637) at org.springframework.boot.SpringApplication.prepareContext(SpringApplication.java:373) at org.springframework.boot.SpringApplication.run(SpringApplication.java:314) at org.springframework.boot.SpringApplication.run(SpringApplication.java:1237) at org.springframework.boot.SpringApplication.run(SpringApplication.java:1226) at com.mycompanydomain.Application.main(Application.java:14) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.boot.loader.MainMethodRunner.run(MainMethodRunner.java:49) at org.springframework.boot.loader.Launcher.launch(Launcher.java:107) at org.springframework.boot.loader.Launcher.launch(Launcher.java:58) at org.springframework.boot.loader.JarLauncher.main(JarLauncher.java:88) {"@timestamp":"2020-11-28T17:59:57.944Z","level":"INFO","message":"The following profiles are active: master","thread":"main","logger":"com.mycompanidomain.Application","p0":null,"p1":null,"p2":null,"p3":null} 2020-11-28 19:00:02,249 main ERROR An exception occurred processing Appender console java.lang.ArrayIndexOutOfBoundsException: Array index out of range: 2 at org.apache.logging.log4j.layout.template.json.resolver.MessageParameterResolver.resolve(MessageParameterResolver.java:138) at org.apache.logging.log4j.layout.template.json.resolver.MessageParameterResolver.resolve(MessageParameterResolver.java:74) at org.apache.logging.log4j.layout.template.json.resolver.TemplateResolver.resolve(TemplateResolver.java:39) at org.apache.logging.log4j.layout.template.json.resolver.TemplateResolvers$4.resolve(TemplateResolvers.java:320) at org.apache.logging.log4j.layout.template.json.JsonTemplateLayout.encode(JsonTemplateLayout.java:237) at org.apache.logging.log4j.layout.template.json.JsonTemplateLayout.encode(JsonTemplateLayout.java:52) at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.directEncodeEvent(AbstractOutputStreamAppender.java:197) at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.tryAppend(AbstractOutputStreamAppender.java:190) at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:181) at org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:156) at org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:129) at org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:120) at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:84) at org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:543) at org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:502) at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:485) at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:460) at org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:82) at org.apache.logging.log4j.core.Logger.log(Logger.java:161) at org.apache.logging.log4j.spi.AbstractLogger.tryLogMessage(AbstractLogger.java:2198) at org.apache.logging.log4j.spi.AbstractLogger.logMessageTrackRecursion(AbstractLogger.java:2152) at org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2135) at org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:2034) at org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1907) at org.apache.logging.slf4j.Log4jLogger.info(Log4jLogger.java:189) at org.springframework.data.repository.config.RepositoryConfigurationDelegate.registerRepositoriesIn(RepositoryConfigurationDelegate.java:127) at org.springframework.data.repository.config.RepositoryBeanDefinitionRegistrarSupport.registerBeanDefinitions(RepositoryBeanDefinitionRegistrarSupport.java:107) at org.springframework.context.annotation.ConfigurationClassBeanDefinitionReader.lambda$loadBeanDefinitionsFromRegistrars$1(ConfigurationClassBeanDefinitionReader.java:384) at org.springframework.context.annotation.ConfigurationClassBeanDefinitionReader$$Lambda$297.0000000086A93A90.accept(Unknown Source) at java.util.LinkedHashMap.forEach(LinkedHashMap.java:684) at org.springframework.context.annotation.ConfigurationClassBeanDefinitionReader.loadBeanDefinitionsFromRegistrars(ConfigurationClassBeanDefinitionReader.java:383) at org.springframework.context.annotation.ConfigurationClassBeanDefinitionReader.loadBeanDefinitionsForConfigurationClass(ConfigurationClassBeanDefinitionReader.java:148) at org.springframework.context.annotation.ConfigurationClassBeanDefinitionReader.loadBeanDefinitions(ConfigurationClassBeanDefinitionReader.java:120) at org.springframework.context.annotation.ConfigurationClassPostProcessor.processConfigBeanDefinitions(ConfigurationClassPostProcessor.java:331) at org.springframework.context.annotation.ConfigurationClassPostProcessor.postProcessBeanDefinitionRegistry(ConfigurationClassPostProcessor.java:236) at org.springframework.context.support.PostProcessorRegistrationDelegate.invokeBeanDefinitionRegistryPostProcessors(PostProcessorRegistrationDelegate.java:280) at org.springframework.context.support.PostProcessorRegistrationDelegate.invokeBeanFactoryPostProcessors(PostProcessorRegistrationDelegate.java:96) at org.springframework.context.support.AbstractApplicationContext.invokeBeanFactoryPostProcessors(AbstractApplicationContext.java:707) at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:533) at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:143) at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:758) at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:750) at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:397) at org.springframework.boot.SpringApplication.run(SpringApplication.java:315) at org.springframework.boot.SpringApplication.run(SpringApplication.java:1237) at org.springframework.boot.SpringApplication.run(SpringApplication.java:1226) at com.mycompanydomain.Application.main(Application.java:14) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.boot.loader.MainMethodRunner.run(MainMethodRunner.java:49) at org.springframework.boot.loader.Launcher.launch(Launcher.java:107) at org.springframework.boot.loader.Launcher.launch(Launcher.java:58) at org.springframework.boot.loader.JarLauncher.main(JarLauncher.java:88)
These errors appear only on the first four log messages, after that the messages are properly written without errors.
{"@timestamp":"2020-11-28T18:00:12.390Z","level":"INFO","message":"Tomcat initialized with port(s): 8080 (http)","thread":"main","logger":"org.springframework.boot.web.embedded.tomcat.TomcatWebServer","p0":null,"p1":null,"p2":null,"p3":null} {"@timestamp":"2020-11-28T18:00:12.452Z","level":"INFO","message":"Initializing ProtocolHandler [\"http-nio-8080\"]","thread":"main","logger":"org.apache.coyote.http11.Http11NioProtocol","p0":null,"p1":null,"p2":null,"p3":null} {"@timestamp":"2020-11-28T18:00:12.454Z","level":"INFO","message":"Starting service [Tomcat]","thread":"main","logger":"org.apache.catalina.core.StandardService","p0":null,"p1":null,"p2":null,"p3":null} {"@timestamp":"2020-11-28T18:00:12.455Z","level":"INFO","message":"Starting Servlet engine: [Apache Tomcat/9.0.38]","thread":"main","logger":"org.apache.catalina.core.StandardEngine","p0":null,"p1":null,"p2":null,"p3":null} {"@timestamp":"2020-11-28T18:00:12.622Z","level":"INFO","message":"Initializing Spring embedded WebApplicationContext","thread":"main","logger":"org.apache.catalina.core.ContainerBase.[Tomcat].[localhost].[/]","p0":null,"p1":null,"p2":null,"p3":null} {"@timestamp":"2020-11-28T18:00:12.622Z","level":"INFO","message":"Root WebApplicationContext: initialization completed in 14385 ms","thread":"main","logger":"org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext","p0":null,"p1":null,"p2":null,"p3":null}
Attachments
Issue Links
- links to