Add option to capture logback key value pairs (#8074)

Resolves
https://github.com/open-telemetry/opentelemetry-java-instrumentation/issues/8059

instrumentation/logback/logback-appender-1.0/javaagent/README.md

@@ -5,6 +5,7 @@
 | `otel.instrumentation.logback-appender.experimental-log-attributes` | Boolean | `false` | Enable the capture of experimental span attributes `thread.name` and `thread.id`. |
 | `otel.instrumentation.logback-appender.experimental.capture-code-attributes` | Boolean | `false` | Enable the capture of [source code attributes]. Note that capturing source code attributes at logging sites might add a performance overhead. |
 | `otel.instrumentation.logback-appender.experimental.capture-marker-attribute` | Boolean | `false` | Enable the capture of Logback markers as attributes. |
+| `otel.instrumentation.logback-appender.experimental.capture-key-value-pair-attributes` | Boolean | `false` | Enable the capture of Logback key value pairs as attributes. |
 | `otel.instrumentation.logback-appender.experimental.capture-mdc-attributes` | String  |  | List of MDC attributes to capture. Use the wildcard character `*` to capture all attributes. |
 
 [source code attributes]: https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/trace/semantic_conventions/span-general.md#source-code-attributes

instrumentation/logback/logback-appender-1.0/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/logback/appender/v1_0/LogbackSingletons.java

@@ -27,6 +27,10 @@ public final class LogbackSingletons {
     boolean captureMarkerAttribute =
         config.getBoolean(
             "otel.instrumentation.logback-appender.experimental.capture-marker-attribute", false);
+    boolean captureKeyValuePairAttributes =
+        config.getBoolean(
+            "otel.instrumentation.logback-appender.experimental.capture-key-value-pair-attributes",
+            false);
     List<String> captureMdcAttributes =
         config.getList(
             "otel.instrumentation.logback-appender.experimental.capture-mdc-attributes",
@@ -37,7 +41,8 @@ public final class LogbackSingletons {
             captureExperimentalAttributes,
             captureMdcAttributes,
             captureCodeAttributes,
-            captureMarkerAttribute);
+            captureMarkerAttribute,
+            captureKeyValuePairAttributes);
   }
 
   public static LoggingEventMapper mapper() {

instrumentation/logback/logback-appender-1.0/javaagent/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LogbackTest.java

@@ -16,6 +16,7 @@ import io.opentelemetry.instrumentation.testing.junit.InstrumentationExtension;
 import io.opentelemetry.sdk.common.InstrumentationScopeInfo;
 import io.opentelemetry.sdk.logs.data.LogRecordData;
 import io.opentelemetry.semconv.trace.attributes.SemanticAttributes;
+import java.util.Arrays;
 import java.util.stream.Stream;
 import org.assertj.core.api.AbstractLongAssert;
 import org.junit.jupiter.api.Test;
@@ -215,7 +216,7 @@ class LogbackTest {
         .hasAttributesSatisfyingExactly(
             equalTo(SemanticAttributes.THREAD_NAME, Thread.currentThread().getName()),
             equalTo(SemanticAttributes.THREAD_ID, Thread.currentThread().getId()),
-            equalTo(AttributeKey.stringKey("logback.marker"), markerName),
+            equalTo(AttributeKey.stringArrayKey("logback.marker"), Arrays.asList(markerName)),
             equalTo(SemanticAttributes.CODE_NAMESPACE, LogbackTest.class.getName()),
             equalTo(SemanticAttributes.CODE_FUNCTION, "testMarker"),
             satisfies(SemanticAttributes.CODE_LINENO, AbstractLongAssert::isPositive),

instrumentation/logback/logback-appender-1.0/library/build.gradle.kts

@@ -4,17 +4,20 @@ plugins {
 }
 
 dependencies {
+  compileOnly(project(":muzzle"))
   implementation("io.opentelemetry:opentelemetry-api-logs")
 
   // pin the version strictly to avoid overriding by dependencyManagement versions
   compileOnly("ch.qos.logback:logback-classic") {
     version {
-      strictly("1.0.0")
+      // compiling against newer version than the earliest supported version (1.0.0) to support
+      // features added in 1.3.0
+      strictly("1.3.0")
     }
   }
   compileOnly("org.slf4j:slf4j-api") {
     version {
-      strictly("1.6.4")
+      strictly("2.0.0")
     }
   }
 
@@ -52,3 +55,39 @@ configurations.configureEach {
   exclude("org.apache.groovy", "groovy-json")
   exclude("org.spockframework", "spock-core")
 }
+
+val latestDepTest = findProperty("testLatestDeps") as Boolean
+testing {
+  suites {
+    val slf4j2ApiTest by registering(JvmTestSuite::class) {
+      dependencies {
+        implementation(project(":instrumentation:logback:logback-appender-1.0:library"))
+        implementation("io.opentelemetry:opentelemetry-api-logs")
+        implementation("io.opentelemetry:opentelemetry-sdk-logs")
+        implementation("io.opentelemetry:opentelemetry-sdk-testing")
+
+        if (latestDepTest) {
+          implementation("ch.qos.logback:logback-classic:+")
+          implementation("org.slf4j:slf4j-api:+")
+        } else {
+          implementation("ch.qos.logback:logback-classic") {
+            version {
+              strictly("1.3.0")
+            }
+          }
+          implementation("org.slf4j:slf4j-api") {
+            version {
+              strictly("2.0.0")
+            }
+          }
+        }
+      }
+    }
+  }
+}
+
+tasks {
+  check {
+    dependsOn(testing.suites)
+  }
+}

instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/OpenTelemetryAppender.java

@@ -18,12 +18,13 @@ import org.slf4j.MDC;
 
 public class OpenTelemetryAppender extends UnsynchronizedAppenderBase<ILoggingEvent> {
 
-  private volatile boolean captureExperimentalAttributes = false;
+  private boolean captureExperimentalAttributes = false;
-  private volatile boolean captureCodeAttributes = false;
+  private boolean captureCodeAttributes = false;
-  private volatile boolean captureMarkerAttribute = false;
+  private boolean captureMarkerAttribute = false;
-  private volatile List<String> captureMdcAttributes = emptyList();
+  private boolean captureKeyValuePairAttributes = false;
+  private List<String> captureMdcAttributes = emptyList();
 
-  private volatile LoggingEventMapper mapper;
+  private LoggingEventMapper mapper;
 
   public OpenTelemetryAppender() {}
 
@@ -34,7 +35,8 @@ public class OpenTelemetryAppender extends UnsynchronizedAppenderBase<ILoggingEv
             captureExperimentalAttributes,
             captureMdcAttributes,
             captureCodeAttributes,
-            captureMarkerAttribute);
+            captureMarkerAttribute,
+            captureKeyValuePairAttributes);
     super.start();
   }
 
@@ -73,6 +75,15 @@ public class OpenTelemetryAppender extends UnsynchronizedAppenderBase<ILoggingEv
     this.captureMarkerAttribute = captureMarkerAttribute;
   }
 
+  /**
+   * Sets whether the key value pair attributes should be set to logs.
+   *
+   * @param captureKeyValuePairAttributes To enable or disable the marker attribute
+   */
+  public void setCaptureKeyValuePairAttributes(boolean captureKeyValuePairAttributes) {
+    this.captureKeyValuePairAttributes = captureKeyValuePairAttributes;
+  }
+
   /** Configures the {@link MDC} attributes that will be copied to logs. */
   public void setCaptureMdcAttributes(String attributes) {
     if (attributes != null) {

instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventMapper.java

@@ -16,13 +16,16 @@ import io.opentelemetry.api.logs.LoggerProvider;
 import io.opentelemetry.api.logs.Severity;
 import io.opentelemetry.context.Context;
 import io.opentelemetry.instrumentation.api.internal.cache.Cache;
+import io.opentelemetry.javaagent.tooling.muzzle.NoMuzzle;
 import io.opentelemetry.semconv.trace.attributes.SemanticAttributes;
 import java.io.PrintWriter;
 import java.io.StringWriter;
+import java.util.ArrayList;
 import java.util.List;
 import java.util.Map;
 import java.util.concurrent.TimeUnit;
 import org.slf4j.Marker;
+import org.slf4j.event.KeyValuePair;
 
 /**
  * This class is internal and is hence not for public use. Its APIs are unstable and can change at
@@ -30,25 +33,31 @@ import org.slf4j.Marker;
  */
 public final class LoggingEventMapper {
 
+  private static final boolean supportsKeyValuePairs = supportsKeyValuePairs();
+  private static final boolean supportsMultipleMarkers = supportsMultipleMarkers();
   private static final Cache<String, AttributeKey<String>> mdcAttributeKeys = Cache.bounded(100);
 
-  private static final AttributeKey<String> LOG_MARKER = AttributeKey.stringKey("logback.marker");
+  private static final AttributeKey<List<String>> LOG_MARKER =
+      AttributeKey.stringArrayKey("logback.marker");
 
   private final boolean captureExperimentalAttributes;
   private final List<String> captureMdcAttributes;
   private final boolean captureAllMdcAttributes;
   private final boolean captureCodeAttributes;
   private final boolean captureMarkerAttribute;
+  private final boolean captureKeyValuePairAttributes;
 
   public LoggingEventMapper(
       boolean captureExperimentalAttributes,
       List<String> captureMdcAttributes,
       boolean captureCodeAttributes,
-      boolean captureMarkerAttribute) {
+      boolean captureMarkerAttribute,
+      boolean captureKeyValuePairAttributes) {
     this.captureExperimentalAttributes = captureExperimentalAttributes;
     this.captureCodeAttributes = captureCodeAttributes;
     this.captureMdcAttributes = captureMdcAttributes;
     this.captureMarkerAttribute = captureMarkerAttribute;
+    this.captureKeyValuePairAttributes = captureKeyValuePairAttributes;
     this.captureAllMdcAttributes =
         captureMdcAttributes.size() == 1 && captureMdcAttributes.get(0).equals("*");
   }
@@ -132,11 +141,11 @@ public final class LoggingEventMapper {
     }
 
     if (captureMarkerAttribute) {
-      Marker marker = loggingEvent.getMarker();
+      captureMarkerAttribute(attributes, loggingEvent);
-      if (marker != null) {
+    }
-        String markerName = marker.getName();
+
-        attributes.put(LOG_MARKER, markerName);
+    if (supportsKeyValuePairs && captureKeyValuePairAttributes) {
-      }
+      captureKeyValuePairAttributes(attributes, loggingEvent);
     }
 
     builder.setAllAttributes(attributes.build());
@@ -195,4 +204,76 @@ public final class LoggingEventMapper {
         return Severity.UNDEFINED_SEVERITY_NUMBER;
     }
   }
+
+  @NoMuzzle
+  private static void captureKeyValuePairAttributes(
+      AttributesBuilder attributes, ILoggingEvent loggingEvent) {
+    List<KeyValuePair> keyValuePairs = loggingEvent.getKeyValuePairs();
+    if (keyValuePairs != null) {
+      for (KeyValuePair keyValuePair : keyValuePairs) {
+        if (keyValuePair.value != null) {
+          attributes.put(keyValuePair.key, keyValuePair.value.toString());
+        }
+      }
+    }
+  }
+
+  private static boolean supportsKeyValuePairs() {
+    try {
+      Class.forName("org.slf4j.event.KeyValuePair");
+    } catch (ClassNotFoundException e) {
+      return false;
+    }
+    try {
+      ILoggingEvent.class.getMethod("getKeyValuePairs");
+    } catch (NoSuchMethodException e) {
+      return false;
+    }
+
+    return true;
+  }
+
+  private static void captureMarkerAttribute(
+      AttributesBuilder attributes, ILoggingEvent loggingEvent) {
+    if (supportsMultipleMarkers && hasMultipleMarkers(loggingEvent)) {
+      captureMultipleMarkerAttributes(attributes, loggingEvent);
+    } else {
+      captureSingleMarkerAttribute(attributes, loggingEvent);
+    }
+  }
+
+  @Deprecated // getMarker is deprecate since 1.3.0
+  private static void captureSingleMarkerAttribute(
+      AttributesBuilder attributes, ILoggingEvent loggingEvent) {
+    Marker marker = loggingEvent.getMarker();
+    if (marker != null) {
+      attributes.put(LOG_MARKER, marker.getName());
+    }
+  }
+
+  @NoMuzzle
+  private static void captureMultipleMarkerAttributes(
+      AttributesBuilder attributes, ILoggingEvent loggingEvent) {
+    List<String> markerNames = new ArrayList<>(loggingEvent.getMarkerList().size());
+    for (Marker marker : loggingEvent.getMarkerList()) {
+      markerNames.add(marker.getName());
+    }
+    attributes.put(LOG_MARKER, markerNames.toArray(new String[0]));
+  }
+
+  @NoMuzzle
+  private static boolean hasMultipleMarkers(ILoggingEvent loggingEvent) {
+    List<Marker> markerList = loggingEvent.getMarkerList();
+    return markerList != null && markerList.size() > 1;
+  }
+
+  private static boolean supportsMultipleMarkers() {
+    try {
+      ILoggingEvent.class.getMethod("getMarkerList");
+    } catch (NoSuchMethodException e) {
+      return false;
+    }
+
+    return true;
+  }
 }

instrumentation/logback/logback-appender-1.0/library/src/slf4j2ApiTest/java/io/opentelemetry/instrumentation/logback/appender/v1_0/Slf4j2Test.java

@@ -0,0 +1,94 @@
+/*
+ * Copyright The OpenTelemetry Authors
+ * SPDX-License-Identifier: Apache-2.0
+ */
+
+package io.opentelemetry.instrumentation.logback.appender.v1_0;
+
+import static io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions.assertThat;
+
+import io.opentelemetry.api.common.AttributeKey;
+import io.opentelemetry.api.logs.GlobalLoggerProvider;
+import io.opentelemetry.sdk.common.InstrumentationScopeInfo;
+import io.opentelemetry.sdk.logs.SdkLoggerProvider;
+import io.opentelemetry.sdk.logs.data.LogRecordData;
+import io.opentelemetry.sdk.logs.export.InMemoryLogRecordExporter;
+import io.opentelemetry.sdk.logs.export.SimpleLogRecordProcessor;
+import io.opentelemetry.sdk.resources.Resource;
+import java.util.Arrays;
+import java.util.List;
+import org.junit.jupiter.api.BeforeAll;
+import org.junit.jupiter.api.BeforeEach;
+import org.junit.jupiter.api.Test;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+import org.slf4j.MarkerFactory;
+
+public class Slf4j2Test {
+  private static final Logger logger = LoggerFactory.getLogger("TestLogger");
+
+  private static InMemoryLogRecordExporter logRecordExporter;
+  private static Resource resource;
+  private static InstrumentationScopeInfo instrumentationScopeInfo;
+
+  @BeforeAll
+  static void setupAll() {
+    logRecordExporter = InMemoryLogRecordExporter.create();
+    resource = Resource.getDefault();
+    instrumentationScopeInfo = InstrumentationScopeInfo.create("TestLogger");
+
+    SdkLoggerProvider loggerProvider =
+        SdkLoggerProvider.builder()
+            .setResource(resource)
+            .addLogRecordProcessor(SimpleLogRecordProcessor.create(logRecordExporter))
+            .build();
+
+    GlobalLoggerProvider.resetForTest();
+    GlobalLoggerProvider.set(loggerProvider);
+  }
+
+  @BeforeEach
+  void setup() {
+    logRecordExporter.reset();
+  }
+
+  @Test
+  void keyValue() {
+    logger.atInfo().setMessage("log message 1").addKeyValue("key", "value").log();
+
+    List<LogRecordData> logDataList = logRecordExporter.getFinishedLogItems();
+    assertThat(logDataList).hasSize(1);
+    LogRecordData logData = logDataList.get(0);
+    assertThat(logData.getResource()).isEqualTo(resource);
+    assertThat(logData.getInstrumentationScopeInfo()).isEqualTo(instrumentationScopeInfo);
+    assertThat(logData.getBody().asString()).isEqualTo("log message 1");
+    assertThat(logData.getAttributes().size()).isEqualTo(5); // 4 code attributes + 1 key value pair
+    assertThat(logData.getAttributes())
+        .hasEntrySatisfying(
+            AttributeKey.stringKey("key"), value -> assertThat(value).isEqualTo("value"));
+  }
+
+  @Test
+  void multipleMarkers() {
+    String markerName1 = "aMarker1";
+    String markerName2 = "aMarker2";
+    logger
+        .atInfo()
+        .setMessage("log message 1")
+        .addMarker(MarkerFactory.getMarker(markerName1))
+        .addMarker(MarkerFactory.getMarker(markerName2))
+        .log();
+
+    List<LogRecordData> logDataList = logRecordExporter.getFinishedLogItems();
+    assertThat(logDataList).hasSize(1);
+    LogRecordData logData = logDataList.get(0);
+    assertThat(logData.getResource()).isEqualTo(resource);
+    assertThat(logData.getInstrumentationScopeInfo()).isEqualTo(instrumentationScopeInfo);
+    assertThat(logData.getBody().asString()).isEqualTo("log message 1");
+    assertThat(logData.getAttributes().size()).isEqualTo(5); // 4 code attributes + 1 marker
+    assertThat(logData.getAttributes())
+        .hasEntrySatisfying(
+            AttributeKey.stringArrayKey("logback.marker"),
+            value -> assertThat(value).isEqualTo(Arrays.asList(markerName1, markerName2)));
+  }
+}

instrumentation/logback/logback-appender-1.0/library/src/slf4j2ApiTest/resources/logback-test.xml

@@ -0,0 +1,25 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<configuration>
+
+  <appender name="console" class="ch.qos.logback.core.ConsoleAppender">
+    <encoder>
+      <pattern>
+        %d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n
+      </pattern>
+    </encoder>
+  </appender>
+  <appender name="OpenTelemetry"
+    class="io.opentelemetry.instrumentation.logback.appender.v1_0.OpenTelemetryAppender">
+    <captureExperimentalAttributes>false</captureExperimentalAttributes>
+    <captureCodeAttributes>true</captureCodeAttributes>
+    <captureMarkerAttribute>true</captureMarkerAttribute>
+    <captureKeyValuePairAttributes>true</captureKeyValuePairAttributes>
+    <captureMdcAttributes>*</captureMdcAttributes>
+  </appender>
+
+  <root level="INFO">
+    <appender-ref ref="console"/>
+    <appender-ref ref="OpenTelemetry"/>
+  </root>
+
+</configuration>

instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/OpenTelemetryAppenderConfigTest.java

@@ -5,7 +5,7 @@
 
 package io.opentelemetry.instrumentation.logback.appender.v1_0;
 
-import static org.assertj.core.api.AssertionsForInterfaceTypes.assertThat;
+import static org.assertj.core.api.Assertions.assertThat;
 
 import io.opentelemetry.api.common.AttributeKey;
 import io.opentelemetry.api.logs.GlobalLoggerProvider;
@@ -22,9 +22,9 @@ import io.opentelemetry.sdk.resources.Resource;
 import io.opentelemetry.sdk.trace.SdkTracerProvider;
 import io.opentelemetry.semconv.trace.attributes.SemanticAttributes;
 import java.time.Instant;
+import java.util.Arrays;
 import java.util.List;
 import java.util.concurrent.TimeUnit;
-import org.assertj.core.api.AssertionsForClassTypes;
 import org.junit.jupiter.api.BeforeAll;
 import org.junit.jupiter.api.BeforeEach;
 import org.junit.jupiter.api.Test;
@@ -142,8 +142,9 @@ class OpenTelemetryAppenderConfigTest {
     Long lineNumber = logData.getAttributes().get(SemanticAttributes.CODE_LINENO);
     assertThat(lineNumber).isGreaterThan(1);
 
-    String logMarker = logData.getAttributes().get(AttributeKey.stringKey("logback.marker"));
+    List<String> logMarker =
-    assertThat(logMarker).isEqualTo(markerName);
+        logData.getAttributes().get(AttributeKey.stringArrayKey("logback.marker"));
+    assertThat(logMarker).isEqualTo(Arrays.asList(markerName));
   }
 
   @Test
@@ -163,11 +164,9 @@ class OpenTelemetryAppenderConfigTest {
     assertThat(logData.getInstrumentationScopeInfo()).isEqualTo(instrumentationScopeInfo);
     assertThat(logData.getBody().asString()).isEqualTo("log message 1");
     assertThat(logData.getAttributes().size()).isEqualTo(2 + 4); // 4 code attributes
-    AssertionsForClassTypes.assertThat(
+    assertThat(logData.getAttributes().get(AttributeKey.stringKey("logback.mdc.key1")))
-            logData.getAttributes().get(AttributeKey.stringKey("logback.mdc.key1")))
         .isEqualTo("val1");
-    AssertionsForClassTypes.assertThat(
+    assertThat(logData.getAttributes().get(AttributeKey.stringKey("logback.mdc.key2")))
-            logData.getAttributes().get(AttributeKey.stringKey("logback.mdc.key2")))
         .isEqualTo("val2");
   }
 }

instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventMapperTest.java

@@ -22,7 +22,7 @@ class LoggingEventMapperTest {
   @Test
   void testDefault() {
     // given
-    LoggingEventMapper mapper = new LoggingEventMapper(false, emptyList(), false, false);
+    LoggingEventMapper mapper = new LoggingEventMapper(false, emptyList(), false, false, false);
     Map<String, String> contextData = new HashMap<>();
     contextData.put("key1", "value1");
     contextData.put("key2", "value2");
@@ -38,7 +38,8 @@ class LoggingEventMapperTest {
   @Test
   void testSome() {
     // given
-    LoggingEventMapper mapper = new LoggingEventMapper(false, singletonList("key2"), false, false);
+    LoggingEventMapper mapper =
+        new LoggingEventMapper(false, singletonList("key2"), false, false, false);
     Map<String, String> contextData = new HashMap<>();
     contextData.put("key1", "value1");
     contextData.put("key2", "value2");
@@ -55,7 +56,8 @@ class LoggingEventMapperTest {
   @Test
   void testAll() {
     // given
-    LoggingEventMapper mapper = new LoggingEventMapper(false, singletonList("*"), false, false);
+    LoggingEventMapper mapper =
+        new LoggingEventMapper(false, singletonList("*"), false, false, false);
     Map<String, String> contextData = new HashMap<>();
     contextData.put("key1", "value1");
     contextData.put("key2", "value2");

instrumentation/logback/logback-mdc-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/mdc/v1_0/OpenTelemetryAppender.java

@@ -28,7 +28,7 @@ import java.util.Map;
 
 public class OpenTelemetryAppender extends UnsynchronizedAppenderBase<ILoggingEvent>
     implements AppenderAttachable<ILoggingEvent> {
-  private volatile boolean addBaggage;
+  private boolean addBaggage;
 
   private final AppenderAttachableImpl<ILoggingEvent> aai = new AppenderAttachableImpl<>();