Muzzle mismatch logs should be warnings in tests (open-telemetry#1754)

malafeev · Nov 26, 2020 · 90ecff5 · 90ecff5
1 parent 31f1a73
commit 90ecff5
Show file tree

Hide file tree

Showing 4 changed files with 16 additions and 6 deletions.
diff --git a/README.md b/README.md
@@ -398,7 +398,7 @@ Format is "my.package.MyClass1[method1,method2];my.package.MyClass2[method3]" |
 
 To turn on the agent's internal debug logging:
 
-`-Dio.opentelemetry.javaagent.slf4j.simpleLogger.defaultLogLevel=debug`
+`-Dotel.javaagent.debug=true`
 
 **Note**: These logs are extremely verbose. Enable debug logging only when needed.
 Debug logging negatively impacts the performance of your application.

diff --git a/javaagent-bootstrap/src/main/java/io/opentelemetry/javaagent/bootstrap/AgentInitializer.java b/javaagent-bootstrap/src/main/java/io/opentelemetry/javaagent/bootstrap/AgentInitializer.java
@@ -31,6 +31,8 @@ public class AgentInitializer {
       "'[opentelemetry.auto.trace 'yyyy-MM-dd HH:mm:ss:SSS Z']'";
   private static final String SIMPLE_LOGGER_DEFAULT_LOG_LEVEL_PROPERTY =
       "io.opentelemetry.javaagent.slf4j.simpleLogger.defaultLogLevel";
+  private static final String SIMPLE_LOGGER_MUZZLE_LOG_LEVEL_PROPERTY =
+      "io.opentelemetry.javaagent.slf4j.simpleLogger.log.muzzleMatcher";
 
   private static final Logger log;
 
@@ -174,6 +176,9 @@ private static void configureLogger() {
 
     if (isDebugMode()) {
       setSystemPropertyDefault(SIMPLE_LOGGER_DEFAULT_LOG_LEVEL_PROPERTY, "DEBUG");
+    } else {
+      // by default muzzle warnings are turned off
+      setSystemPropertyDefault(SIMPLE_LOGGER_MUZZLE_LOG_LEVEL_PROPERTY, "OFF");
     }
   }
 

diff --git a/...agent-tooling/src/main/java/io/opentelemetry/javaagent/tooling/InstrumentationModule.java b/...agent-tooling/src/main/java/io/opentelemetry/javaagent/tooling/InstrumentationModule.java
@@ -45,6 +45,7 @@
  */
 public abstract class InstrumentationModule {
   private static final Logger log = LoggerFactory.getLogger(InstrumentationModule.class);
+  private static final Logger muzzleLog = LoggerFactory.getLogger("muzzleMatcher");
 
   private static final String[] EMPTY = new String[0];
 
@@ -214,18 +215,20 @@ public boolean matches(
       if (muzzle != null) {
         boolean isMatch = muzzle.matches(classLoader);
 
-        if (log.isDebugEnabled()) {
-          if (!isMatch) {
-            log.debug(
+        if (!isMatch) {
+          if (muzzleLog.isWarnEnabled()) {
+            muzzleLog.warn(
                 "Instrumentation skipped, mismatched references were found: {} -- {} on {}",
                 mainInstrumentationName(),
                 InstrumentationModule.this.getClass().getName(),
                 classLoader);
             List<Mismatch> mismatches = muzzle.getMismatchedReferenceSources(classLoader);
             for (Mismatch mismatch : mismatches) {
-              log.debug("-- {}", mismatch);
+              muzzleLog.warn("-- {}", mismatch);
             }
-          } else {
+          }
+        } else {
+          if (muzzleLog.isDebugEnabled()) {
             log.debug(
                 "Applying instrumentation: {} -- {} on {}",
                 mainInstrumentationName(),

diff --git a/testing-common/src/main/groovy/io/opentelemetry/instrumentation/test/AgentTestRunner.java b/testing-common/src/main/groovy/io/opentelemetry/instrumentation/test/AgentTestRunner.java
@@ -73,6 +73,8 @@ public abstract class AgentTestRunner extends Specification {
     // always run with the thread propagation debugger to help track down sporadic test failures
     System.setProperty("otel.threadPropagationDebugger", "true");
     System.setProperty("otel.internal.failOnContextLeak", "true");
+    // always print muzzle warnings
+    System.setProperty("io.opentelemetry.javaagent.slf4j.simpleLogger.log.muzzleMatcher", "true");
   }
 
   /**