Logback MDC auto-instrumentation gets muzzled and does not work

instrumentation/logback/logback-1.0.0/auto/src/main/java/io/opentelemetry/instrumentation/auto/logback/v1_0_0/LogbackInstrumentation.java

@@ -16,6 +16,7 @@
 
 package io.opentelemetry.instrumentation.auto.logback.v1_0_0;
 
+import static java.util.Collections.singletonMap;
 import static net.bytebuddy.matcher.ElementMatchers.isMethod;
 import static net.bytebuddy.matcher.ElementMatchers.isPublic;
 import static net.bytebuddy.matcher.ElementMatchers.named;
@@ -24,9 +25,10 @@
 
 import ch.qos.logback.classic.spi.ILoggingEvent;
 import com.google.auto.service.AutoService;
-import io.opentelemetry.instrumentation.logback.v1_0_0.OpenTelemetryAppender;
+import io.opentelemetry.instrumentation.auto.api.InstrumentationContext;
 import io.opentelemetry.javaagent.tooling.Instrumenter;
-import java.util.Collections;
+import io.opentelemetry.trace.Span;
+import io.opentelemetry.trace.TracingContextUtils;
 import java.util.Map;
 import net.bytebuddy.asm.Advice;
 import net.bytebuddy.description.method.MethodDescription;
@@ -41,24 +43,18 @@ public LogbackInstrumentation() {
   }
 
   @Override
