Details
-
Bug
-
Resolution: Not a bug
-
Critical
-
None
-
2.0.9
-
None
-
None
Description
my setup
library dependencies
<dependency> <groupId>org.slf4j</groupId> <artifactId>slf4j-api</artifactId> <version>2.0.9</version> </dependency> <dependency> <groupId>org.apache.logging.log4j</groupId> <artifactId>log4j-slf4j2-impl</artifactId> <version>2.20.0</version> </dependency>
my log4j2 configuration
<Appenders> <RollingFile name="performanceFileAppender"> <FileName>${path}performance.log</FileName> <FilePattern>${path}performance.%d{yyyy-MM-dd}.log</FilePattern> <PatternLayout pattern="[%d{dd.MM.yyyy HH:mm:ss,SSS}] [%-5p] - %m %n" /> </RollingFile> <Console name="performanceConsoleAppender"> <EcsLayout eventDataset="performance.log"></EcsLayout> </Console> <Loggers> <Logger name="PERFORMANCE"> <AppenderRef ref="performanceFileAppender"/> <AppenderRef ref="performanceConsoleAppender"/> <Level>INFO</Level> </Logger> <Root> <AppenderRef ref="performanceFileAppender"/> <AppenderRef ref="performanceConsoleAppender"/> <Level>INFO</Level> </Root> </Loggers>
my log-requests
with log4j-2.20.0
StringMapMessage log4jMap = new StringMapMessage() .with("message", "direct log4j implementation - Measure times:") .with("myDocId", documentId) .with("myInitExtractorInMs", createFormExtractor) .with("myvalidatedDocumentInMs", validatedDocument) .with("myreadPageInMs", readPage) .with("mytransformInfosInMs", transformInfos); LogManager.getLogger("PERFORMANCE").info(log4jMap);
with slf4j 2.0.9
private static final Logger LOG = LoggerFactory.getLogger("PERFORMANCE"); ... LOG.atInfo().setMessage("slf4j2-with-log4j - Measure times:") .addKeyValue("myDocId", documentId) .addKeyValue("myInitExtractorInMs", createFormExtractor) .addKeyValue("myvalidatedDocumentInMs", validatedDocument) .addKeyValue("myreadPageInMs", readPage) .addKeyValue("mytransformInfosInMs", transformInfos) .log();
What is the issue?
slf4j2 in combination with log4j2:
when logging into Files with a structurized key-value-log-requests with .addKeyValue() (see above at Environment # my log-request)
the resulting logging-output is missing the key-value-logs (see below at # logfile output as example) it does not contain any of the key-value-pairs.
log output with log4j and with slf4j in comparison
json output
here all is fine
log4j output
{ "@timestamp": "2023-09-19T17:25:51.241", "log.level": "INFO", "message": "direct log4j implementation - Measure times:", "myDocId": "60", "myInitExtractorInMs": 79, "myreadPageInMs": 29, "mytransformInfosInMs": 29, "myvalidatedDocumentInMs": 164, "event.dataset": "performance.log", }
slf4j output
{ "@timestamp": "2023-09-19T17:25:51.248", "log.level": "INFO", "message": "slf4j2-with-log4j - Measure times:", "event.dataset": "performance.log", "myDocId": "60", "myInitExtractorInMs": "79", "myreadPageInMs": "29", "mytransformInfosInMs": "29", "myvalidatedDocumentInMs": "164", }
logfile-output
log4j output - it is logging all log-requests that has been done correctly (though the ordering is a bit messy)
[19.09.2023 19:25:51,241] [INFO ] - message="direct log4j implementation - Measure times:" myDocId="60" myInitExtractorInMs="79" myreadPageInMs="29" mytransformInfosInMs="29" myvalidatedDocumentInMs="164"
slf4j output - this is where the bug is - all the key values are missing
[19.09.2023 19:25:51,248] [INFO ] - slf4j2-with-log4j - Measure times: