Add JBoss logging support (#222)

instrumentation/java-util-logging/java-util-logging.gradle

@@ -1 +1,22 @@
 apply from: "${rootDir}/gradle/instrumentation.gradle"
+apply plugin: 'org.unbroken-dome.test-sets'
+
+muzzle {
+  pass {
+    group = 'org.jboss.logmanager'
+    module = 'jboss-logmanager'
+    versions = '(,)'
+  }
+}
+
+testSets {
+  latestDepTest {
+    dirName = 'test'
+  }
+}
+
+dependencies {
+  testCompile 'org.jboss.logmanager:jboss-logmanager:1.0.0.GA'
+
+  latestDepTestCompile 'org.jboss.logmanager:jboss-logmanager:+'
+}

instrumentation/java-util-logging/src/main/java/io/opentelemetry/auto/instrumentation/jul/JavaUtilLoggingSpansInstrumentation.java

@@ -23,6 +23,7 @@ import static net.bytebuddy.matcher.ElementMatchers.takesArgument;
 import static net.bytebuddy.matcher.ElementMatchers.takesArguments;
 
 import com.google.auto.service.AutoService;
+import io.opentelemetry.auto.bootstrap.CallDepthThreadLocalMap;
 import io.opentelemetry.auto.tooling.Instrumenter;
 import java.util.HashMap;
 import java.util.Map;
@@ -61,16 +62,36 @@ public class JavaUtilLoggingSpansInstrumentation extends Instrumenter.Default {
             .and(named("log"))
             .and(takesArguments(1))
             .and(takesArgument(0, named("java.util.logging.LogRecord"))),
-        JavaUtilLoggingSpansInstrumentation.class.getName() + "$LogMessageAdvice");
+        JavaUtilLoggingSpansInstrumentation.class.getName() + "$LogAdvice");
+    transformers.put(
+        isMethod()
+            .and(isPublic())
+            .and(named("logRaw"))
+            .and(takesArguments(1))
+            .and(takesArgument(0, named("org.jboss.logmanager.ExtLogRecord"))),
+        JavaUtilLoggingSpansInstrumentation.class.getName() + "$LogAdvice");
     return transformers;
   }
 
