Support slf4j to log4j2
MODIFY
instrumentation/log4j/log4j-appender-2.17/javaagent/build.gradle.kts
instrumentation/log4j/log4j-appender-2.17/javaagent/build.gradle.kts
@@ -11,6 +11,8 @@ muzzle {
}
}
+val testLatestDeps = findProperty("testLatestDeps") as Boolean
+
dependencies {
library("org.apache.logging.log4j:log4j-core:2.17.0")
@@ -21,16 +23,33 @@ dependencies {
testImplementation("org.awaitility:awaitility")
+ // this dependency is needed for the slf4j->log4j test
+ if (testLatestDeps) {
+ testImplementation("org.apache.logging.log4j:log4j-slf4j2-impl:2.19.0")
+ } else {
+ // log4j 2.17 doesn't have an slf4j2 bridge
+ testImplementation("org.apache.logging.log4j:log4j-slf4j-impl:2.17.0")
+ testImplementation("org.slf4j:slf4j-api") {
+ version {
+ strictly("1.7.36")
+ }
+ }
+ }
+
// this is needed for the async logging test
testImplementation("com.lmax:disruptor:3.4.2")
}
+tasks.withType<Test>().configureEach {
+ systemProperty("testLatestDeps", testLatestDeps)
+}
+
tasks {
val testAsync by registering(Test::class) {
jvmArgs("-DLog4j2.contextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector")
}
- named<Test>("test") {
+ check {
dependsOn(testAsync)
}
}
@@ -42,3 +61,10 @@ tasks.withType<Test>().configureEach {
jvmArgs("-Dotel.instrumentation.log4j-appender.experimental-log-attributes=true")
jvmArgs("-Dotel.instrumentation.log4j-appender.experimental.capture-marker-attribute=true")
}
+
+configurations {
+ testImplementation {
+ // this is needed for the slf4j->log4j test
+ exclude("ch.qos.logback", "logback-classic")
+ }
+}

MODIFY
instrumentation/log4j/log4j-appender-2.17/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v2_17/Log4jAppenderInstrumentation.java
instrumentation/log4j/log4j-appender-2.17/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v2_17/Log4jAppenderInstrumentation.java
@@ -52,6 +52,17 @@ class Log4jAppenderInstrumentation implements TypeInstrumentation {
.and(takesArgument(4, named("org.apache.logging.log4j.message.Message")))
.and(takesArgument(5, Throwable.class)),
Log4jAppenderInstrumentation.class.getName() + "$LogAdvice");
+ transformer.applyAdviceToMethod(
+ isMethod()
+ .and(isProtected().or(isPublic()))
+ .and(named("logMessage"))
+ .and(takesArguments(5))
+ .and(takesArgument(0, String.class))
+ .and(takesArgument(1, named("org.apache.logging.log4j.Level")))
+ .and(takesArgument(2, named("org.apache.logging.log4j.Marker")))
+ .and(takesArgument(3, named("org.apache.logging.log4j.message.Message")))
+ .and(takesArgument(4, Throwable.class)),
+ Log4jAppenderInstrumentation.class.getName() + "$LogMessageAdvice");
}
@SuppressWarnings("unused")
@@ -78,4 +89,29 @@ class Log4jAppenderInstrumentation implements TypeInstrumentation {
callDepth.decrementAndGet();
}
}
+
+ @SuppressWarnings("unused")
+ public static class LogMessageAdvice {
+
+ @Advice.OnMethodEnter(suppress = Throwable.class)
+ public static void methodEnter(
+ @Advice.This Logger logger,
+ @Advice.Argument(1) Level level,
+ @Advice.Argument(2) Marker marker,
+ @Advice.Argument(3) Message message,
+ @Advice.Argument(4) Throwable t,
+ @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(LoggerProvider.class);
+ if (callDepth.getAndIncrement() == 0) {
+ Log4jHelper.capture(logger, level, marker, message, t);
+ }
+ }
+
+ @Advice.OnMethodExit(onThrowable = Throwable.class, suppress = Throwable.class)
+ public static void methodExit(@Advice.Local("otelCallDepth") CallDepth callDepth) {
+ callDepth.decrementAndGet();
+ }
+ }
}

