[slf4j-dev] [JIRA] Updates for SLF4J-600: .addKeyValue() log-requests are not getting logged

[slf4j developers list]

SLF4J / SLF4J-600 [Open]
.addKeyValue() log-requests are not getting logged

==============================

Here's what changed in this issue in the last few minutes.

This issue has been created
This issue is now assigned to you.


View or comment on issue using this link
https://jira.qos.ch/browse/SLF4J-600

==============================
 Issue created
------------------------------

Ferhat Bayrak created this issue on 19/Sep/23 19:53

Summary:              .addKeyValue() log-requests are not getting logged
Issue Type:           Bug
Affects Versions:     2.0.9
Assignee:             SLF4J developers list
Created:              19/Sep/23 19:53
Environment:
  h1. my setup
  h2. library dependencies
  {code:java}
  	<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>
  {code}
  h2. my log4j2 configuration
  {code:java}
      <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>
  {code}
  h2. my log-requests
  
  with log4j-2.20.0
  {code:java}
  		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);
  {code}
  with slf4j 2.0.9
  {code:java}
      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();
  {code}
Priority:             Critical
Reporter:             Ferhat Bayrak
Description:
  h1. 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 # 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.
  
   
  h1. log output with log4j and with slf4j in comparison
  h2. json output
  
  here all is fine
  
  log4j output
  {code:java}
  {
      "@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",
  }{code}
  slf4j output
  {code:java}
  {
      "@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",
  }{code}
  h2. logfile-output
  
  log4j output - it is giving just one single log output in a correct way (though the ordering is a bit messy)
  {code:java}
  [19.09.2023 19:25:51,241] [INFO ] - message="direct log4j implementation - Measure times:" myDocId="60" myInitExtractorInMs="79" myreadPageInMs="29" mytransformInfosInMs="29" myvalidatedDocumentInMs="164"{code}
  
  slf4j output - this is where the bug is - all the key values are missing
  {code:java}
  [19.09.2023 19:25:51,248] [INFO ] - slf4j2-with-log4j - Measure times:{code}


==============================
 This message was sent by Atlassian Jira (v9.6.0#960000-sha1:a3ee8af)