Add support for capturing logback mdc attributes

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

@@ -19,7 +19,14 @@ dependencies {
 
   compileOnly(project(":instrumentation-api-appender"))
 
+  implementation(project(":instrumentation:logback:logback-appender-1.0:library"))
+
   latestDepTestLibrary("ch.qos.logback:logback-classic:1.2.+")
 
   testImplementation("org.awaitility:awaitility")
 }
+
+tasks.withType<Test>().configureEach {
+  // TODO run tests both with and without experimental log attributes
+  jvmArgs("-Dotel.instrumentation.logback-appender.experimental.capture-mdc-attributes=*")
+}

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

@@ -13,6 +13,7 @@
 
 import ch.qos.logback.classic.spi.ILoggingEvent;
 import io.opentelemetry.instrumentation.api.appender.LogEmitterProvider;
+import io.opentelemetry.instrumentation.logback.appender.v1_0.internal.LoggingEventMapper;
 import io.opentelemetry.javaagent.extension.instrumentation.TypeInstrumentation;
 import io.opentelemetry.javaagent.extension.instrumentation.TypeTransformer;
 import io.opentelemetry.javaagent.instrumentation.api.CallDepth;
@@ -49,7 +50,7 @@ public static void methodEnter(
       // logging framework delegates to another
       callDepth = CallDepth.forClass(LogEmitterProvider.class);
       if (callDepth.getAndIncrement() == 0) {
-        LogbackHelper.capture(event);
+        LoggingEventMapper.INSTANCE.capture(event);
       }
     }
 

instrumentation/logback/logback-appender-1.0/javaagent/src/test/groovy/LogbackTest.groovy

@@ -3,11 +3,13 @@
  * SPDX-License-Identifier: Apache-2.0
  */
 
+import io.opentelemetry.api.common.AttributeKey
 import io.opentelemetry.instrumentation.test.AgentInstrumentationSpecification
 import io.opentelemetry.sdk.logs.data.Severity
 import io.opentelemetry.semconv.trace.attributes.SemanticAttributes
 import org.slf4j.Logger
 import org.slf4j.LoggerFactory
+import org.slf4j.MDC
 import spock.lang.Unroll
 
 import static io.opentelemetry.instrumentation.test.utils.TraceUtils.runUnderTrace
@@ -95,4 +97,31 @@ class LogbackTest extends AgentInstrumentationSpecification {
     severity = args[3]
     severityText = args[4]
   }
+
+  def "test mdc"() {
+    when:
+    MDC.put("key1", "val1")
+    MDC.put("key2", "val2")
+    try {
+      abcLogger.info("xyz")
+    } finally {
+      MDC.clear()
+    }
+
+    then:
+
+    await()
+      .untilAsserted(
+        () -> {
+          assertThat(logs).hasSize(1)
+        })
+    def log = logs.get(0)
+    assertThat(log.getBody().asString()).isEqualTo("xyz")
+    assertThat(log.getInstrumentationLibraryInfo().getName()).isEqualTo("abc")
+    assertThat(log.getSeverity()).isEqualTo(Severity.INFO)
+    assertThat(log.getSeverityText()).isEqualTo("INFO")
+    assertThat(log.getAttributes().size()).isEqualTo(2)
+    assertThat(log.getAttributes().get(AttributeKey.stringKey("logback.mdc.key1"))).isEqualTo("val1")
+    assertThat(log.getAttributes().get(AttributeKey.stringKey("logback.mdc.key2"))).isEqualTo("val2")
+  }
 }

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

@@ -0,0 +1,20 @@
+plugins {
+  id("otel.library-instrumentation")
+}
+
+dependencies {
+  api(project(":instrumentation-api-appender"))
+
+  library("ch.qos.logback:logback-classic:0.9.16")
+
+  testImplementation(project(":instrumentation-sdk-appender"))
+  testImplementation("io.opentelemetry:opentelemetry-sdk-logs")
+  testImplementation("io.opentelemetry:opentelemetry-sdk-testing")
+
+  testImplementation("org.mockito:mockito-core")
+}
+
+tasks.withType<Test>().configureEach {
+  // TODO run tests both with and without experimental log attributes
+  jvmArgs("-Dotel.instrumentation.logback-appender.experimental.capture-mdc-attributes=*")
+}

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