ADD
instrumentation/log4j/log4j-appender-2.17/javaagent/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/Slf4jToLog4jTest.java
+/*
+ * Copyright The OpenTelemetry Authors
+ * SPDX-License-Identifier: Apache-2.0
+ */
+
+package io.opentelemetry.instrumentation.log4j.appender.v2_17;
+
+import static io.opentelemetry.sdk.testing.assertj.LogAssertions.assertThat;
+import static io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions.equalTo;
+import static io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions.satisfies;
+
+import io.opentelemetry.api.common.AttributeKey;
+import io.opentelemetry.api.logs.Severity;
+import io.opentelemetry.instrumentation.testing.junit.AgentInstrumentationExtension;
+import io.opentelemetry.instrumentation.testing.junit.InstrumentationExtension;
+import io.opentelemetry.sdk.common.InstrumentationScopeInfo;
+import io.opentelemetry.sdk.logs.data.LogRecordData;
+import io.opentelemetry.semconv.trace.attributes.SemanticAttributes;
+import java.util.stream.Stream;
+import org.junit.jupiter.api.Test;
+import org.junit.jupiter.api.extension.RegisterExtension;
+import org.junit.jupiter.params.ParameterizedTest;
+import org.junit.jupiter.params.provider.Arguments;
+import org.junit.jupiter.params.provider.MethodSource;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+import org.slf4j.MDC;
+import org.slf4j.Marker;
+import org.slf4j.MarkerFactory;
+
+class Slf4jToLog4jTest {
+
+ @RegisterExtension
+ static final InstrumentationExtension testing = AgentInstrumentationExtension.create();
+
+ private static final Logger logger = LoggerFactory.getLogger("abc");
+
+ private static Stream<Arguments> provideParameters() {
+ return Stream.of(
+ Arguments.of(false, false),
+ Arguments.of(false, true),
+ Arguments.of(true, false),
+ Arguments.of(true, true));
+ }
+
+ @ParameterizedTest
+ @MethodSource("provideParameters")
+ public void test(boolean logException, boolean withParent) throws InterruptedException {
+ test(Logger::debug, Logger::debug, logException, withParent, null, null, null);
+ testing.clearData();
+ test(Logger::info, Logger::info, logException, withParent, "abc", Severity.INFO, "INFO");
+ testing.clearData();
+ test(Logger::warn, Logger::warn, logException, withParent, "abc", Severity.WARN, "WARN");
+ testing.clearData();
+ test(Logger::error, Logger::error, logException, withParent, "abc", Severity.ERROR, "ERROR");
+ testing.clearData();
+ }
+
+ private static void test(
+ OneArgLoggerMethod oneArgLoggerMethod,
+ TwoArgLoggerMethod twoArgLoggerMethod,
+ boolean logException,
+ boolean withParent,
+ String expectedLoggerName,
+ Severity expectedSeverity,
+ String expectedSeverityText)
+ throws InterruptedException {
+
+ // when
+ if (withParent) {
+ testing.runWithSpan(
+ "parent", () -> performLogging(oneArgLoggerMethod, twoArgLoggerMethod, logException));
+ } else {
+ performLogging(oneArgLoggerMethod, twoArgLoggerMethod, logException);
+ }
+
+ // then
+ if (withParent) {
+ testing.waitForTraces(1);
+ }
+
+ if (expectedSeverity != null) {
+ LogRecordData log = testing.waitForLogRecords(1).get(0);
+ assertThat(log)
+ .hasBody("xyz: 123")
+ .hasInstrumentationScope(InstrumentationScopeInfo.builder(expectedLoggerName).build())
+ .hasSeverity(expectedSeverity)
+ .hasSeverityText(expectedSeverityText);
+ if (logException) {
+ assertThat(log)
+ .hasAttributesSatisfyingExactly(
+ equalTo(SemanticAttributes.THREAD_NAME, Thread.currentThread().getName()),
+ equalTo(SemanticAttributes.THREAD_ID, Thread.currentThread().getId()),
+ equalTo(SemanticAttributes.EXCEPTION_TYPE, IllegalStateException.class.getName()),
+ equalTo(SemanticAttributes.EXCEPTION_MESSAGE, "hello"),
+ satisfies(
+ SemanticAttributes.EXCEPTION_STACKTRACE,
+ v -> v.contains(Slf4jToLog4jTest.class.getName())));
+ } else {
+ assertThat(log)
+ .hasAttributesSatisfyingExactly(
+ equalTo(SemanticAttributes.THREAD_NAME, Thread.currentThread().getName()),
+ equalTo(SemanticAttributes.THREAD_ID, Thread.currentThread().getId()));
+ }
+
+ if (withParent) {
+ assertThat(log).hasSpanContext(testing.spans().get(0).getSpanContext());
+ } else {
+ assertThat(log.getSpanContext().isValid()).isFalse();
+ }
+
+ } else {
+ Thread.sleep(500); // sleep a bit just to make sure no log is captured
+ assertThat(testing.logRecords()).isEmpty();
+ }
+ }
+
+ @Test
+ void testMdc() {
+ MDC.put("key1", "val1");
+ MDC.put("key2", "val2");
+ try {
+ logger.info("xyz: {}", 123);
+ } finally {
+ MDC.clear();
+ }
+
+ LogRecordData log = testing.waitForLogRecords(1).get(0);
+ assertThat(log)
+ .hasBody("xyz: 123")
+ .hasInstrumentationScope(InstrumentationScopeInfo.builder("abc").build())
+ .hasSeverity(Severity.INFO)
+ .hasSeverityText("INFO")
+ .hasAttributesSatisfyingExactly(
+ equalTo(AttributeKey.stringKey("log4j.context_data.key1"), "val1"),
+ equalTo(AttributeKey.stringKey("log4j.context_data.key2"), "val2"),
+ equalTo(SemanticAttributes.THREAD_NAME, Thread.currentThread().getName()),
+ equalTo(SemanticAttributes.THREAD_ID, Thread.currentThread().getId()));
+ }
+
+ @Test
+ public void testMarker() {
+
+ String markerName = "aMarker";
+ Marker marker = MarkerFactory.getMarker(markerName);
+
+ logger.info(marker, "Message");
+
+ LogRecordData log = testing.waitForLogRecords(1).get(0);
+ assertThat(log)
+ .hasAttributesSatisfyingExactly(
+ equalTo(SemanticAttributes.THREAD_NAME, Thread.currentThread().getName()),
+ equalTo(SemanticAttributes.THREAD_ID, Thread.currentThread().getId()),
+ equalTo(AttributeKey.stringKey("log4j.marker"), markerName));
+ }
+
+ private static void performLogging(
+ OneArgLoggerMethod oneArgLoggerMethod,
+ TwoArgLoggerMethod twoArgLoggerMethod,
+ boolean logException) {
+ if (logException) {
+ twoArgLoggerMethod.call(logger, "xyz: {}", 123, new IllegalStateException("hello"));
+ } else {
+ oneArgLoggerMethod.call(logger, "xyz: {}", 123);
+ }
+ }
+
+ @FunctionalInterface
+ interface OneArgLoggerMethod {
+ void call(Logger logger, String msg, Object arg);
+ }
+
+ @FunctionalInterface
+ interface TwoArgLoggerMethod {
+ void call(Logger logger, String msg, Object arg1, Object arg2);
+ }
+}

