diff --git a/instrumentation/java-util-logging/javaagent/build.gradle.kts b/instrumentation/java-util-logging/javaagent/build.gradle.kts index 165f30bd164d..20df245972a7 100644 --- a/instrumentation/java-util-logging/javaagent/build.gradle.kts +++ b/instrumentation/java-util-logging/javaagent/build.gradle.kts @@ -7,6 +7,9 @@ dependencies { compileOnly(project(":instrumentation-appender-api-internal")) + // ensure no cross interference + testInstrumentation(project(":instrumentation:jboss-logmanager-1.1:javaagent")) + testImplementation("org.awaitility:awaitility") } diff --git a/instrumentation/java-util-logging/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/jul/JavaUtilLoggingInstrumentation.java b/instrumentation/java-util-logging/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/jul/JavaUtilLoggingInstrumentation.java index 1eff30eb294c..a8cc53cc41fa 100644 --- a/instrumentation/java-util-logging/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/jul/JavaUtilLoggingInstrumentation.java +++ b/instrumentation/java-util-logging/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/jul/JavaUtilLoggingInstrumentation.java @@ -38,13 +38,6 @@ public void transform(TypeTransformer transformer) { .and(takesArguments(1)) .and(takesArgument(0, named("java.util.logging.LogRecord"))), JavaUtilLoggingInstrumentation.class.getName() + "$LogAdvice"); - transformer.applyAdviceToMethod( - isMethod() - .and(isPublic()) - .and(named("logRaw")) - .and(takesArguments(1)) - .and(takesArgument(0, named("org.jboss.logmanager.ExtLogRecord"))), - JavaUtilLoggingInstrumentation.class.getName() + "$LogAdvice"); } @SuppressWarnings("unused") diff --git a/instrumentation/java-util-logging/javaagent/src/test/groovy/JavaUtilLoggingTest.groovy b/instrumentation/java-util-logging/javaagent/src/test/groovy/JavaUtilLoggingTest.groovy index 7e3b8aded5a2..204369526282 100644 --- a/instrumentation/java-util-logging/javaagent/src/test/groovy/JavaUtilLoggingTest.groovy +++ b/instrumentation/java-util-logging/javaagent/src/test/groovy/JavaUtilLoggingTest.groovy @@ -6,7 +6,6 @@ import io.opentelemetry.instrumentation.test.AgentInstrumentationSpecification import io.opentelemetry.sdk.logs.data.Severity import io.opentelemetry.semconv.trace.attributes.SemanticAttributes -import spock.lang.Shared import spock.lang.Unroll import java.util.logging.Level @@ -17,12 +16,7 @@ import static org.awaitility.Awaitility.await class JavaUtilLoggingTest extends AgentInstrumentationSpecification { - @Shared - private final Object logger = createLogger("abc") - - Object createLogger(String name) { - Logger.getLogger(name) - } + private static final Logger logger = Logger.getLogger("abc") @Unroll def "test method=#testMethod with testArgs=#testArgs and parent=#parent"() { diff --git a/instrumentation/java-util-logging/jboss-testing/build.gradle.kts b/instrumentation/java-util-logging/jboss-testing/build.gradle.kts deleted file mode 100644 index d68113e50c41..000000000000 --- a/instrumentation/java-util-logging/jboss-testing/build.gradle.kts +++ /dev/null @@ -1,25 +0,0 @@ -plugins { - id("otel.javaagent-testing") -} - -// separate testing module is needed, because presence of jboss-logmanager 2.1.6 or later -// on the classpath causes the normal java.util.logging test to use it - -dependencies { - compileOnly(project(":instrumentation:java-util-logging:shaded-stub-for-instrumenting")) - - compileOnly(project(":instrumentation-appender-api-internal")) - - testInstrumentation(project(":instrumentation:java-util-logging:javaagent")) - - // the JBoss instrumentation in this artifact is needed - // for jboss-logmanager versions 1.1.0.GA through latest 2.x - testLibrary("org.jboss.logmanager:jboss-logmanager:1.1.0.GA") - - testImplementation("org.awaitility:awaitility") -} - -tasks.withType().configureEach { - // TODO run tests both with and without experimental log attributes - jvmArgs("-Dotel.instrumentation.java-util-logging.experimental-log-attributes=true") -} diff --git a/instrumentation/jboss-logmanager-1.1/javaagent/build.gradle.kts b/instrumentation/jboss-logmanager-1.1/javaagent/build.gradle.kts new file mode 100644 index 000000000000..e64168a1527f --- /dev/null +++ b/instrumentation/jboss-logmanager-1.1/javaagent/build.gradle.kts @@ -0,0 +1,29 @@ +plugins { + id("otel.javaagent-instrumentation") +} + +muzzle { + pass { + group.set("org.jboss.logmanager") + module.set("jboss-logmanager") + versions.set("[1.1.0.GA,)") + assertInverse.set(true) + } +} + +dependencies { + library("org.jboss.logmanager:jboss-logmanager:1.1.0.GA") + + compileOnly(project(":instrumentation-appender-api-internal")) + + // ensure no cross interference + testInstrumentation(project(":instrumentation:java-util-logging:javaagent")) + + testImplementation("org.awaitility:awaitility") +} + +tasks.withType().configureEach { + // TODO run tests both with and without experimental log attributes + jvmArgs("-Dotel.instrumentation.jboss-logmanager.experimental.capture-mdc-attributes=*") + jvmArgs("-Dotel.instrumentation.jboss-logmanager.experimental-log-attributes=true") +} diff --git a/instrumentation/jboss-logmanager-1.1/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/jbosslogmanager/v1_1/JbossLogmanagerInstrumentation.java b/instrumentation/jboss-logmanager-1.1/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/jbosslogmanager/v1_1/JbossLogmanagerInstrumentation.java new file mode 100644 index 000000000000..5ecab05d43c9 --- /dev/null +++ b/instrumentation/jboss-logmanager-1.1/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/jbosslogmanager/v1_1/JbossLogmanagerInstrumentation.java @@ -0,0 +1,61 @@ +/* + * Copyright The OpenTelemetry Authors + * SPDX-License-Identifier: Apache-2.0 + */ + +package io.opentelemetry.javaagent.instrumentation.jbosslogmanager.v1_1; + +import static net.bytebuddy.matcher.ElementMatchers.isMethod; +import static net.bytebuddy.matcher.ElementMatchers.isPublic; +import static net.bytebuddy.matcher.ElementMatchers.named; +import static net.bytebuddy.matcher.ElementMatchers.takesArgument; +import static net.bytebuddy.matcher.ElementMatchers.takesArguments; + +import io.opentelemetry.instrumentation.api.appender.internal.LogEmitterProvider; +import io.opentelemetry.javaagent.extension.instrumentation.TypeInstrumentation; +import io.opentelemetry.javaagent.extension.instrumentation.TypeTransformer; +import io.opentelemetry.javaagent.instrumentation.api.CallDepth; +import net.bytebuddy.asm.Advice; +import net.bytebuddy.description.type.TypeDescription; +import net.bytebuddy.matcher.ElementMatcher; +import org.jboss.logmanager.ExtLogRecord; +import org.jboss.logmanager.Logger; + +public class JbossLogmanagerInstrumentation implements TypeInstrumentation { + @Override + public ElementMatcher typeMatcher() { + return named("org.jboss.logmanager.Logger"); + } + + @Override + public void transform(TypeTransformer transformer) { + transformer.applyAdviceToMethod( + isMethod() + .and(isPublic()) + .and(named("logRaw")) + .and(takesArguments(1)) + .and(takesArgument(0, named("org.jboss.logmanager.ExtLogRecord"))), + JbossLogmanagerInstrumentation.class.getName() + "$CallLogRawAdvice"); + } + + @SuppressWarnings("unused") + public static class CallLogRawAdvice { + @Advice.OnMethodEnter(suppress = Throwable.class) + public static void methodEnter( + @Advice.This() Logger logger, + @Advice.Argument(0) ExtLogRecord record, + @Advice.Local("otelCallDepth") CallDepth callDepth) { + // need to track call depth across all loggers in order to avoid double capture when one + // logging framework delegates to another + callDepth = CallDepth.forClass(LogEmitterProvider.class); + if (callDepth.getAndIncrement() == 0) { + LoggingEventMapper.INSTANCE.capture(logger, record); + } + } + + @Advice.OnMethodExit(onThrowable = Throwable.class, suppress = Throwable.class) + public static void methodExit(@Advice.Local("otelCallDepth") CallDepth callDepth) { + callDepth.decrementAndGet(); + } + } +} diff --git a/instrumentation/jboss-logmanager-1.1/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/jbosslogmanager/v1_1/JbossLogmanagerInstrumentationModule.java b/instrumentation/jboss-logmanager-1.1/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/jbosslogmanager/v1_1/JbossLogmanagerInstrumentationModule.java new file mode 100644 index 000000000000..2957591d46ed --- /dev/null +++ b/instrumentation/jboss-logmanager-1.1/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/jbosslogmanager/v1_1/JbossLogmanagerInstrumentationModule.java @@ -0,0 +1,26 @@ +/* + * Copyright The OpenTelemetry Authors + * SPDX-License-Identifier: Apache-2.0 + */ + +package io.opentelemetry.javaagent.instrumentation.jbosslogmanager.v1_1; + +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 java.util.List; + +@AutoService(InstrumentationModule.class) +public class JbossLogmanagerInstrumentationModule extends InstrumentationModule { + + public JbossLogmanagerInstrumentationModule() { + super("jboss-logmanager", "jboss-logmanager-1.1"); + } + + @Override + public List typeInstrumentations() { + return singletonList(new JbossLogmanagerInstrumentation()); + } +} diff --git a/instrumentation/jboss-logmanager-1.1/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/jbosslogmanager/v1_1/LoggingEventMapper.java b/instrumentation/jboss-logmanager-1.1/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/jbosslogmanager/v1_1/LoggingEventMapper.java new file mode 100644 index 000000000000..53b32a65553a --- /dev/null +++ b/instrumentation/jboss-logmanager-1.1/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/jbosslogmanager/v1_1/LoggingEventMapper.java @@ -0,0 +1,145 @@ +/* + * Copyright The OpenTelemetry Authors + * SPDX-License-Identifier: Apache-2.0 + */ + +package io.opentelemetry.javaagent.instrumentation.jbosslogmanager.v1_1; + +import static java.util.Collections.emptyList; + +import io.opentelemetry.api.common.AttributeKey; +import io.opentelemetry.api.common.Attributes; +import io.opentelemetry.api.common.AttributesBuilder; +import io.opentelemetry.context.Context; +import io.opentelemetry.instrumentation.api.appender.internal.LogBuilder; +import io.opentelemetry.instrumentation.api.appender.internal.Severity; +import io.opentelemetry.instrumentation.api.cache.Cache; +import io.opentelemetry.instrumentation.api.config.Config; +import io.opentelemetry.javaagent.instrumentation.api.appender.internal.AgentLogEmitterProvider; +import io.opentelemetry.semconv.trace.attributes.SemanticAttributes; +import java.io.PrintWriter; +import java.io.StringWriter; +import java.util.List; +import java.util.Map; +import org.jboss.logmanager.ExtLogRecord; +import org.jboss.logmanager.Level; +import org.jboss.logmanager.Logger; +import org.jboss.logmanager.MDC; + +public final class LoggingEventMapper { + + public static final LoggingEventMapper INSTANCE = new LoggingEventMapper(); + + private static final Cache> mdcAttributeKeys = Cache.bounded(100); + + private final List captureMdcAttributes; + + private static final boolean captureExperimentalAttributes = + Config.get() + .getBoolean("otel.instrumentation.jboss-logmanager.experimental-log-attributes", false); + + // cached as an optimization + private final boolean captureAllMdcAttributes; + + private LoggingEventMapper() { + this.captureMdcAttributes = + Config.get() + .getList( + "otel.instrumentation.jboss-logmanager.experimental.capture-mdc-attributes", + emptyList()); + this.captureAllMdcAttributes = + captureMdcAttributes.size() == 1 && captureMdcAttributes.get(0).equals("*"); + } + + public void capture(Logger logger, ExtLogRecord record) { + String instrumentationName = logger.getName(); + if (instrumentationName == null || instrumentationName.isEmpty()) { + instrumentationName = "ROOT"; + } + + LogBuilder builder = + AgentLogEmitterProvider.get().logEmitterBuilder(instrumentationName).build().logBuilder(); + + String message = record.getFormattedMessage(); + if (message != null) { + builder.setBody(message); + } + + java.util.logging.Level level = record.getLevel(); + if (level != null) { + builder.setSeverity(levelToSeverity(level)); + builder.setSeverityText(level.toString()); + } + + AttributesBuilder attributes = Attributes.builder(); + + Throwable throwable = record.getThrown(); + if (throwable != null) { + // TODO (trask) extract method for recording exception into + // instrumentation-appender-api-internal + attributes.put(SemanticAttributes.EXCEPTION_TYPE, throwable.getClass().getName()); + attributes.put(SemanticAttributes.EXCEPTION_MESSAGE, throwable.getMessage()); + StringWriter writer = new StringWriter(); + throwable.printStackTrace(new PrintWriter(writer)); + attributes.put(SemanticAttributes.EXCEPTION_STACKTRACE, writer.toString()); + } + captureMdcAttributes(attributes); + + if (captureExperimentalAttributes) { + Thread currentThread = Thread.currentThread(); + attributes.put(SemanticAttributes.THREAD_NAME, currentThread.getName()); + attributes.put(SemanticAttributes.THREAD_ID, currentThread.getId()); + } + + builder.setAttributes(attributes.build()); + + builder.setContext(Context.current()); + + builder.emit(); + } + + private void captureMdcAttributes(AttributesBuilder attributes) { + + Map context = MDC.copy(); + + if (captureAllMdcAttributes) { + if (context != null) { + for (Map.Entry entry : context.entrySet()) { + attributes.put( + getMdcAttributeKey(String.valueOf(entry.getKey())), String.valueOf(entry.getValue())); + } + } + return; + } + + for (String key : captureMdcAttributes) { + Object value = context.get(key); + if (value != null) { + attributes.put(key, value.toString()); + } + } + } + + public static AttributeKey getMdcAttributeKey(String key) { + return mdcAttributeKeys.computeIfAbsent( + key, k -> AttributeKey.stringKey("jboss-logmanager.mdc." + k)); + } + + private static Severity levelToSeverity(java.util.logging.Level level) { + int levelInt = level.intValue(); + if (levelInt >= Level.FATAL.intValue()) { + return Severity.FATAL; + } else if (levelInt >= Level.ERROR.intValue()) { + return Severity.ERROR; + } else if (levelInt >= Level.WARNING.intValue()) { + return Severity.WARN; + } else if (levelInt >= Level.INFO.intValue()) { + return Severity.INFO; + } else if (levelInt >= Level.DEBUG.intValue()) { + return Severity.DEBUG; + } else if (levelInt >= Level.TRACE.intValue()) { + return Severity.TRACE; + } + return Severity.UNDEFINED_SEVERITY_NUMBER; + } +} diff --git a/instrumentation/java-util-logging/jboss-testing/src/test/groovy/JavaUtilLoggingJBossTest.groovy b/instrumentation/jboss-logmanager-1.1/javaagent/src/test/groovy/JbossLogmanagerTest.groovy similarity index 50% rename from instrumentation/java-util-logging/jboss-testing/src/test/groovy/JavaUtilLoggingJBossTest.groovy rename to instrumentation/jboss-logmanager-1.1/javaagent/src/test/groovy/JbossLogmanagerTest.groovy index e2c5096ec7ff..0ca969086a2d 100644 --- a/instrumentation/java-util-logging/jboss-testing/src/test/groovy/JavaUtilLoggingJBossTest.groovy +++ b/instrumentation/jboss-logmanager-1.1/javaagent/src/test/groovy/JbossLogmanagerTest.groovy @@ -3,43 +3,41 @@ * SPDX-License-Identifier: Apache-2.0 */ +import io.opentelemetry.api.common.AttributeKey import io.opentelemetry.instrumentation.test.AgentInstrumentationSpecification import io.opentelemetry.sdk.logs.data.Severity import io.opentelemetry.semconv.trace.attributes.SemanticAttributes +import org.jboss.logmanager.MDC +import org.jboss.logmanager.Level import org.jboss.logmanager.LogContext -import spock.lang.Shared import spock.lang.Unroll - -import java.util.logging.Level +import org.jboss.logmanager.Logger import static org.assertj.core.api.Assertions.assertThat import static org.awaitility.Awaitility.await -class JavaUtilLoggingJBossTest extends AgentInstrumentationSpecification { - - @Shared - private final Object logger = LogContext.create().getLogger("abc") +class JbossLogmanagerTest extends AgentInstrumentationSpecification { + private static final Logger logger = LogContext.getLogContext().getLogger("abc") + static { + logger.setLevel(Level.INFO) + } @Unroll - def "test method=#testMethod with testArgs=#testArgs and parent=#parent"() { + def "test testMethod=#testMethod, exception=#exception, parent=#parent"(Level testMethod, boolean exception, boolean parent) { when: if (parent) { runWithSpan("parent") { - if (testArgs == "exception") { - logger.log(Level."${testMethod.toUpperCase()}", "xyz", new IllegalStateException("hello")) - } else if (testArgs == "params") { - logger.log(Level."${testMethod.toUpperCase()}", "xyz: {0}", 123) + if (exception) { + logger.log(testMethod, "xyz", new IllegalStateException("hello")) } else { - logger."$testMethod"("xyz") + logger.log(testMethod, "xyz") } } } else { - if (testArgs == "exception") { - logger.log(Level."${testMethod.toUpperCase()}", "xyz", new IllegalStateException("hello")) - } else if (testArgs == "params") { - logger.log(Level."${testMethod.toUpperCase()}", "xyz: {0}", 123) + if (exception) { + logger.log(testMethod, "xyz", new IllegalStateException("hello")) } else { - logger."$testMethod"("xyz") + logger.log(testMethod, "xyz") } } @@ -55,19 +53,15 @@ class JavaUtilLoggingJBossTest extends AgentInstrumentationSpecification { assertThat(logs).hasSize(1) }) def log = logs.get(0) - if (testArgs == "params") { - assertThat(log.getBody().asString()).isEqualTo("xyz: 123") - } else { - assertThat(log.getBody().asString()).isEqualTo("xyz") - } + assertThat(log.getBody().asString()).isEqualTo("xyz") assertThat(log.getInstrumentationLibraryInfo().getName()).isEqualTo("abc") assertThat(log.getSeverity()).isEqualTo(severity) assertThat(log.getSeverityText()).isEqualTo(severityText) - if (testArgs == "exception") { + if (exception) { assertThat(log.getAttributes().size()).isEqualTo(5) assertThat(log.getAttributes().get(SemanticAttributes.EXCEPTION_TYPE)).isEqualTo(IllegalStateException.getName()) assertThat(log.getAttributes().get(SemanticAttributes.EXCEPTION_MESSAGE)).isEqualTo("hello") - assertThat(log.getAttributes().get(SemanticAttributes.EXCEPTION_STACKTRACE)).contains(JavaUtilLoggingJBossTest.name) + assertThat(log.getAttributes().get(SemanticAttributes.EXCEPTION_STACKTRACE)).contains(JbossLogmanagerTest.name) } else { assertThat(log.getAttributes().size()).isEqualTo(2) assertThat(log.getAttributes().get(SemanticAttributes.EXCEPTION_TYPE)).isNull() @@ -83,23 +77,53 @@ class JavaUtilLoggingJBossTest extends AgentInstrumentationSpecification { } } else { Thread.sleep(500) // sleep a bit just to make sure no log is captured - logs.size() == 0 + assertThat(logs.size() == 0).isTrue() } where: - [args, testArgs, parent] << [ + [args, exception, parent] << [ [ - ["fine", null, null], - ["info", Severity.INFO, "INFO"], - ["warning", Severity.WARN, "WARNING"], - ["severe", Severity.ERROR, "SEVERE"] + [Level.DEBUG, null, null], + [Level.INFO, Severity.INFO, "INFO"], + [Level.WARN, Severity.WARN, "WARN"], + [Level.ERROR, Severity.ERROR, "ERROR"] ], - ["none", "exception", "param"], + [true, false], [true, false] ].combinations() - testMethod = args[0] + testMethod = args[0] as Level severity = args[1] severityText = args[2] } + + def "test mdc"() { + when: + MDC.put("key1", "val1") + MDC.put("key2", "val2") + try { + logger.info("xyz") + } finally { + MDC.remove("key1") + MDC.remove("key2") + } + + then: + + await() + .untilAsserted( + () -> { + assertThat(logs).hasSize(1) + }) + def log = logs.get(0) + assertThat(log.getBody().asString()).isEqualTo("xyz") + assertThat(log.getInstrumentationLibraryInfo().getName()).isEqualTo("abc") + assertThat(log.getSeverity()).isEqualTo(Severity.INFO) + assertThat(log.getSeverityText()).isEqualTo("INFO") + assertThat(log.getAttributes().size()).isEqualTo(4) + assertThat(log.getAttributes().get(AttributeKey.stringKey("jboss-logmanager.mdc.key1"))).isEqualTo("val1") + assertThat(log.getAttributes().get(AttributeKey.stringKey("jboss-logmanager.mdc.key2"))).isEqualTo("val2") + assertThat(log.getAttributes().get(SemanticAttributes.THREAD_NAME)).isEqualTo(Thread.currentThread().getName()) + assertThat(log.getAttributes().get(SemanticAttributes.THREAD_ID)).isEqualTo(Thread.currentThread().getId()) + } } diff --git a/settings.gradle.kts b/settings.gradle.kts index b9350f181941..2bc64750b526 100644 --- a/settings.gradle.kts +++ b/settings.gradle.kts @@ -214,7 +214,6 @@ include(":instrumentation:http-url-connection:javaagent") include(":instrumentation:hystrix-1.4:javaagent") include(":instrumentation:java-http-client:javaagent") include(":instrumentation:java-util-logging:javaagent") -include(":instrumentation:java-util-logging:jboss-testing") include(":instrumentation:java-util-logging:shaded-stub-for-instrumenting") include(":instrumentation:jaxrs:jaxrs-common:bootstrap") include(":instrumentation:jaxrs:jaxrs-1.0:javaagent") @@ -242,6 +241,7 @@ include(":instrumentation:jaxws:jaxws-2.0-tomee-testing") include(":instrumentation:jaxws:jaxws-2.0-wildfly-testing") include(":instrumentation:jaxws:jaxws-common:library") include(":instrumentation:jaxws:jaxws-jws-api-1.1:javaagent") +include(":instrumentation:jboss-logmanager-1.1:javaagent") include(":instrumentation:jdbc:javaagent") include(":instrumentation:jdbc:library") include(":instrumentation:jdbc:testing")