Bridge agent logs into application's slf4j logger (#7339)

Related discussion #7257
Resolves #3413
Resolves #5059
Resolves #6258
Resolves #7179

Adds a logging implementation that'll collect agent logs in memory until
slf4j is detected in the instrumented application; and when that happens
will dump all the logs into the application slf4j and log directly to
the application logger from that time on.

It's still in a POC state, unfortunately: while it works fine with an
app that uses & initializes slf4j directly, Spring Boot applications
actually reconfigure the logging implementation (e.g. logback) a while
after slf4j is loaded; which causes all the startup agent logs (debug
included) to be dumped with the default logback pattern.

Future work:
* ~~Make sure all logs produces by the agent are sent to loggers named
`io.opentelemetry...`
(#7446
DONE
* Make this work on Spring Boot
* Documentation
* Smoke test?

instrumentation-api/build.gradle.kts

@@ -20,6 +20,7 @@ dependencies {
   testImplementation(project(":testing-common"))
   testImplementation("io.opentelemetry:opentelemetry-sdk-metrics")
   testImplementation("io.opentelemetry:opentelemetry-sdk-testing")
+  testImplementation("org.junit-pioneer:junit-pioneer")
 
   jmhImplementation(project(":instrumentation-api-semconv"))
 }
@@ -35,4 +36,10 @@ tasks {
       isEnabled.set(false)
     }
   }
+
+  withType<Test>().configureEach {
+    // required on jdk17
+    jvmArgs("--add-opens=java.base/java.util=ALL-UNNAMED")
+    jvmArgs("-XX:+IgnoreUnrecognizedVMOptions")
+  }
 }

instrumentation-api/src/main/java/io/opentelemetry/instrumentation/api/internal/ConfigPropertiesUtil.java

@@ -19,6 +19,18 @@ public static boolean getBoolean(String propertyName, boolean defaultValue) {
     return strValue == null ? defaultValue : Boolean.parseBoolean(strValue);
   }
 
