From 5c4dc47710e588e3ad99058a201c73b684cb2068 Mon Sep 17 00:00:00 2001 From: Trask Stalnaker Date: Tue, 10 Mar 2020 17:14:44 -0700 Subject: [PATCH] Add JBoss logging support (#222) --- .../java-util-logging.gradle | 21 ++++++++++++ .../JavaUtilLoggingSpansInstrumentation.java | 29 +++++++++++++--- .../JBossJavaUtilLoggingEventTest.groovy | 33 +++++++++++++++++++ .../log4j/v1_1/Log4jSpansInstrumentation.java | 18 ++++++++-- .../log4j/v2_0/Log4jSpansInstrumentation.java | 18 ++++++++-- .../logback/LogbackSpansInstrumentation.java | 18 ++++++++-- 6 files changed, 127 insertions(+), 10 deletions(-) create mode 100644 instrumentation/java-util-logging/src/test/groovy/JBossJavaUtilLoggingEventTest.groovy diff --git a/instrumentation/java-util-logging/java-util-logging.gradle b/instrumentation/java-util-logging/java-util-logging.gradle index cea0b75744..3510b3cbfa 100644 --- a/instrumentation/java-util-logging/java-util-logging.gradle +++ b/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:+' +} diff --git a/instrumentation/java-util-logging/src/main/java/io/opentelemetry/auto/instrumentation/jul/JavaUtilLoggingSpansInstrumentation.java b/instrumentation/java-util-logging/src/main/java/io/opentelemetry/auto/instrumentation/jul/JavaUtilLoggingSpansInstrumentation.java index 77b9b35866..73a4ad6022 100644 --- a/instrumentation/java-util-logging/src/main/java/io/opentelemetry/auto/instrumentation/jul/JavaUtilLoggingSpansInstrumentation.java +++ b/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"); + } } } } diff --git a/instrumentation/java-util-logging/src/test/groovy/JBossJavaUtilLoggingEventTest.groovy b/instrumentation/java-util-logging/src/test/groovy/JBossJavaUtilLoggingEventTest.groovy new file mode 100644 index 0000000000..63560b8096 --- /dev/null +++ b/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" + } +} diff --git a/instrumentation/log4j/log4j-1.1/src/main/java/io/opentelemetry/auto/instrumentation/log4j/v1_1/Log4jSpansInstrumentation.java b/instrumentation/log4j/log4j-1.1/src/main/java/io/opentelemetry/auto/instrumentation/log4j/v1_1/Log4jSpansInstrumentation.java index b8e352370a..17c85c78e8 100644 --- a/instrumentation/log4j/log4j-1.1/src/main/java/io/opentelemetry/auto/instrumentation/log4j/v1_1/Log4jSpansInstrumentation.java +++ b/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"); + } } } } diff --git a/instrumentation/log4j/log4j-2.0/src/main/java/io/opentelemetry/auto/instrumentation/log4j/v2_0/Log4jSpansInstrumentation.java b/instrumentation/log4j/log4j-2.0/src/main/java/io/opentelemetry/auto/instrumentation/log4j/v2_0/Log4jSpansInstrumentation.java index ff051ca82b..5608a3b765 100644 --- a/instrumentation/log4j/log4j-2.0/src/main/java/io/opentelemetry/auto/instrumentation/log4j/v2_0/Log4jSpansInstrumentation.java +++ b/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"); + } } } } diff --git a/instrumentation/logback-1.0/src/main/java/io/opentelemetry/auto/instrumentation/logback/LogbackSpansInstrumentation.java b/instrumentation/logback-1.0/src/main/java/io/opentelemetry/auto/instrumentation/logback/LogbackSpansInstrumentation.java index 92cb63b1c3..1e19f953c2 100644 --- a/instrumentation/logback-1.0/src/main/java/io/opentelemetry/auto/instrumentation/logback/LogbackSpansInstrumentation.java +++ b/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"); + } } } }