You are viewing a plain text version of this content. The canonical link for it is here.
Posted to notifications@logging.apache.org by "Volkan Yazici (Jira)" <ji...@apache.org> on 2020/12/28 18:57:00 UTC

[jira] [Resolved] (LOG4J2-2967) NullPointerException when used the messageParameter resolver of the JsonLayoutTemplate

     [ https://issues.apache.org/jira/browse/LOG4J2-2967?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Volkan Yazici resolved LOG4J2-2967.
-----------------------------------
    Resolution: Fixed

> NullPointerException when used the messageParameter resolver of the JsonLayoutTemplate
> --------------------------------------------------------------------------------------
>
>                 Key: LOG4J2-2967
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-2967
>             Project: Log4j 2
>          Issue Type: Bug
>          Components: Layouts
>    Affects Versions: 2.14.0
>         Environment: * JDK 8
> * Spring Boot 2.3.4
> * Log4j2 2.14.0
>            Reporter: Diego Pettisani
>            Assignee: Volkan Yazici
>            Priority: Minor
>
> 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:
> {code: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>
> {code}
> and the following custom JSON template layout:
> {code:json}
> {
>   "@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
>   }
> {code}
> When the app starts the following {{NullPointerException}} occurs:
> {code}
> 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)
> {code}
> These errors appear only on the first four log messages, after that the messages are properly written without errors.
> {code}
> {"@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}
> {code}



--
This message was sent by Atlassian Jira
(v8.3.4#803005)