Muzzle logs should be logged using the io.opentelemetry.* logger name (#7446)

Also, log them on DEBUG when debug mode is off. Related to https://github.com/open-telemetry/opentelemetry-java-instrumentation/pull/7339
2023-01-12 05:18:45 +01:00 · 2023-01-12 05:18:45 +01:00 · bb7a12dc8f
parent cd470080b7
commit bb7a12dc8f
3 changed files with 114 additions and 88 deletions
--- a/javaagent-internal-logging-simple/src/main/java/io/opentelemetry/javaagent/logging/simple/Slf4jSimpleLoggingCustomizer.java
+++ b/javaagent-internal-logging-simple/src/main/java/io/opentelemetry/javaagent/logging/simple/Slf4jSimpleLoggingCustomizer.java
@ -34,9 +34,6 @@ public final class Slf4jSimpleLoggingCustomizer implements LoggingCustomizer {
    if (isDebugMode()) {
      setSystemPropertyDefault(SIMPLE_LOGGER_DEFAULT_LOG_LEVEL_PROPERTY, "DEBUG");
      setSystemPropertyDefault(SIMPLE_LOGGER_PREFIX + "okhttp3.internal.http2", "INFO");
-    } else {
-      // by default muzzle warnings are turned off
-      setSystemPropertyDefault(SIMPLE_LOGGER_PREFIX + "muzzleMatcher", "OFF");
    }

    // trigger loading the provider from the agent CL
--- a/javaagent-tooling/src/main/java/io/opentelemetry/javaagent/tooling/instrumentation/InstrumentationModuleInstaller.java
+++ b/javaagent-tooling/src/main/java/io/opentelemetry/javaagent/tooling/instrumentation/InstrumentationModuleInstaller.java
@ -7,12 +7,10 @@ package io.opentelemetry.javaagent.tooling.instrumentation;

 import static java.util.logging.Level.FINE;
 import static java.util.logging.Level.WARNING;
-import static net.bytebuddy.dynamic.loading.ClassLoadingStrategy.BOOTSTRAP_LOADER;
 import static net.bytebuddy.matcher.ElementMatchers.isAnnotatedWith;
 import static net.bytebuddy.matcher.ElementMatchers.named;
 import static net.bytebuddy.matcher.ElementMatchers.not;

-import io.opentelemetry.instrumentation.api.internal.cache.Cache;
 import io.opentelemetry.javaagent.extension.instrumentation.InstrumentationModule;
 import io.opentelemetry.javaagent.extension.instrumentation.TypeInstrumentation;
 import io.opentelemetry.javaagent.tooling.HelperInjector;
@ -24,26 +22,20 @@ import io.opentelemetry.javaagent.tooling.field.VirtualFieldImplementationInstal
 import io.opentelemetry.javaagent.tooling.field.VirtualFieldImplementationInstallerFactory;
 import io.opentelemetry.javaagent.tooling.muzzle.HelperResourceBuilderImpl;
 import io.opentelemetry.javaagent.tooling.muzzle.InstrumentationModuleMuzzle;
-import io.opentelemetry.javaagent.tooling.muzzle.Mismatch;
-import io.opentelemetry.javaagent.tooling.muzzle.ReferenceMatcher;
 import io.opentelemetry.javaagent.tooling.util.IgnoreFailedTypeMatcher;
 import io.opentelemetry.javaagent.tooling.util.NamedMatcher;
 import io.opentelemetry.sdk.autoconfigure.spi.ConfigProperties;
 import java.lang.instrument.Instrumentation;
-import java.security.ProtectionDomain;
 import java.util.List;
-import java.util.concurrent.atomic.AtomicBoolean;
-import java.util.logging.Logger;
 import net.bytebuddy.agent.builder.AgentBuilder;
 import net.bytebuddy.description.annotation.AnnotationSource;
 import net.bytebuddy.description.type.TypeDescription;
 import net.bytebuddy.matcher.ElementMatcher;
-import net.bytebuddy.utility.JavaModule;

 public final class InstrumentationModuleInstaller {
-  private static final TransformSafeLogger logger =
+
+  static final TransformSafeLogger logger =
      TransformSafeLogger.getLogger(InstrumentationModule.class);
-  private static final Logger muzzleLogger = Logger.getLogger("muzzleMatcher");

  // Added here instead of AgentInstaller's ignores because it's relatively
  // expensive. https://github.com/DataDog/dd-trace-java/pull/1045
@ -88,7 +80,7 @@ public final class InstrumentationModuleInstaller {

    ElementMatcher.Junction<ClassLoader> moduleClassLoaderMatcher =
        instrumentationModule.classLoaderMatcher();
-    MuzzleMatcher muzzleMatcher = new MuzzleMatcher(instrumentationModule);
+    MuzzleMatcher muzzleMatcher = new MuzzleMatcher(logger, instrumentationModule, config);
    AgentBuilder.Transformer helperInjector =
        new HelperInjector(
            instrumentationModule.instrumentationName(),
@ -139,78 +131,4 @@ public final class InstrumentationModuleInstaller {

    return agentBuilder;
  }
-
-  /**
-   * A ByteBuddy matcher that decides whether this instrumentation should be applied. Calls
-   * generated {@link ReferenceMatcher}: if any mismatch with the passed {@code classLoader} is
-   * found this instrumentation is skipped.
-   */
-  private static class MuzzleMatcher implements AgentBuilder.RawMatcher {
-    private final InstrumentationModule instrumentationModule;
-    private final AtomicBoolean initialized = new AtomicBoolean(false);
-    private final Cache<ClassLoader, Boolean> matchCache = Cache.weak();
-    private volatile ReferenceMatcher referenceMatcher;
-
-    private MuzzleMatcher(InstrumentationModule instrumentationModule) {
-      this.instrumentationModule = instrumentationModule;
-    }
-
-    @Override
-    public boolean matches(
-        TypeDescription typeDescription,
-        ClassLoader classLoader,
-        JavaModule module,
-        Class<?> classBeingRedefined,
-        ProtectionDomain protectionDomain) {
-      if (classLoader == BOOTSTRAP_LOADER) {
-        classLoader = Utils.getBootstrapProxy();
-      }
-      return matchCache.computeIfAbsent(classLoader, this::doesMatch);
-    }
-
-    private boolean doesMatch(ClassLoader classLoader) {
-      ReferenceMatcher muzzle = getReferenceMatcher();
-      boolean isMatch = muzzle.matches(classLoader);
-
-      if (!isMatch) {
-        MuzzleFailureCounter.inc();
-        if (muzzleLogger.isLoggable(WARNING)) {
-          muzzleLogger.log(
-              WARNING,
-              "Instrumentation skipped, mismatched references were found: {0} [class {1}] on {2}",
-              new Object[] {
-                instrumentationModule.instrumentationName(),
-                instrumentationModule.getClass().getName(),
-                classLoader
-              });
-          List<Mismatch> mismatches = muzzle.getMismatchedReferenceSources(classLoader);
-          for (Mismatch mismatch : mismatches) {
-            muzzleLogger.log(WARNING, "-- {0}", mismatch);
-          }
-        }
-      } else {
-        if (logger.isLoggable(FINE)) {
-          logger.log(
-              FINE,
-              "Applying instrumentation: {0} [class {1}] on {2}",
-              new Object[] {
-                instrumentationModule.instrumentationName(),
-                instrumentationModule.getClass().getName(),
-                classLoader
-              });
-        }
-      }
-
-      return isMatch;
-    }
-
-    // ReferenceMatcher is lazily created to avoid unnecessarily loading the muzzle references from
-    // the module during the agent setup
-    private ReferenceMatcher getReferenceMatcher() {
-      if (initialized.compareAndSet(false, true)) {
-        referenceMatcher = ReferenceMatcher.of(instrumentationModule);
-      }
-      return referenceMatcher;
-    }
-  }
 }
--- a/javaagent-tooling/src/main/java/io/opentelemetry/javaagent/tooling/instrumentation/MuzzleMatcher.java
+++ b/javaagent-tooling/src/main/java/io/opentelemetry/javaagent/tooling/instrumentation/MuzzleMatcher.java
@ -0,0 +1,111 @@
+/*
+ * Copyright The OpenTelemetry Authors
+ * SPDX-License-Identifier: Apache-2.0
+ */
+
+package io.opentelemetry.javaagent.tooling.instrumentation;
+
+import static java.util.logging.Level.FINE;
+import static java.util.logging.Level.WARNING;
+import static net.bytebuddy.dynamic.loading.ClassLoadingStrategy.BOOTSTRAP_LOADER;
+
+import io.opentelemetry.instrumentation.api.internal.cache.Cache;
+import io.opentelemetry.javaagent.extension.instrumentation.InstrumentationModule;
+import io.opentelemetry.javaagent.tooling.TransformSafeLogger;
+import io.opentelemetry.javaagent.tooling.Utils;
+import io.opentelemetry.javaagent.tooling.config.AgentConfig;
+import io.opentelemetry.javaagent.tooling.muzzle.Mismatch;
+import io.opentelemetry.javaagent.tooling.muzzle.ReferenceMatcher;
+import io.opentelemetry.sdk.autoconfigure.spi.ConfigProperties;
+import java.security.ProtectionDomain;
+import java.util.List;
+import java.util.concurrent.atomic.AtomicBoolean;
+import java.util.logging.Level;
+import java.util.logging.Logger;
+import net.bytebuddy.agent.builder.AgentBuilder;
+import net.bytebuddy.description.type.TypeDescription;
+import net.bytebuddy.utility.JavaModule;
+
+/**
+ * A ByteBuddy matcher that decides whether this instrumentation should be applied. Calls generated
+ * {@link ReferenceMatcher}: if any mismatch with the passed {@code classLoader} is found this
+ * instrumentation is skipped.
+ */
+class MuzzleMatcher implements AgentBuilder.RawMatcher {
+
+  private static final Logger muzzleLogger = Logger.getLogger(MuzzleMatcher.class.getName());
+
+  private final TransformSafeLogger instrumentationLogger;
+  private final InstrumentationModule instrumentationModule;
+  private final Level muzzleLogLevel;
+  private final AtomicBoolean initialized = new AtomicBoolean(false);
+  private final Cache<ClassLoader, Boolean> matchCache = Cache.weak();
+  private volatile ReferenceMatcher referenceMatcher;
+
+  MuzzleMatcher(
+      TransformSafeLogger instrumentationLogger,
+      InstrumentationModule instrumentationModule,
+      ConfigProperties config) {
+    this.instrumentationLogger = instrumentationLogger;
+    this.instrumentationModule = instrumentationModule;
+    this.muzzleLogLevel = AgentConfig.isDebugModeEnabled(config) ? WARNING : FINE;
+  }
+
+  @Override
+  public boolean matches(
+      TypeDescription typeDescription,
+      ClassLoader classLoader,
+      JavaModule module,
+      Class<?> classBeingRedefined,
+      ProtectionDomain protectionDomain) {
+    if (classLoader == BOOTSTRAP_LOADER) {
+      classLoader = Utils.getBootstrapProxy();
+    }
+    return matchCache.computeIfAbsent(classLoader, this::doesMatch);
+  }
+
+  private boolean doesMatch(ClassLoader classLoader) {
+    ReferenceMatcher muzzle = getReferenceMatcher();
+    boolean isMatch = muzzle.matches(classLoader);
+
+    if (!isMatch) {
+      MuzzleFailureCounter.inc();
+      if (muzzleLogger.isLoggable(muzzleLogLevel)) {
+        muzzleLogger.log(
+            muzzleLogLevel,
+            "Instrumentation skipped, mismatched references were found: {0} [class {1}] on {2}",
+            new Object[] {
+              instrumentationModule.instrumentationName(),
+              instrumentationModule.getClass().getName(),
+              classLoader
+            });
+        List<Mismatch> mismatches = muzzle.getMismatchedReferenceSources(classLoader);
+        for (Mismatch mismatch : mismatches) {
+          muzzleLogger.log(muzzleLogLevel, "-- {0}", mismatch);
+        }
+      }
+    } else {
+      if (instrumentationLogger.isLoggable(FINE)) {
+        instrumentationLogger.log(
+            FINE,
+            "Applying instrumentation: {0} [class {1}] on {2}",
+            new Object[] {
+              instrumentationModule.instrumentationName(),
+              instrumentationModule.getClass().getName(),
+              classLoader
+            });
+      }
+    }
+
+    return isMatch;
+  }
+
+  // ReferenceMatcher is lazily created to avoid unnecessarily loading the muzzle references from
+  // the module during the agent setup
+  private ReferenceMatcher getReferenceMatcher() {
+    if (initialized.compareAndSet(false, true)) {
+      referenceMatcher = ReferenceMatcher.of(instrumentationModule);
+    }
+    return referenceMatcher;
+  }
+}