@@ -0,0 +1,163 @@
+/*
+ * Copyright The OpenTelemetry Authors
+ * SPDX-License-Identifier: Apache-2.0
+ */
+
+package io.opentelemetry.instrumentation.logback.appender.v1_0.internal;
+
+import static java.util.Collections.emptyList;
+
+import ch.qos.logback.classic.Level;
+import ch.qos.logback.classic.spi.ILoggingEvent;
+import ch.qos.logback.classic.spi.ThrowableProxy;
+import io.opentelemetry.api.common.AttributeKey;
+import io.opentelemetry.api.common.Attributes;
+import io.opentelemetry.api.common.AttributesBuilder;
+import io.opentelemetry.context.Context;
+import io.opentelemetry.instrumentation.api.appender.GlobalLogEmitterProvider;
+import io.opentelemetry.instrumentation.api.appender.LogBuilder;
+import io.opentelemetry.instrumentation.api.appender.Severity;
+import io.opentelemetry.instrumentation.api.cache.Cache;
+import io.opentelemetry.instrumentation.api.config.Config;
+import io.opentelemetry.semconv.trace.attributes.SemanticAttributes;
+import java.io.PrintWriter;
+import java.io.StringWriter;
+import java.util.List;
+import java.util.Map;
+import java.util.concurrent.TimeUnit;
+
+public final class LoggingEventMapper {
+
+  public static final LoggingEventMapper INSTANCE = new LoggingEventMapper();
+
+  private static final Cache<String, AttributeKey<String>> mdcAttributeKeys = Cache.bounded(100);
+
+  private final List<String> captureMdcAttributes;
+
+  // cached as an optimization
+  private final boolean captureAllMdcAttributes;
+
+  private LoggingEventMapper() {
+    this(
+        Config.get()
+            .getList(
+                "otel.instrumentation.logback-appender.experimental.capture-mdc-attributes",
+                emptyList()));
+  }
+
+  // visible for testing
+  LoggingEventMapper(List<String> captureMdcAttributes) {
+    this.captureMdcAttributes = captureMdcAttributes;
+    this.captureAllMdcAttributes =
+        captureMdcAttributes.size() == 1 && captureMdcAttributes.get(0).equals("*");
+  }
+
+  public void capture(final ILoggingEvent event) {
+    LogBuilder builder =
+        GlobalLogEmitterProvider.get()
+            .logEmitterBuilder(event.getLoggerName())
+            .build()
+            .logBuilder();
+    mapLoggingEvent(builder, event);
+    builder.emit();
+  }
+
+  /**
+   * Map the {@link ILoggingEvent} data model onto the {@link LogBuilder}. Unmapped fields include:
+   *
+   * <ul>
+   *   <li>Thread name - {@link ILoggingEvent#getThreadName()}
+   *   <li>Marker - {@link ILoggingEvent#getMarker()}
+   *   <li>Mapped diagnostic context - {@link ILoggingEvent#getMDCPropertyMap()}
+   * </ul>
+   */
+  private void mapLoggingEvent(LogBuilder builder, ILoggingEvent loggingEvent) {
+    // message
+    String message = loggingEvent.getMessage();
+    if (message != null) {
+      builder.setBody(message);
+    }
+
+    // time
+    long timestamp = loggingEvent.getTimeStamp();
+    builder.setEpoch(timestamp, TimeUnit.MILLISECONDS);
+
+    // level
+    Level level = loggingEvent.getLevel();
+    if (level != null) {
+      builder.setSeverity(levelToSeverity(level));
+      builder.setSeverityText(level.levelStr);
+    }
+
+    AttributesBuilder attributes = Attributes.builder();
+
+    // throwable
+    Object throwableProxy = loggingEvent.getThrowableProxy();
+    Throwable throwable = null;
+    if (throwableProxy instanceof ThrowableProxy) {
+      // there is only one other subclass of ch.qos.logback.classic.spi.IThrowableProxy
+      // and it is only used for logging exceptions over the wire
+      throwable = ((ThrowableProxy) throwableProxy).getThrowable();
+    }
+    if (throwable != null) {
+      setThrowable(attributes, throwable);
+    }
+
+    captureMdcAttributes(attributes, loggingEvent.getMDCPropertyMap());
+
+    builder.setAttributes(attributes.build());
+
+    // span context
+    builder.setContext(Context.current());
+  }
+
+  // visible for testing
+  void captureMdcAttributes(AttributesBuilder attributes, Map<String, String> mdcProperties) {
+
+    if (captureAllMdcAttributes) {
+      for (Map.Entry<String, String> entry : mdcProperties.entrySet()) {
+        attributes.put(getMdcAttributeKey(entry.getKey()), entry.getValue());
+      }
+      return;
+    }
+
+    for (String key : captureMdcAttributes) {
+      String value = mdcProperties.get(key);
+      if (value != null) {
+        attributes.put(getMdcAttributeKey(key), value);
+      }
+    }
+  }
+
+  public static AttributeKey<String> getMdcAttributeKey(String key) {
+    return mdcAttributeKeys.computeIfAbsent(key, k -> AttributeKey.stringKey("logback.mdc." + k));
+  }
+
+  private static void setThrowable(AttributesBuilder attributes, Throwable throwable) {
+    // TODO (trask) extract method for recording exception into instrumentation-api-appender
+    attributes.put(SemanticAttributes.EXCEPTION_TYPE, throwable.getClass().getName());
+    attributes.put(SemanticAttributes.EXCEPTION_MESSAGE, throwable.getMessage());
+    StringWriter writer = new StringWriter();
+    throwable.printStackTrace(new PrintWriter(writer));
+    attributes.put(SemanticAttributes.EXCEPTION_STACKTRACE, writer.toString());
+  }
+
+  private static Severity levelToSeverity(Level level) {
+    switch (level.levelInt) {
+      case Level.ALL_INT:
+      case Level.TRACE_INT:
+        return Severity.TRACE;
+      case Level.DEBUG_INT:
+        return Severity.DEBUG;
+      case Level.INFO_INT:
+        return Severity.INFO;
+      case Level.WARN_INT:
+        return Severity.WARN;
+      case Level.ERROR_INT:
+        return Severity.ERROR;
+      case Level.OFF_INT:
+      default:
+        return Severity.UNDEFINED_SEVERITY_NUMBER;
+    }
+  }
+}