+  public static int getInt(String propertyName, int defaultValue) {
+    String strValue = getString(propertyName);
+    if (strValue == null) {
+      return defaultValue;
+    }
+    try {
+      return Integer.parseInt(strValue);
+    } catch (NumberFormatException ignored) {
+      return defaultValue;
+    }
+  }
+
   @Nullable
   public static String getString(String propertyName) {
     String value = System.getProperty(propertyName);

instrumentation-api/src/test/java/io/opentelemetry/instrumentation/api/internal/ConfigPropertiesUtilTest.java

@@ -0,0 +1,75 @@
+/*
+ * Copyright The OpenTelemetry Authors
+ * SPDX-License-Identifier: Apache-2.0
+ */
+
+package io.opentelemetry.instrumentation.api.internal;
+
+import static org.assertj.core.api.Assertions.assertThat;
+
+import org.junit.jupiter.api.Test;
+import org.junitpioneer.jupiter.SetEnvironmentVariable;
+import org.junitpioneer.jupiter.SetSystemProperty;
+
+class ConfigPropertiesUtilTest {
+
+  @SetEnvironmentVariable(key = "TEST_PROPERTY_STRING", value = "env")
+  @SetSystemProperty(key = "test.property.string", value = "sys")
+  @Test
+  void getString_systemProperty() {
+    assertThat(ConfigPropertiesUtil.getString("test.property.string")).isEqualTo("sys");
+  }
+
+  @SetEnvironmentVariable(key = "TEST_PROPERTY_STRING", value = "env")
+  @Test
+  void getString_environmentVariable() {
+    assertThat(ConfigPropertiesUtil.getString("test.property.string")).isEqualTo("env");
+  }
+
+  @Test
+  void getString_none() {
+    assertThat(ConfigPropertiesUtil.getString("test.property.string")).isNull();
+  }
+
+  @SetEnvironmentVariable(key = "TEST_PROPERTY_INT", value = "12")
+  @SetSystemProperty(key = "test.property.int", value = "42")
+  @Test
+  void getInt_systemProperty() {
+    assertThat(ConfigPropertiesUtil.getInt("test.property.int", -1)).isEqualTo(42);
+  }
+
+  @SetEnvironmentVariable(key = "TEST_PROPERTY_INT", value = "12")
+  @Test
+  void getInt_environmentVariable() {
+    assertThat(ConfigPropertiesUtil.getInt("test.property.int", -1)).isEqualTo(12);
+  }
+
+  @Test
+  void getInt_none() {
+    assertThat(ConfigPropertiesUtil.getInt("test.property.int", -1)).isEqualTo(-1);
+  }
+
+  @SetSystemProperty(key = "test.property.int", value = "not a number")
+  @Test
+  void getInt_invalidNumber() {
+    assertThat(ConfigPropertiesUtil.getInt("test.property.int", -1)).isEqualTo(-1);
+  }
+
+  @SetEnvironmentVariable(key = "TEST_PROPERTY_BOOLEAN", value = "false")
+  @SetSystemProperty(key = "test.property.boolean", value = "true")
+  @Test
+  void getBoolean_systemProperty() {
+    assertThat(ConfigPropertiesUtil.getBoolean("test.property.boolean", false)).isTrue();
+  }
+
+  @SetEnvironmentVariable(key = "TEST_PROPERTY_BOOLEAN", value = "true")
+  @Test
+  void getBoolean_environmentVariable() {
+    assertThat(ConfigPropertiesUtil.getBoolean("test.property.boolean", false)).isTrue();
+  }
+
+  @Test
+  void getBoolean_none() {
+    assertThat(ConfigPropertiesUtil.getBoolean("test.property.boolean", false)).isFalse();
+  }
+}

instrumentation/internal/internal-application-logger/bootstrap/build.gradle.kts

@@ -0,0 +1,7 @@
+plugins {
+  id("otel.javaagent-bootstrap")
+}
+
+dependencies {
+  compileOnly(project(":javaagent-bootstrap"))
+}

instrumentation/internal/internal-application-logger/bootstrap/src/main/java/io/opentelemetry/javaagent/bootstrap/logging/ApplicationLoggerBridge.java

@@ -0,0 +1,35 @@
+/*
+ * Copyright The OpenTelemetry Authors
+ * SPDX-License-Identifier: Apache-2.0
+ */
+
+package io.opentelemetry.javaagent.bootstrap.logging;
+
+import io.opentelemetry.javaagent.bootstrap.InternalLogger;
+import java.util.concurrent.atomic.AtomicReference;
+
+public abstract class ApplicationLoggerBridge {
+
+  private static final AtomicReference<ApplicationLoggerBridge> applicationLoggerBridge =
+      new AtomicReference<>();
+
+  public static void set(ApplicationLoggerBridge bridge) {
+    if (!applicationLoggerBridge.compareAndSet(null, bridge)) {
+      throw new IllegalStateException(
+          "ApplicationLoggerBridge was already set earlier."
+              + " This should never happen in a properly build javaagent, and it's most likely a result of an error in the javaagent build.");
+    }
+  }
+
+  public static void installApplicationLogger(InternalLogger.Factory applicationLoggerFactory) {
+    ApplicationLoggerBridge bridge = applicationLoggerBridge.get();
+    if (bridge == null) {
+      throw new IllegalStateException(
+          "ApplicationLoggerBridge#set() was not called before an attempt to install a bridge was made."
+              + " This should never happen in a properly build javaagent, and it's most likely a result of an error in the javaagent build.");
+    }
+    bridge.install(applicationLoggerFactory);
+  }
+
+  protected abstract void install(InternalLogger.Factory applicationLoggerFactory);
+}

instrumentation/internal/internal-application-logger/javaagent/build.gradle.kts

@@ -0,0 +1,25 @@
+plugins {
+  id("otel.javaagent-instrumentation")
+}
+
+muzzle {
+  pass {
+    group.set("org.slf4j")
+    module.set("slf4j-api")
+    versions.set("[1.4.0,)")
+    assertInverse.set(true)
+  }
+}
+
+dependencies {
+  bootstrap(project(":instrumentation:internal:internal-application-logger:bootstrap"))
+
+  compileOnly(project(":javaagent-bootstrap"))
+
+  compileOnly("org.slf4j:slf4j-api") {
+    version {
+      // 1.4.0 introduced the TRACE logging level
+      strictly("1.4.0")
+    }
+  }
+}

instrumentation/internal/internal-application-logger/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/internal/logging/ApplicationLoggingIgnoredTypesConfigurer.java

@@ -0,0 +1,20 @@
+/*
+ * Copyright The OpenTelemetry Authors
+ * SPDX-License-Identifier: Apache-2.0
+ */
+
+package io.opentelemetry.javaagent.instrumentation.internal.logging;
+
+import com.google.auto.service.AutoService;
+import io.opentelemetry.javaagent.extension.ignore.IgnoredTypesBuilder;
+import io.opentelemetry.javaagent.extension.ignore.IgnoredTypesConfigurer;
+import io.opentelemetry.sdk.autoconfigure.spi.ConfigProperties;
+
+@AutoService(IgnoredTypesConfigurer.class)
+public final class ApplicationLoggingIgnoredTypesConfigurer implements IgnoredTypesConfigurer {
+
+  @Override
+  public void configure(IgnoredTypesBuilder builder, ConfigProperties config) {
+    builder.allowClass("org.slf4j.LoggerFactory");
+  }
+}

instrumentation/internal/internal-application-logger/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/internal/logging/ApplicationLoggingInstrumentationModule.java

@@ -0,0 +1,33 @@
+/*
+ * Copyright The OpenTelemetry Authors
+ * SPDX-License-Identifier: Apache-2.0
+ */
+
+package io.opentelemetry.javaagent.instrumentation.internal.logging;
+
+import static java.util.Collections.singletonList;
+
+import com.google.auto.service.AutoService;
+import io.opentelemetry.javaagent.extension.instrumentation.InstrumentationModule;
+import io.opentelemetry.javaagent.extension.instrumentation.TypeInstrumentation;
+import io.opentelemetry.sdk.autoconfigure.spi.ConfigProperties;
+import java.util.List;
+
+@AutoService(InstrumentationModule.class)
+public class ApplicationLoggingInstrumentationModule extends InstrumentationModule {
+
+  public ApplicationLoggingInstrumentationModule() {
+    super("internal-application-logging");
+  }
+
+  @Override
+  public boolean defaultEnabled(ConfigProperties config) {
+    // only enable this instrumentation if the application logger is enabled
+    return "application".equals(config.getString("otel.javaagent.logging"));
+  }
+
+  @Override
+  public List<TypeInstrumentation> typeInstrumentations() {
+    return singletonList(new LoggerFactoryInstrumentation());
+  }
+}

instrumentation/internal/internal-application-logger/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/internal/logging/LoggerFactoryInstrumentation.java

@@ -0,0 +1,40 @@
+/*
+ * Copyright The OpenTelemetry Authors
+ * SPDX-License-Identifier: Apache-2.0
+ */
+
+package io.opentelemetry.javaagent.instrumentation.internal.logging;
+
+import static net.bytebuddy.matcher.ElementMatchers.named;
+import static net.bytebuddy.matcher.ElementMatchers.takesArguments;
+
+import io.opentelemetry.javaagent.extension.instrumentation.TypeInstrumentation;
+import io.opentelemetry.javaagent.extension.instrumentation.TypeTransformer;
+import net.bytebuddy.asm.Advice;
+import net.bytebuddy.description.type.TypeDescription;
+import net.bytebuddy.matcher.ElementMatcher;
+
+public class LoggerFactoryInstrumentation implements TypeInstrumentation {
+
+  @Override
+  public ElementMatcher<TypeDescription> typeMatcher() {
+    return named("org.slf4j.LoggerFactory");
+  }
+
+  @Override
+  public void transform(TypeTransformer transformer) {
+    // once a call to getILoggerFactory() exits we can be certain that slf4j is properly initialized
+    transformer.applyAdviceToMethod(
+        named("getILoggerFactory").and(takesArguments(0)),
+        this.getClass().getName() + "$GetLoggerFactoryAdvice");
+  }
+
+  @SuppressWarnings("unused")
+  public static class GetLoggerFactoryAdvice {
+
+    @Advice.OnMethodExit(suppress = Throwable.class)
+    public static void onExit() {
+      Slf4jApplicationLoggerBridge.install();
+    }
+  }
+}

instrumentation/internal/internal-application-logger/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/internal/logging/Slf4jApplicationLoggerBridge.java

@@ -0,0 +1,81 @@
+/*
+ * Copyright The OpenTelemetry Authors
+ * SPDX-License-Identifier: Apache-2.0
+ */
+
+package io.opentelemetry.javaagent.instrumentation.internal.logging;
+
+import io.opentelemetry.javaagent.bootstrap.InternalLogger;
+import io.opentelemetry.javaagent.bootstrap.logging.ApplicationLoggerBridge;
+import java.util.concurrent.atomic.AtomicBoolean;
+import javax.annotation.Nullable;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+
+public final class Slf4jApplicationLoggerBridge implements InternalLogger.Factory {
+
+  private static final AtomicBoolean installed = new AtomicBoolean();
+
+  public static void install() {
+    if (installed.compareAndSet(false, true)) {
+      ApplicationLoggerBridge.installApplicationLogger(new Slf4jApplicationLoggerBridge());
+    }
+  }
+
+  @Override
+  public InternalLogger create(String name) {
+    return new Slf4jApplicationLogger(name);
+  }
+
+  static final class Slf4jApplicationLogger implements InternalLogger {
+
+    private final Logger slf4jLogger;
+
+    Slf4jApplicationLogger(String name) {
+      this.slf4jLogger = LoggerFactory.getLogger(name);
+    }
+
+    @Override
+    public boolean isLoggable(Level level) {
+      switch (level) {
+        case ERROR:
+          return slf4jLogger.isErrorEnabled();
+        case WARN:
+          return slf4jLogger.isWarnEnabled();
+        case INFO:
+          return slf4jLogger.isInfoEnabled();
+        case DEBUG:
+          return slf4jLogger.isDebugEnabled();
+        case TRACE:
+          return slf4jLogger.isTraceEnabled();
+      }
+      return false; // unreachable
+    }
+
+    @Override
+    public void log(Level level, String message, @Nullable Throwable error) {
+      switch (level) {
+        case ERROR:
+          slf4jLogger.error(message, error);
+          break;
+        case WARN:
+          slf4jLogger.warn(message, error);
+          break;
+        case INFO:
+          slf4jLogger.info(message, error);
+          break;
+        case DEBUG:
+          slf4jLogger.debug(message, error);
+          break;
+        case TRACE:
+          slf4jLogger.trace(message, error);
+          break;
+      }
+    }
+
+    @Override
+    public String name() {
+      return slf4jLogger.getName();
+    }
+  }
+}