Logging ConditionEvaluationReportMessage object into JsonLayout fails

[Armstrong4444]

Hi, The Log4j2 StatusLogger throws an error after attempting to log a ConditionEvaluationReportMessage.

ERROR StatusConsoleListener com.fasterxml.jackson.databind.exc.InvalidDefinitionException: No serializer found for class org.springframework.boot.autoconfigure.logging.ConditionEvaluationReportMessage and no properties discovered to create BeanSerializer (to avoid exception, disable SerializationFeature.FAIL_ON_EMPTY_BEANS) (through reference chain: org.apache.logging.log4j.core.layout.AbstractJacksonLayout$LogEventWithAdditionalFields["logEvent"]->org.apache.logging.log4j.core.impl.Log4jLogEvent["message"])
 com.fasterxml.jackson.databind.exc.InvalidDefinitionException: No serializer found for class org.springframework.boot.autoconfigure.logging.ConditionEvaluationReportMessage and no properties discovered to create BeanSerializer (to avoid exception, disable SerializationFeature.FAIL_ON_EMPTY_BEANS) (through reference chain: org.apache.logging.log4j.core.layout.AbstractJacksonLayout$LogEventWithAdditionalFields["logEvent"]->org.apache.logging.log4j.core.impl.Log4jLogEvent["message"])
    at com.fasterxml.jackson.databind.exc.InvalidDefinitionException.from(InvalidDefinitionException.java:77)
    at com.fasterxml.jackson.databind.SerializerProvider.reportBadDefinition(SerializerProvider.java:1308)
    at com.fasterxml.jackson.databind.DatabindContext.reportBadDefinition(DatabindContext.java:414)
    at com.fasterxml.jackson.databind.ser.impl.UnknownSerializer.failForEmpty(UnknownSerializer.java:53)
    at com.fasterxml.jackson.databind.ser.impl.UnknownSerializer.serialize(UnknownSerializer.java:30)
    at com.fasterxml.jackson.databind.ser.DefaultSerializerProvider._serialize(DefaultSerializerProvider.java:479)
    at com.fasterxml.jackson.databind.ser.DefaultSerializerProvider.serializeValue(DefaultSerializerProvider.java:318)
    at com.fasterxml.jackson.databind.ObjectMapper.writeValue(ObjectMapper.java:3303)
    at com.fasterxml.jackson.core.base.GeneratorBase.writeObject(GeneratorBase.java:389)
    at org.apache.logging.log4j.core.jackson.ObjectMessageSerializer.serialize(ObjectMessageSerializer.java:43)
    at org.apache.logging.log4j.core.jackson.ObjectMessageSerializer.serialize(ObjectMessageSerializer.java:32)
    at com.fasterxml.jackson.databind.ser.BeanPropertyWriter.serializeAsField(BeanPropertyWriter.java:732)
    at com.fasterxml.jackson.databind.ser.impl.SimpleBeanPropertyFilter.serializeAsField(SimpleBeanPropertyFilter.java:218)
    at com.fasterxml.jackson.databind.ser.std.BeanSerializerBase.serializeFieldsFiltered(BeanSerializerBase.java:823)
    at com.fasterxml.jackson.databind.ser.impl.UnwrappingBeanSerializer.serialize(UnwrappingBeanSerializer.java:136)
    at com.fasterxml.jackson.databind.ser.impl.UnwrappingBeanPropertyWriter.serializeAsField(UnwrappingBeanPropertyWriter.java:127)
    at com.fasterxml.jackson.databind.ser.std.BeanSerializerBase.serializeFields(BeanSerializerBase.java:772)
    at com.fasterxml.jackson.databind.ser.BeanSerializer.serialize(BeanSerializer.java:178)
    at com.fasterxml.jackson.databind.ser.DefaultSerializerProvider._serialize(DefaultSerializerProvider.java:479)
    at com.fasterxml.jackson.databind.ser.DefaultSerializerProvider.serializeValue(DefaultSerializerProvider.java:318)
    at com.fasterxml.jackson.databind.ObjectWriter$Prefetch.serialize(ObjectWriter.java:1572)
    at com.fasterxml.jackson.databind.ObjectWriter._writeValueAndClose(ObjectWriter.java:1273)
    at com.fasterxml.jackson.databind.ObjectWriter.writeValue(ObjectWriter.java:1114)
    at org.apache.logging.log4j.core.layout.AbstractJacksonLayout.toSerializable(AbstractJacksonLayout.java:343)
    at org.apache.logging.log4j.core.layout.JsonLayout.toSerializable(JsonLayout.java:292)
    at org.apache.logging.log4j.core.layout.AbstractJacksonLayout.toSerializable(AbstractJacksonLayout.java:291)
    at org.apache.logging.log4j.core.layout.JsonLayout.toSerializable(JsonLayout.java:70)
    at org.apache.logging.log4j.core.layout.AbstractJacksonLayout.toSerializable(AbstractJacksonLayout.java:51)
    at org.apache.logging.log4j.core.layout.AbstractStringLayout.toByteArray(AbstractStringLayout.java:294)
    at org.apache.logging.log4j.core.layout.AbstractLayout.encode(AbstractLayout.java:209)
    at org.apache.logging.log4j.core.layout.AbstractLayout.encode(AbstractLayout.java:37)
    at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.directEncodeEvent(AbstractOutputStreamAppender.java:219)
    at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.tryAppend(AbstractOutputStreamAppender.java:212)
    at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:203)
    at org.apache.logging.log4j.core.appender.RollingFileAppender.append(RollingFileAppender.java:301)
    at org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:161)
    at org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:134)
    at org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:125)
    at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:89)
    at org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:686)
    at org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:644)
    at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:620)
    at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:556)
    at org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:81)
    at org.apache.logging.log4j.core.Logger.log(Logger.java:163)
    at org.apache.logging.log4j.spi.AbstractLogger.tryLogMessage(AbstractLogger.java:2165)
    at org.apache.logging.log4j.spi.AbstractLogger.logMessageTrackRecursion(AbstractLogger.java:2119)
    at org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2102)
    at org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:1954)
    at org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1812)
    at org.apache.commons.logging.LogAdapter$Log4jLog.log(LogAdapter.java:264)
    at org.apache.commons.logging.LogAdapter$Log4jLog.debug(LogAdapter.java:234)
    at org.springframework.boot.autoconfigure.logging.ConditionEvaluationReportLogger.logReport(ConditionEvaluationReportLogger.java:72)
    at org.springframework.boot.autoconfigure.logging.ConditionEvaluationReportLoggingListener$ConditionEvaluationReportListener.onApplicationEvent(ConditionEvaluationReportLoggingListener.java:135)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.doInvokeListener(SimpleApplicationEventMulticaster.java:178)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.invokeListener(SimpleApplicationEventMulticaster.java:171)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:149)
    at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:451)
    at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:384)
    at org.springframework.context.support.AbstractApplicationContext.finishRefresh(AbstractApplicationContext.java:981)
    at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:627)
    at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:146)
    at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:754)
    at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:456)
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:334)
    at cz.elanor.elishrp.common.spring.configuration.HrpCommonApp.run(HrpCommonApp.java:16)
    at cz.elanor.elishrp.webserver.HrpWebserverApplication.main(HrpWebserverApplication.java:31)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:568)
    at org.springframework.boot.devtools.restart.RestartLauncher.run(RestartLauncher.java:50)

