Allow the Spring starter to configure the OTel Logback appender from …

…system properties (open-telemetry#10355)
steverao · Feb 16, 2024 · e08ce94 · e08ce94
1 parent 3c01d90
commit e08ce94
Show file tree

Hide file tree

Showing 6 changed files with 188 additions and 17 deletions.
diff --git a/...tion/spring/autoconfigure/instrumentation/logging/LogbackAppenderApplicationListener.java b/...tion/spring/autoconfigure/instrumentation/logging/LogbackAppenderApplicationListener.java
@@ -10,6 +10,7 @@
 import ch.qos.logback.core.Appender;
 import io.opentelemetry.instrumentation.logback.appender.v1_0.OpenTelemetryAppender;
 import java.util.Iterator;
+import java.util.Optional;
 import org.slf4j.ILoggerFactory;
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
@@ -53,35 +54,130 @@ private static boolean isAssignableFrom(Class<?> type, Class<?>... supportedType
   @Override
   public void onApplicationEvent(ApplicationEvent event) {
     if (event instanceof ApplicationEnvironmentPreparedEvent // Event for which
-        // org.springframework.boot.context.logging.LoggingApplicationListener
-        // initializes logging
-        && !isOpenTelemetryAppenderAlreadyConfigured()) {
-      ch.qos.logback.classic.Logger logger =
-          (ch.qos.logback.classic.Logger)
-              LoggerFactory.getILoggerFactory().getLogger(Logger.ROOT_LOGGER_NAME);
-
-      OpenTelemetryAppender appender = new OpenTelemetryAppender();
-      appender.start();
-      logger.addAppender(appender);
+    // org.springframework.boot.context.logging.LoggingApplicationListener
+    // initializes logging
+    ) {
+      Optional<OpenTelemetryAppender> existingOpenTelemetryAppender = findOpenTelemetryAppender();
+      ApplicationEnvironmentPreparedEvent applicationEnvironmentPreparedEvent =
+          (ApplicationEnvironmentPreparedEvent) event;
+      if (existingOpenTelemetryAppender.isPresent()) {
+        reInitializeOpenTelemetryAppender(
+            existingOpenTelemetryAppender, applicationEnvironmentPreparedEvent);
+      } else {
+        addOpenTelemetryAppender(applicationEnvironmentPreparedEvent);
+      }
+    }
+  }
+
+  private static void reInitializeOpenTelemetryAppender(
+      Optional<OpenTelemetryAppender> existingOpenTelemetryAppender,
+      ApplicationEnvironmentPreparedEvent applicationEnvironmentPreparedEvent) {
+    OpenTelemetryAppender openTelemetryAppender = existingOpenTelemetryAppender.get();
+    // The OpenTelemetry appender is stopped and restarted from the
+    // org.springframework.boot.context.logging.LoggingApplicationListener.initialize
+    // method.
+    // The OpenTelemetryAppender initializes the LoggingEventMapper in the start() method. So, here
+    // we stop the OpenTelemetry appender before its re-initialization and its restart.
+    openTelemetryAppender.stop();
+    initializeOpenTelemetryAppenderFromProperties(
+        applicationEnvironmentPreparedEvent, openTelemetryAppender);
+    openTelemetryAppender.start();
+  }
+
+  private static void addOpenTelemetryAppender(
+      ApplicationEnvironmentPreparedEvent applicationEnvironmentPreparedEvent) {
+    ch.qos.logback.classic.Logger logger =
+        (ch.qos.logback.classic.Logger)
+            LoggerFactory.getILoggerFactory().getLogger(Logger.ROOT_LOGGER_NAME);
+    OpenTelemetryAppender openTelemetryAppender = new OpenTelemetryAppender();
+    initializeOpenTelemetryAppenderFromProperties(
+        applicationEnvironmentPreparedEvent, openTelemetryAppender);
+    openTelemetryAppender.start();
+    logger.addAppender(openTelemetryAppender);
+  }
+
+  private static void initializeOpenTelemetryAppenderFromProperties(
+      ApplicationEnvironmentPreparedEvent applicationEnvironmentPreparedEvent,
+      OpenTelemetryAppender openTelemetryAppender) {
+
+    // Implemented in the same way as the
+    // org.springframework.boot.context.logging.LoggingApplicationListener, config properties not
+    // available
+    Boolean codeAttribute =
+        evaluateBooleanProperty(
+            applicationEnvironmentPreparedEvent,
+            "otel.instrumentation.logback-appender.experimental.capture-code-attributes");
+    if (codeAttribute != null) {
+      openTelemetryAppender.setCaptureCodeAttributes(codeAttribute.booleanValue());
+    }
+
+    Boolean markerAttribute =
+        evaluateBooleanProperty(
+            applicationEnvironmentPreparedEvent,
+            "otel.instrumentation.logback-appender.experimental.capture-marker-attribute");
+    if (markerAttribute != null) {
+      openTelemetryAppender.setCaptureMarkerAttribute(markerAttribute.booleanValue());
     }
+
+    Boolean keyValuePairAttributes =
+        evaluateBooleanProperty(
+            applicationEnvironmentPreparedEvent,
+            "otel.instrumentation.logback-appender.experimental.capture-key-value-pair-attributes");
+    if (keyValuePairAttributes != null) {
+      openTelemetryAppender.setCaptureKeyValuePairAttributes(keyValuePairAttributes.booleanValue());
+    }
+
+    Boolean logAttributes =
+        evaluateBooleanProperty(
+            applicationEnvironmentPreparedEvent,
+            "otel.instrumentation.logback-appender.experimental-log-attributes");
+    if (logAttributes != null) {
+      openTelemetryAppender.setCaptureExperimentalAttributes(logAttributes.booleanValue());
+    }
+
+    Boolean loggerContextAttributes =
+        evaluateBooleanProperty(
+            applicationEnvironmentPreparedEvent,
+            "otel.instrumentation.logback-appender.experimental.capture-logger-context-attributes");
+    if (loggerContextAttributes != null) {
+      openTelemetryAppender.setCaptureLoggerContext(loggerContextAttributes.booleanValue());
+    }
+
+    String mdcAttributeProperty =
+        applicationEnvironmentPreparedEvent
+            .getEnvironment()
+            .getProperty(
+                "otel.instrumentation.logback-appender.experimental.capture-mdc-attributes",
+                String.class);
+    if (mdcAttributeProperty != null) {
+      openTelemetryAppender.setCaptureMdcAttributes(mdcAttributeProperty);
+    }
+  }
+
+  private static Boolean evaluateBooleanProperty(
+      ApplicationEnvironmentPreparedEvent applicationEnvironmentPreparedEvent, String property) {
+    return applicationEnvironmentPreparedEvent
+        .getEnvironment()
+        .getProperty(property, Boolean.class);
   }
 
-  private static boolean isOpenTelemetryAppenderAlreadyConfigured() {
+  private static Optional<OpenTelemetryAppender> findOpenTelemetryAppender() {
     ILoggerFactory loggerFactorySpi = LoggerFactory.getILoggerFactory();
     if (!(loggerFactorySpi instanceof LoggerContext)) {
-      return false;
+      return Optional.empty();
     }
     LoggerContext loggerContext = (LoggerContext) loggerFactorySpi;
     for (ch.qos.logback.classic.Logger logger : loggerContext.getLoggerList()) {
       Iterator<Appender<ILoggingEvent>> appenderIterator = logger.iteratorForAppenders();
       while (appenderIterator.hasNext()) {
         Appender<ILoggingEvent> appender = appenderIterator.next();
         if (appender instanceof OpenTelemetryAppender) {
-          return true;
+          OpenTelemetryAppender openTelemetryAppender = (OpenTelemetryAppender) appender;
+          return Optional.of(openTelemetryAppender);
         }
       }
     }
-    return false;
+    return Optional.empty();
   }
 
   @Override

diff --git a/...t-autoconfigure/src/main/resources/META-INF/additional-spring-configuration-metadata.json b/...t-autoconfigure/src/main/resources/META-INF/additional-spring-configuration-metadata.json
@@ -0,0 +1,44 @@
+{
+  "groups": [
+    {
+      "name": "otel"
+    }
+  ],
+  "properties": [
+    {
+      "name": "otel.instrumentation.logback-appender.experimental.capture-code-attributes",
+      "type": "java.lang.Boolean",
+      "description": "Enable the capture of source code attributes. Note that capturing source code attributes at logging sites might add a performance overhead.",
+      "defaultValue": false
+    },
+    {
+      "name": "otel.instrumentation.logback-appender.experimental.capture-marker-attribute",
+      "type": "java.lang.Boolean",
+      "description": "Enable the capture of Logback markers as attributes.",
+      "defaultValue": false
+    },
+    {
+      "name": "otel.instrumentation.logback-appender.experimental.capture-key-value-pair-attributes",
+      "type": "java.lang.Boolean",
+      "description": "Enable the capture of Logback key value pairs as attributes.",
+      "defaultValue": false
+    },
+    {
+      "name": "otel.instrumentation.logback-appender.experimental-log-attributes",
+      "type": "java.lang.Boolean",
+      "description": "Enable the capture of experimental log attributes thread.name and thread.id.",
+      "defaultValue": false
+    },
+    {
+      "name": "otel.instrumentation.logback-appender.experimental.capture-logger-context-attributes",
+      "type": "java.lang.Boolean",
+      "description": "Enable the capture of Logback logger context properties as attributes.",
+      "defaultValue": false
+    },
+    {
+      "name": "otel.instrumentation.logback-appender.experimental.capture-mdc-attributes",
+      "type": "java.lang.String",
+      "description": "Comma separated list of MDC attributes to capture. Use the wildcard character * to capture all attributes."
+    }
+  ]
+}
diff --git a/...try/instrumentation/spring/autoconfigure/instrumentation/logging/LogbackAppenderTest.java b/...try/instrumentation/spring/autoconfigure/instrumentation/logging/LogbackAppenderTest.java
@@ -8,16 +8,21 @@
 import static org.assertj.core.api.Assertions.assertThat;
 
 import io.opentelemetry.api.OpenTelemetry;
+import io.opentelemetry.api.common.AttributeKey;
+import io.opentelemetry.api.common.Attributes;
 import io.opentelemetry.instrumentation.logback.appender.v1_0.OpenTelemetryAppender;
 import io.opentelemetry.instrumentation.testing.internal.AutoCleanupExtension;
 import io.opentelemetry.instrumentation.testing.junit.InstrumentationExtension;
 import io.opentelemetry.instrumentation.testing.junit.LibraryInstrumentationExtension;
+import io.opentelemetry.sdk.logs.data.LogRecordData;
 import java.util.HashMap;
+import java.util.List;
 import java.util.Map;
 import org.junit.jupiter.api.BeforeEach;
 import org.junit.jupiter.api.Test;
 import org.junit.jupiter.api.extension.RegisterExtension;
 import org.slf4j.LoggerFactory;
+import org.slf4j.MDC;
 import org.springframework.boot.SpringApplication;
 import org.springframework.context.ConfigurableApplicationContext;
 import org.springframework.context.annotation.Bean;
@@ -49,6 +54,10 @@ public OpenTelemetry openTelemetry() {
   void shouldInitializeAppender() {
     Map<String, Object> properties = new HashMap<>();
     properties.put("logging.config", "classpath:logback-test.xml");
+    properties.put(
+        "otel.instrumentation.logback-appender.experimental.capture-mdc-attributes", "*");
+    properties.put(
+        "otel.instrumentation.logback-appender.experimental.capture-code-attributes", false);
 
     SpringApplication app =
         new SpringApplication(
@@ -57,15 +66,30 @@ void shouldInitializeAppender() {
     ConfigurableApplicationContext context = app.run();
     cleanup.deferCleanup(context);
 
-    LoggerFactory.getLogger("test").info("test log message");
+    MDC.put("key1", "val1");
+    MDC.put("key2", "val2");
+    try {
+      LoggerFactory.getLogger("test").info("test log message");
+    } finally {
+      MDC.clear();
+    }
 
-    assertThat(testing.logRecords())
+    List<LogRecordData> logRecords = testing.logRecords();
+    assertThat(logRecords)
         .satisfiesOnlyOnce(
             // OTel appender automatically added or from an XML file, it should not
             // be added a second time by LogbackAppenderApplicationListener
             logRecord -> {
               assertThat(logRecord.getInstrumentationScopeInfo().getName()).isEqualTo("test");
               assertThat(logRecord.getBody().asString()).contains("test log message");
+
+              Attributes attributes = logRecord.getAttributes();
+              // key1 and key2, the code attributes should not be present because they are enabled
+              // in the logback.xml file but are disabled with a property
+              assertThat(attributes.size()).isEqualTo(2);
+              assertThat(attributes.asMap())
+                  .containsEntry(AttributeKey.stringKey("key1"), "val1")
+                  .containsEntry(AttributeKey.stringKey("key2"), "val2");
             });
   }
 

diff --git a/...ation/spring/spring-boot-autoconfigure/src/testLogbackAppender/resources/logback-test.xml b/...ation/spring/spring-boot-autoconfigure/src/testLogbackAppender/resources/logback-test.xml
@@ -9,7 +9,9 @@
     </encoder>
   </appender>
   <appender name="OpenTelemetry"
-    class="io.opentelemetry.instrumentation.logback.appender.v1_0.OpenTelemetryAppender"/>
+    class="io.opentelemetry.instrumentation.logback.appender.v1_0.OpenTelemetryAppender">
+    <captureCodeAttributes>true</captureCodeAttributes>
+  </appender>
 
   <root level="INFO">
     <appender-ref ref="console"/>

diff --git a/smoke-tests-otel-starter/src/main/resources/application.properties b/smoke-tests-otel-starter/src/main/resources/application.properties
@@ -0,0 +1 @@
+otel.instrumentation.logback-appender.experimental.capture-code-attributes=true
diff --git a/...sts-otel-starter/src/test/java/io/opentelemetry/smoketest/OtelSpringStarterSmokeTest.java b/...sts-otel-starter/src/test/java/io/opentelemetry/smoketest/OtelSpringStarterSmokeTest.java
@@ -121,5 +121,9 @@ void shouldSendTelemetry() throws InterruptedException {
         .as("Should instrument logs")
         .startsWith("Starting ")
         .contains(this.getClass().getSimpleName());
+    assertThat(firstLog.getAttributes().asMap())
+        .as("Should capture code attributes")
+        .containsEntry(
+            SemanticAttributes.CODE_NAMESPACE, "org.springframework.boot.StartupInfoLogger");
   }
 }