Fix adding logback mdc appender in spring starter (open-telemetry#13391)

Author: laurit

instrumentation/spring/spring-boot-autoconfigure/build.gradle.kts

@@ -132,6 +132,7 @@ testing {
         implementation("org.springframework.boot:spring-boot-autoconfigure:$springBootVersion")
 
         implementation(project(":instrumentation:logback:logback-appender-1.0:library"))
+        implementation(project(":instrumentation:logback:logback-mdc-1.0:library"))
         // using the same versions as in the spring-boot-autoconfigure
         implementation("ch.qos.logback:logback-classic") {
           version {

instrumentation/spring/spring-boot-autoconfigure/src/main/java/io/opentelemetry/instrumentation/spring/autoconfigure/internal/instrumentation/logging/LogbackAppenderInstaller.java

@@ -172,6 +172,14 @@ private static void addMdcAppender(
     initializeMdcAppenderFromProperties(applicationEnvironmentPreparedEvent, openTelemetryAppender);
     openTelemetryAppender.start();
     logger.addAppender(openTelemetryAppender);
+    // move existing appenders under otel mdc appender, so they could observe the added mdc values
+    for (Iterator<Appender<ILoggingEvent>> i = logger.iteratorForAppenders(); i.hasNext(); ) {
+      Appender<ILoggingEvent> appender = i.next();
+      if (appender != openTelemetryAppender) {
+        openTelemetryAppender.addAppender(appender);
+        logger.detachAppender(appender);
+      }
+    }
   }
 
   private static void initializeMdcAppenderFromProperties(

instrumentation/spring/spring-boot-autoconfigure/src/testLogbackAppender/java/io/opentelemetry/instrumentation/spring/autoconfigure/internal/instrumentation/logging/CustomListAppender.java

@@ -0,0 +1,24 @@
+/*
+ * Copyright The OpenTelemetry Authors
+ * SPDX-License-Identifier: Apache-2.0
+ */
+
+package io.opentelemetry.instrumentation.spring.autoconfigure.internal.instrumentation.logging;
+
+import ch.qos.logback.classic.spi.ILoggingEvent;
+import ch.qos.logback.core.read.ListAppender;
+
+@SuppressWarnings("OtelInternalJavadoc")
+public class CustomListAppender extends ListAppender<ILoggingEvent> {
+  public static boolean lastLogHadTraceId;
+
+  @Override
+  protected void append(ILoggingEvent event) {
+    // Since list appender just captures the event object it is possible that the trace_id is not
+    // present when list appender was called but is added at a later time. Here we record whether
+    // trace_id was present in mdc at the time when the event was processed by the list appender.
+    // https://github.com/open-telemetry/opentelemetry-java-instrumentation/issues/13383
+    lastLogHadTraceId = event.getMDCPropertyMap().get("trace_id") != null;
+    super.append(event);
+  }
+}

instrumentation/spring/spring-boot-autoconfigure/src/testLogbackAppender/java/io/opentelemetry/instrumentation/spring/autoconfigure/internal/instrumentation/logging/LogbackAppenderTest.java

@@ -8,6 +8,7 @@
 import static org.assertj.core.api.Assertions.assertThat;
 
 import ch.qos.logback.classic.spi.ILoggingEvent;
+import ch.qos.logback.core.Appender;
 import ch.qos.logback.core.read.ListAppender;
 import ch.qos.logback.core.spi.AppenderAttachable;
 import io.opentelemetry.api.OpenTelemetry;
@@ -22,6 +23,7 @@
 import io.opentelemetry.instrumentation.testing.junit.LibraryInstrumentationExtension;
 import io.opentelemetry.sdk.logs.data.LogRecordData;
 import java.util.HashMap;
+import java.util.Iterator;
 import java.util.List;
 import java.util.Map;
 import org.junit.jupiter.api.BeforeEach;
@@ -191,6 +193,7 @@ void shouldInitializeMdcAppender() {
     }
 
     assertThat(testing.logRecords()).isEmpty();
+    assertThat(CustomListAppender.lastLogHadTraceId).isTrue();
     assertThat(listAppender.list)
         .satisfiesExactly(
             event ->
@@ -238,13 +241,26 @@ void shouldNotInitializeMdcAppenderWhenDisabled() {
   private static ListAppender<ILoggingEvent> getListAppender() {
     Logger logger = LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME);
     ch.qos.logback.classic.Logger logbackLogger = (ch.qos.logback.classic.Logger) logger;
+
     ListAppender<ILoggingEvent> listAppender =
         (ListAppender<ILoggingEvent>) logbackLogger.getAppender("List");
     if (listAppender != null) {
       return listAppender;
     }
+
     AppenderAttachable<?> mdcAppender =
         (AppenderAttachable<?>) logbackLogger.getAppender("OpenTelemetryMdc");
+    if (mdcAppender == null) {
+      for (Iterator<Appender<ILoggingEvent>> i = logbackLogger.iteratorForAppenders();
+          i.hasNext(); ) {
+        Appender<ILoggingEvent> appender = i.next();
+        if (appender
+            instanceof io.opentelemetry.instrumentation.logback.mdc.v1_0.OpenTelemetryAppender) {
+          mdcAppender = (AppenderAttachable<?>) appender;
+          break;
+        }
+      }
+    }
     return (ListAppender<ILoggingEvent>) mdcAppender.getAppender("List");
   }
 }

instrumentation/spring/spring-boot-autoconfigure/src/testLogbackAppender/resources/logback-no-otel-appenders.xml

@@ -8,7 +8,7 @@
       </pattern>
     </encoder>
   </appender>
-  <appender name="List" class="ch.qos.logback.core.read.ListAppender" />
+  <appender name="List" class="io.opentelemetry.instrumentation.spring.autoconfigure.internal.instrumentation.logging.CustomListAppender" />
 
   <root level="INFO">
     <appender-ref ref="console"/>