MODIFY
instrumentation/logback/logback-appender-1.0/javaagent/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LogbackTest.java
instrumentation/logback/logback-appender-1.0/javaagent/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LogbackTest.java
@@ -121,9 +121,7 @@ class LogbackTest {
if (withParent) {
testing.runWithSpan(
"parent",
- () -> {
- performLogging(logger, oneArgLoggerMethod, twoArgLoggerMethod, logException);
- });
+ () -> performLogging(logger, oneArgLoggerMethod, twoArgLoggerMethod, logException));
} else {
performLogging(logger, oneArgLoggerMethod, twoArgLoggerMethod, logException);
}

MODIFY
testing-common/src/main/java/io/opentelemetry/instrumentation/testing/AgentTestRunner.java
testing-common/src/main/java/io/opentelemetry/instrumentation/testing/AgentTestRunner.java
@@ -26,8 +26,12 @@ import org.slf4j.LoggerFactory;
*/
public final class AgentTestRunner extends InstrumentationTestRunner {
static {
+ try {
LoggerUtils.setLevel(LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME), Level.WARN);
LoggerUtils.setLevel(LoggerFactory.getLogger("io.opentelemetry"), Level.DEBUG);
+ } catch (NoClassDefFoundError e) {
+ // this happens when excluding logback in order to test slf4j -> log4j2
+ }
}
private static final AgentTestRunner INSTANCE = new AgentTestRunner();

Support slf4j to log4j2 (#7656)