implement spans debug logging

Author: SylvainJuge

custom/src/main/java/co/elastic/otel/ElasticAutoConfigurationCustomizerProvider.java

@@ -22,6 +22,7 @@
 import co.elastic.otel.dynamicconfig.BlockableMetricExporter;
 import co.elastic.otel.dynamicconfig.BlockableSpanExporter;
 import co.elastic.otel.dynamicconfig.CentralConfig;
+import co.elastic.otel.logging.AgentLog;
 import com.google.auto.service.AutoService;
 import io.opentelemetry.api.common.AttributeKey;
 import io.opentelemetry.sdk.autoconfigure.spi.AutoConfigurationCustomizer;
@@ -72,6 +73,7 @@ public void customize(AutoConfigurationCustomizer autoConfiguration) {
     autoConfiguration.addTracerProviderCustomizer(
         (providerBuilder, properties) -> {
           CentralConfig.init(providerBuilder, properties);
+          AgentLog.addSpanLoggingIfRequired(providerBuilder, properties);
           return providerBuilder;
         });
   }

internal-logging/build.gradle.kts

@@ -10,6 +10,8 @@ dependencies {
 
   compileOnly("io.opentelemetry.javaagent:opentelemetry-javaagent-tooling")
   compileOnly("io.opentelemetry.javaagent:opentelemetry-javaagent-bootstrap")
+  compileOnly("io.opentelemetry:opentelemetry-sdk-extension-autoconfigure-spi")
+  implementation("io.opentelemetry:opentelemetry-exporter-logging")
   compileOnly(libs.slf4j.api)
   implementation(libs.bundles.log4j2) {
     // Workaround for https://github.com/apache/logging-log4j2/issues/3754

internal-logging/src/main/java/co/elastic/otel/logging/AgentLog.java

@@ -18,6 +18,17 @@
  */
 package co.elastic.otel.logging;
 
+import static java.util.Collections.emptyList;
+
+import io.opentelemetry.exporter.logging.LoggingSpanExporter;
+import io.opentelemetry.sdk.autoconfigure.spi.ConfigProperties;
+import io.opentelemetry.sdk.common.CompletableResultCode;
+import io.opentelemetry.sdk.trace.SdkTracerProviderBuilder;
+import io.opentelemetry.sdk.trace.data.SpanData;
+import io.opentelemetry.sdk.trace.export.SimpleSpanProcessor;
+import io.opentelemetry.sdk.trace.export.SpanExporter;
+import java.util.Collection;
+import java.util.concurrent.atomic.AtomicBoolean;
 import org.apache.logging.log4j.Level;
 import org.apache.logging.log4j.core.config.Configurator;
 import org.apache.logging.log4j.core.config.builder.api.ConfigurationBuilder;
@@ -26,11 +37,21 @@
 
 public class AgentLog {
 
+  /** Upstream instrumentation debug boolean option */
+  public static final String OTEL_JAVAAGENT_DEBUG = "otel.javaagent.debug";
+
   private static final String PATTERN = "%d{DEFAULT} [%t] %-5level %logger{36} - %msg{nolookups}%n";
 
-  // logger is an empty string
+  /** root logger is an empty string */
   private static final String ROOT_LOGGER_NAME = "";
 
+  /**
+   * debug span logging exporter that can be controlled at runtime, only used when logging span
+   * exporter has not been explicitly configured.
+   */
+  private static final DebugLogSpanExporter debugLogSpanExporter =
+      new DebugLogSpanExporter(LoggingSpanExporter.create());
+
   private AgentLog() {}
 
   public static void init() {
@@ -47,6 +68,22 @@ public static void init() {
     Configurator.initialize(conf.build(false));
   }
 
+  public static void addSpanLoggingIfRequired(
+      SdkTracerProviderBuilder providerBuilder, ConfigProperties config) {
+
+    boolean otelDebug = config.getBoolean(OTEL_JAVAAGENT_DEBUG, false);
+
+    // Replicate behavior of upstream agent: span logging exporter is automatically added
+    // when not already present when debugging.
+    // When logging exporter has been explicitly configured, spans logging will be done by the
+    // explicitly configured logging exporter instance
+    boolean loggingExporterNotAlreadyConfigured =
+        !config.getList("otel.traces.exporter", emptyList()).contains("logging");
+    if (otelDebug && loggingExporterNotAlreadyConfigured) {
+      providerBuilder.addSpanProcessor(SimpleSpanProcessor.create(debugLogSpanExporter));
+    }
+  }
+
   public static void setLevel(String level) {
     switch (level) {
       case "trace":
@@ -87,11 +124,46 @@ public static void setLevel(Level level) {
 
     Configurator.setAllLevels(ROOT_LOGGER_NAME, level);
 
-    // when debugging we should avoid very chatty http client debug messages
+    boolean isDebug = level.intLevel() >= Level.DEBUG.intLevel();
+
+    // When debugging, we should avoid very chatty http client debug messages
     // this behavior is replicated from the upstream distribution.
-    if (level.intLevel() >= Level.DEBUG.intLevel()) {
+    if (isDebug) {
       Configurator.setLevel("okhttp3.internal.http2", Level.INFO);
       Configurator.setLevel("okhttp3.internal.concurrent.TaskRunner", Level.INFO);
     }
+
+    // when debugging the upstream otel agent configures an extra debug exporter
+    debugLogSpanExporter.setEnabled(isDebug);
+  }
+
+  private static class DebugLogSpanExporter implements SpanExporter {
+
+    private final SpanExporter delegate;
+    private final AtomicBoolean enabled;
+
+    DebugLogSpanExporter(SpanExporter delegate) {
+      this.delegate = delegate;
+      this.enabled = new AtomicBoolean(false);
+    }
+
+    void setEnabled(boolean value) {
+      enabled.set(value);
+    }
+
+    @Override
+    public CompletableResultCode export(Collection<SpanData> spans) {
+      return enabled.get() ? delegate.export(spans) : CompletableResultCode.ofSuccess();
+    }
+
+    @Override
+    public CompletableResultCode flush() {
+      return enabled.get() ? delegate.flush() : CompletableResultCode.ofSuccess();
+    }
+
+    @Override
+    public CompletableResultCode shutdown() {
+      return enabled.get() ? delegate.shutdown() : CompletableResultCode.ofSuccess();
+    }
   }
 }

internal-logging/src/main/java/co/elastic/otel/logging/ElasticLoggingCustomizer.java

@@ -46,7 +46,7 @@ public void init(EarlyInitAgentConfig earlyConfig) {
     AgentLog.init();
 
     Level level = null;
-    if (earlyConfig.getBoolean("otel.javaagent.debug", false)) {
+    if (earlyConfig.getBoolean(AgentLog.OTEL_JAVAAGENT_DEBUG, false)) {
       // set debug logging when enabled through configuration to behave like the upstream
       // distribution
       level = Level.DEBUG;