Log4j2 xml configuration file is:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration xmlns:xi="http://www.w3.org/2001/XInclude" status="warn">
    <Appenders>
        <Console name="Console" target="SYSTEM_OUT" follow="true">
            <JsonLayout complete="false" compact="true" eventEol="true" includeTimeMillis="true" properties="true" objectMessageAsJsonObject="true" />
    </Console>
    </Appenders>
    <Loggers>               
        <Root level="debug">
            <AppenderRef ref="Console"/>
        </Root>
    </Loggers>
</Configuration>

It seems that the cause of the problem is the attribute 'objectMessageAsJsonObject' set to 'true' in the JsonLayout element. When it is set to 'false', the error is not thrown.

Spring Boot version is 3.2.2

[wilkinsona]

We could, perhaps, change the code that's logging the message to turn it into a String first. However, there's an outside chance that could break someone's existing logging setup that's relying up it being logged as an object for some reason.

Alternatively, you may be able to get this to work by customising the ObjectMapper that Log4j2 is using with a custom serializer for the ConditionEvaluationReportMessage. That converter could be as simple as calling toString() on it.

[Armstrong4444]

Unfortunately, I couldn't find any way to customize the ObjectMapper that log4j2 is using. The ObjectMapper is instantiated in https://github.com/apache/logging-log4j2/blob/rel/2.21.1/log4j-core/src/main/java/org/apache/logging/log4j/core/layout/JacksonFactory.java#L88. This ObjectMapper object is used here: https://github.com/apache/logging-log4j2/blob/e613e9ed71279bb52753a4df810d61c11389df81/log4j-core/src/main/java/org/apache/logging/log4j/core/layout/JacksonFactory.java#L276. The ObjectWriter, which is created from the ObjectMapper, probably can't be customized either, as it is wrapped in JsonLayout without any accessor.

Just one way I see to solve this within Log4j2 is to create a completely new customized JsonLayout (for example MyJsonLayout) plugin instead of using the standard Log4j2 JsonLayout plugin. However, I probably wouldn't do that and would come to accept this issue for the time being.

[mhalbritter]

Hey,

it says here that JsonLayout is deprecated. When using the replacement JsonTemplateLayout and setting stringified to false for the message field, it still serializes MapMessage to a structured JSON. But Log4J will no longer try to serialize all messages to JSON, instead they are written as a String. I guess the Log4j developers learned that serializing every given object to JSON sometimes fails and changed that from JsonLayout to JsonTemplateLayout.

You can see the setup working in action in this repo.

[spring-projects-issues]

If you would like us to look at this issue, please provide the requested information. If the information is not provided within the next 7 days this issue will be closed.

[spring-projects-issues]

Closing due to lack of requested feedback. If you would like us to look at this issue, please provide the requested information and we will re-open the issue.