-  public String[] helperClassNames() {
-    return new String[] {
-      "io.opentelemetry.instrumentation.logback.v1_0_0.OpenTelemetryAppender",
-      "io.opentelemetry.instrumentation.logback.v1_0_0.LoggingEventWrapper",
-      "io.opentelemetry.instrumentation.logback.v1_0_0.UnionMap",
-      "io.opentelemetry.instrumentation.logback.v1_0_0.UnionMap$ConcatenatedSet",
-      "io.opentelemetry.instrumentation.logback.v1_0_0.UnionMap$ConcatenatedSet$ConcatenatedSetIterator",
-    };
+  public ElementMatcher<? super TypeDescription> typeMatcher() {
+    return named("ch.qos.logback.classic.Logger");
   }
 
   @Override
-  public ElementMatcher<? super TypeDescription> typeMatcher() {
-    return named("ch.qos.logback.classic.Logger");
+  public Map<String, String> contextStore() {
+    return singletonMap("ch.qos.logback.classic.spi.ILoggingEvent", Span.class.getName());
   }
 
   @Override
   public Map<? extends ElementMatcher<? super MethodDescription>, String> transformers() {
-    return Collections.singletonMap(
+    return singletonMap(
         isMethod()
             .and(isPublic())
             .and(named("callAppenders"))
@@ -70,7 +66,8 @@ public Map<? extends ElementMatcher<? super MethodDescription>, String> transfor
   public static class CallAppendersAdvice {
     @Advice.OnMethodEnter
     public static void onEnter(@Advice.Argument(value = 0, readOnly = false) ILoggingEvent event) {
-      event = OpenTelemetryAppender.wrapEvent(event);
+      InstrumentationContext.get(ILoggingEvent.class, Span.class)
+          .put(event, TracingContextUtils.getCurrentSpan());
     }
   }
 }

instrumentation/logback/logback-1.0.0/auto/src/main/java/io/opentelemetry/instrumentation/auto/logback/v1_0_0/LoggingEventInstrumentation.java

@@ -0,0 +1,106 @@
+/*
+ * Copyright The OpenTelemetry Authors
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *     http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+package io.opentelemetry.instrumentation.auto.logback.v1_0_0;
+
+import static io.opentelemetry.javaagent.tooling.bytebuddy.matcher.AgentElementMatchers.implementsInterface;
+import static java.util.Collections.singletonMap;
+import static net.bytebuddy.matcher.ElementMatchers.isMethod;
+import static net.bytebuddy.matcher.ElementMatchers.isPublic;
+import static net.bytebuddy.matcher.ElementMatchers.named;
+import static net.bytebuddy.matcher.ElementMatchers.takesArguments;
+
+import ch.qos.logback.classic.spi.ILoggingEvent;
+import com.google.auto.service.AutoService;
+import io.opentelemetry.instrumentation.auto.api.InstrumentationContext;
+import io.opentelemetry.instrumentation.logback.v1_0_0.internal.UnionMap;
+import io.opentelemetry.javaagent.tooling.Instrumenter;
+import io.opentelemetry.trace.Span;
+import io.opentelemetry.trace.SpanContext;
+import java.util.HashMap;
+import java.util.Map;
+import net.bytebuddy.asm.Advice;
+import net.bytebuddy.description.method.MethodDescription;
+import net.bytebuddy.description.type.TypeDescription;
+import net.bytebuddy.implementation.bytecode.assign.Assigner.Typing;
+import net.bytebuddy.matcher.ElementMatcher;
+
+@AutoService(Instrumenter.class)
+public class LoggingEventInstrumentation extends Instrumenter.Default {
+  public LoggingEventInstrumentation() {
+    super("logback");
+  }
+
+  @Override
+  public String[] helperClassNames() {
+    return new String[] {
+      "io.opentelemetry.instrumentation.logback.v1_0_0.internal.UnionMap",
+      "io.opentelemetry.instrumentation.logback.v1_0_0.internal.UnionMap$ConcatenatedSet",
+      "io.opentelemetry.instrumentation.logback.v1_0_0.internal.UnionMap$ConcatenatedSet$ConcatenatedSetIterator"
+    };
+  }
+
+  @Override
+  public ElementMatcher<? super TypeDescription> typeMatcher() {
+    return implementsInterface(named("ch.qos.logback.classic.spi.ILoggingEvent"));
+  }
+
+  @Override
+  public Map<String, String> contextStore() {
+    return singletonMap("ch.qos.logback.classic.spi.ILoggingEvent", Span.class.getName());
+  }
+
+  @Override
+  public Map<? extends ElementMatcher<? super MethodDescription>, String> transformers() {
+    return singletonMap(
+        isMethod()
+            .and(isPublic())
+            .and(named("getMDCPropertyMap").or(named("getMdc")))
+            .and(takesArguments(0)),
+        LoggingEventInstrumentation.class.getName() + "$GetMdcAdvice");
+  }
+
+  public static class GetMdcAdvice {
+    @Advice.OnMethodExit(suppress = Throwable.class)
+    public static void onExit(
+        @Advice.This ILoggingEvent event,
+        @Advice.Return(typing = Typing.DYNAMIC, readOnly = false) Map<String, String> contextData) {
+      if (contextData != null && contextData.containsKey("traceId")) {
+        // Assume already instrumented event if traceId is present.
+        return;
+      }
+
+      Span currentSpan = InstrumentationContext.get(ILoggingEvent.class, Span.class).get(event);
+      if (currentSpan == null || !currentSpan.getContext().isValid()) {
+        return;
+      }
+
+      Map<String, String> spanContextData = new HashMap<>();
+      SpanContext spanContext = currentSpan.getContext();
+      spanContextData.put("traceId", spanContext.getTraceIdAsHexString());
+      spanContextData.put("spanId", spanContext.getSpanIdAsHexString());
+      if (spanContext.isSampled()) {
+        spanContextData.put("sampled", "true");
+      }
+
+      if (contextData == null) {
+        contextData = spanContextData;
+      } else {
+        contextData = new UnionMap<>(contextData, spanContextData);
+      }
+    }
+  }
+}

instrumentation/logback/logback-1.0.0/library/src/main/java/io/opentelemetry/instrumentation/logback/v1_0_0/OpenTelemetryAppender.java

@@ -21,6 +21,7 @@
 import ch.qos.logback.core.UnsynchronizedAppenderBase;
 import ch.qos.logback.core.spi.AppenderAttachable;
 import ch.qos.logback.core.spi.AppenderAttachableImpl;
+import io.opentelemetry.instrumentation.logback.v1_0_0.internal.UnionMap;
 import io.opentelemetry.trace.Span;
 import io.opentelemetry.trace.SpanContext;
 import io.opentelemetry.trace.TracingContextUtils;

instrumentation/logback/logback-1.0.0/library/src/main/java/io/opentelemetry/instrumentation/logback/v1_0_0/UnionMap.java → instrumentation/logback/logback-1.0.0/library/src/main/java/io/opentelemetry/instrumentation/logback/v1_0_0/internal/UnionMap.java

@@ -14,7 +14,7 @@
  * limitations under the License.
  */
 
-package io.opentelemetry.instrumentation.logback.v1_0_0;
+package io.opentelemetry.instrumentation.logback.v1_0_0.internal;
 
 import java.util.AbstractMap;
 import java.util.AbstractSet;
@@ -29,14 +29,14 @@
  * An immutable view over two maps, with keys resolving from the first map first, or otherwise the
  * second if not present in the first.
  */
-final class UnionMap<K, V> extends AbstractMap<K, V> {
+public final class UnionMap<K, V> extends AbstractMap<K, V> {
 
   private final Map<K, V> first;
   private final Map<K, V> second;
   private int size = -1;
   private Set<Entry<K, V>> entrySet;
 
-  UnionMap(Map<K, V> first, Map<K, V> second) {
+  public UnionMap(Map<K, V> first, Map<K, V> second) {
     this.first = first;
     this.second = second;
   }

instrumentation/logback/logback-1.0.0/library/src/test/groovy/io/opentelemetry/instrumentation/logback/v1_0_0/UnionMapTest.groovy → instrumentation/logback/logback-1.0.0/library/src/test/groovy/io/opentelemetry/instrumentation/logback/v1_0_0/internal/UnionMapTest.groovy

@@ -14,7 +14,7 @@
  * limitations under the License.
  */
 
-package io.opentelemetry.instrumentation.logback.v1_0_0
+package io.opentelemetry.instrumentation.logback.v1_0_0.internal
 
 import spock.lang.Specification
 

javaagent-tooling/src/main/java/io/opentelemetry/javaagent/tooling/matcher/AdditionalLibraryIgnoresMatcher.java

@@ -209,7 +209,10 @@ public boolean matches(T target) {
       if (name.equals("ch.qos.logback.core.AsyncAppenderBase$Worker")) {
         return false;
       }
-      if (name.equals("ch.qos.logback.classic.Logger")) {
+      // Allow instrumenting loggers & events
+      if (name.equals("ch.qos.logback.classic.Logger")
+          || name.equals("ch.qos.logback.classic.spi.LoggingEvent")
+          || name.equals("ch.qos.logback.classic.spi.LoggingEventVO")) {
         return false;
       }
       return true;

javaagent-tooling/src/test/groovy/io/opentelemetry/javaagent/tooling/matcher/AdditionalLibraryIgnoresMatcherTest.groovy

@@ -73,4 +73,23 @@ class AdditionalLibraryIgnoresMatcherTest extends Specification {
     typeName << ["org.springframework.boot.autoconfigure.BackgroundPreinitializer\$InnerClass1",
                  "org.springframework.boot.autoconfigure.condition.OnClassCondition\$ConditionMatch"]
   }
+
+  def "logback - don't match logger and logging events"() {
+    setup:
+    def type = Mock(TypeDescription)
+    type.getActualName() >> typeName
+
+    when:
+    def matches = underTest.matches(type)
+
+    then:
+    !matches
+
+    where:
+    typeName << [
+      "ch.qos.logback.classic.Logger",
+      "ch.qos.logback.classic.spi.LoggingEvent",
+      "ch.qos.logback.classic.spi.LoggingEventVO"
+    ]
+  }
 }