-  public static class LogMessageAdvice {
+  public static class LogAdvice {
 
     @Advice.OnMethodEnter(suppress = Throwable.class)
-    public static void methodEnter(
+    public static boolean methodEnter(
         @Advice.This final Logger logger, @Advice.Argument(0) final LogRecord logRecord) {
-      JavaUtilLoggingSpans.capture(logger, logRecord);
+      // need to track call depth across all loggers in order to avoid double capture when one
+      // logging framework delegates to another
+      final boolean topLevel = CallDepthThreadLocalMap.incrementCallDepth("logger") == 0;
+      if (topLevel) {
+        JavaUtilLoggingSpans.capture(logger, logRecord);
+      }
+      return topLevel;
+    }
+
+    @Advice.OnMethodExit(onThrowable = Throwable.class, suppress = Throwable.class)
+    public static void methodExit(@Advice.Enter final boolean topLevel) {
+      if (topLevel) {
+        CallDepthThreadLocalMap.reset("logger");
+      }
     }
   }
 }

instrumentation/java-util-logging/src/test/groovy/JBossJavaUtilLoggingEventTest.groovy

@@ -0,0 +1,33 @@
+/*
+ * Copyright 2020, OpenTelemetry Authors
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *     http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+import io.opentelemetry.auto.test.log.events.LogEventsTestBase
+import org.jboss.logmanager.LogContext
+
+class JBossJavaUtilLoggingEventTest extends LogEventsTestBase {
+
+  @Override
+  Object createLogger(String name) {
+    LogContext.create().getLogger(name)
+  }
+
+  String warn() {
+    return "warning"
+  }
+
+  String error() {
+    return "severe"
+  }
+}

instrumentation/log4j/log4j-1.1/src/main/java/io/opentelemetry/auto/instrumentation/log4j/v1_1/Log4jSpansInstrumentation.java

@@ -22,6 +22,7 @@ import static net.bytebuddy.matcher.ElementMatchers.takesArgument;
 import static net.bytebuddy.matcher.ElementMatchers.takesArguments;
 
 import com.google.auto.service.AutoService;
+import io.opentelemetry.auto.bootstrap.CallDepthThreadLocalMap;
 import io.opentelemetry.auto.tooling.Instrumenter;
 import java.util.HashMap;
 import java.util.Map;
@@ -67,12 +68,25 @@ public class Log4jSpansInstrumentation extends Instrumenter.Default {
   public static class ForcedLogAdvice {
 
     @Advice.OnMethodEnter(suppress = Throwable.class)
-    public static void methodEnter(
+    public static boolean methodEnter(
         @Advice.This final Category logger,
         @Advice.Argument(1) final Priority level,
         @Advice.Argument(2) final Object message,
         @Advice.Argument(3) final Throwable t) {
-      Log4jSpans.capture(logger, level, message, t);
+      // need to track call depth across all loggers to avoid double capture when one logging
+      // framework delegates to another
+      final boolean topLevel = CallDepthThreadLocalMap.incrementCallDepth("logger") == 0;
+      if (topLevel) {
+        Log4jSpans.capture(logger, level, message, t);
+      }
+      return topLevel;
+    }
+
+    @Advice.OnMethodExit(onThrowable = Throwable.class, suppress = Throwable.class)
+    public static void methodExit(@Advice.Enter final boolean topLevel) {
+      if (topLevel) {
+        CallDepthThreadLocalMap.reset("logger");
+      }
     }
   }
 }

instrumentation/log4j/log4j-2.0/src/main/java/io/opentelemetry/auto/instrumentation/log4j/v2_0/Log4jSpansInstrumentation.java

@@ -24,6 +24,7 @@ import static net.bytebuddy.matcher.ElementMatchers.takesArgument;
 import static net.bytebuddy.matcher.ElementMatchers.takesArguments;
 
 import com.google.auto.service.AutoService;
+import io.opentelemetry.auto.bootstrap.CallDepthThreadLocalMap;
 import io.opentelemetry.auto.tooling.Instrumenter;
 import java.util.HashMap;
 import java.util.Map;
@@ -96,12 +97,25 @@ public class Log4jSpansInstrumentation extends Instrumenter.Default {
   public static class LogAdvice {
 
     @Advice.OnMethodEnter(suppress = Throwable.class)
-    public static void methodEnter(
+    public static boolean methodEnter(
         @Advice.This final Logger logger,
         @Advice.Argument(0) final Level level,
         @Advice.Argument(4) final Message message,
         @Advice.Argument(5) final Throwable t) {
-      Log4jSpans.capture(logger, level, message, t);
+      // need to track call depth across all loggers in order to avoid double capture when one
+      // logging framework delegates to another
+      final boolean topLevel = CallDepthThreadLocalMap.incrementCallDepth("logger") == 0;
+      if (topLevel) {
+        Log4jSpans.capture(logger, level, message, t);
+      }
+      return topLevel;
+    }
+
+    @Advice.OnMethodExit(onThrowable = Throwable.class, suppress = Throwable.class)
+    public static void methodExit(@Advice.Enter final boolean topLevel) {
+      if (topLevel) {
+        CallDepthThreadLocalMap.reset("logger");
+      }
     }
   }
 }

instrumentation/logback-1.0/src/main/java/io/opentelemetry/auto/instrumentation/logback/LogbackSpansInstrumentation.java

@@ -23,6 +23,7 @@ import static net.bytebuddy.matcher.ElementMatchers.takesArguments;
 
 import ch.qos.logback.classic.spi.ILoggingEvent;
 import com.google.auto.service.AutoService;
+import io.opentelemetry.auto.bootstrap.CallDepthThreadLocalMap;
 import io.opentelemetry.auto.tooling.Instrumenter;
 import java.util.HashMap;
 import java.util.Map;
@@ -63,8 +64,21 @@ public class LogbackSpansInstrumentation extends Instrumenter.Default {
   public static class CallAppendersAdvice {
 
     @Advice.OnMethodEnter(suppress = Throwable.class)
-    public static void methodEnter(@Advice.Argument(0) final ILoggingEvent event) {
-      LogbackSpans.capture(event);
+    public static boolean methodEnter(@Advice.Argument(0) final ILoggingEvent event) {
+      // need to track call depth across all loggers in order to avoid double capture when one
+      // logging framework delegates to another
+      final boolean topLevel = CallDepthThreadLocalMap.incrementCallDepth("logger") == 0;
+      if (topLevel) {
+        LogbackSpans.capture(event);
+      }
+      return topLevel;
+    }
+
+    @Advice.OnMethodExit(onThrowable = Throwable.class, suppress = Throwable.class)
+    public static void methodExit(@Advice.Enter final boolean topLevel) {
+      if (topLevel) {
+        CallDepthThreadLocalMap.reset("logger");
+      }
     }
   }
 }