diff --git a/instrumentation/log4j/log4j-appender-1.2/javaagent/build.gradle.kts b/instrumentation/log4j/log4j-appender-1.2/javaagent/build.gradle.kts index 07aa11d752..a07c33a0d3 100644 --- a/instrumentation/log4j/log4j-appender-1.2/javaagent/build.gradle.kts +++ b/instrumentation/log4j/log4j-appender-1.2/javaagent/build.gradle.kts @@ -32,5 +32,6 @@ configurations { tasks.withType().configureEach { // TODO run tests both with and without experimental log attributes + jvmArgs("-Dotel.instrumentation.log4j-appender.experimental.capture-mdc-attributes=*") jvmArgs("-Dotel.instrumentation.log4j-appender.experimental-log-attributes=true") } diff --git a/instrumentation/log4j/log4j-appender-1.2/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v1_2/Log4jAppenderInstrumentation.java b/instrumentation/log4j/log4j-appender-1.2/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v1_2/Log4jAppenderInstrumentation.java index f0ec431e04..e1e9683b01 100644 --- a/instrumentation/log4j/log4j-appender-1.2/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v1_2/Log4jAppenderInstrumentation.java +++ b/instrumentation/log4j/log4j-appender-1.2/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v1_2/Log4jAppenderInstrumentation.java @@ -56,7 +56,7 @@ class Log4jAppenderInstrumentation implements TypeInstrumentation { // framework delegates to another callDepth = CallDepth.forClass(LogEmitterProvider.class); if (callDepth.getAndIncrement() == 0) { - Log4jHelper.capture(logger, level, message, t); + LogEventMapper.INSTANCE.capture(logger, level, message, t); } } diff --git a/instrumentation/log4j/log4j-appender-1.2/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v1_2/Log4jHelper.java b/instrumentation/log4j/log4j-appender-1.2/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v1_2/LogEventMapper.java similarity index 59% rename from instrumentation/log4j/log4j-appender-1.2/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v1_2/Log4jHelper.java rename to instrumentation/log4j/log4j-appender-1.2/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v1_2/LogEventMapper.java index 497530f80d..2c79220ac2 100644 --- a/instrumentation/log4j/log4j-appender-1.2/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v1_2/Log4jHelper.java +++ b/instrumentation/log4j/log4j-appender-1.2/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v1_2/LogEventMapper.java @@ -5,20 +5,33 @@ package io.opentelemetry.javaagent.instrumentation.log4j.appender.v1_2; +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.Hashtable; +import java.util.List; +import java.util.Map; +import java.util.stream.Collectors; import org.apache.log4j.Category; +import org.apache.log4j.MDC; import org.apache.log4j.Priority; -public final class Log4jHelper { +public final class LogEventMapper { + + private static final Cache> mdcAttributeKeys = Cache.bounded(100); + + public static final LogEventMapper INSTANCE = new LogEventMapper(); // copied from org.apache.log4j.Level because it was only introduced in 1.2.12 private static final int TRACE_INT = 5000; @@ -27,8 +40,25 @@ public final class Log4jHelper { Config.get() .getBoolean("otel.instrumentation.log4j-appender.experimental-log-attributes", false); - // TODO (trask) capture MDC - public static void capture(Category logger, Priority level, Object message, Throwable throwable) { + private final Map> captureMdcAttributes; + + // cached as an optimization + private final boolean captureAllMdcAttributes; + + private LogEventMapper() { + List captureMdcAttributes = + Config.get() + .getList( + "otel.instrumentation.log4j-appender.experimental.capture-mdc-attributes", + emptyList()); + this.captureMdcAttributes = + captureMdcAttributes.stream() + .collect(Collectors.toMap(attr -> attr, LogEventMapper::getMdcAttributeKey)); + this.captureAllMdcAttributes = + captureMdcAttributes.size() == 1 && captureMdcAttributes.get(0).equals("*"); + } + + public void capture(Category logger, Priority level, Object message, Throwable throwable) { String instrumentationName = logger.getName(); if (instrumentationName == null || instrumentationName.isEmpty()) { instrumentationName = "ROOT"; @@ -60,6 +90,8 @@ public final class Log4jHelper { attributes.put(SemanticAttributes.EXCEPTION_STACKTRACE, writer.toString()); } + captureMdcAttributes(attributes); + if (captureExperimentalAttributes) { Thread currentThread = Thread.currentThread(); attributes.put(SemanticAttributes.THREAD_NAME, currentThread.getName()); @@ -74,6 +106,32 @@ public final class Log4jHelper { builder.emit(); } + private void captureMdcAttributes(AttributesBuilder attributes) { + + Hashtable context = MDC.getContext(); + + if (captureAllMdcAttributes) { + if (context != null) { + for (Map.Entry entry : context.entrySet()) { + attributes.put( + getMdcAttributeKey(String.valueOf(entry.getKey())), String.valueOf(entry.getValue())); + } + } + return; + } + + for (Map.Entry> entry : captureMdcAttributes.entrySet()) { + Object value = context.get(entry.getKey()); + if (value != null) { + attributes.put(entry.getValue(), value.toString()); + } + } + } + + private static AttributeKey getMdcAttributeKey(String key) { + return mdcAttributeKeys.computeIfAbsent(key, k -> AttributeKey.stringKey("log4j.mdc." + k)); + } + private static Severity levelToSeverity(Priority level) { int lev = level.toInt(); if (lev <= TRACE_INT) { @@ -93,6 +151,4 @@ public final class Log4jHelper { } return Severity.FATAL; } - - private Log4jHelper() {} } diff --git a/instrumentation/log4j/log4j-appender-1.2/javaagent/src/test/groovy/Log4j1Test.groovy b/instrumentation/log4j/log4j-appender-1.2/javaagent/src/test/groovy/Log4j1Test.groovy index b91f050e7e..a69341bc30 100644 --- a/instrumentation/log4j/log4j-appender-1.2/javaagent/src/test/groovy/Log4j1Test.groovy +++ b/instrumentation/log4j/log4j-appender-1.2/javaagent/src/test/groovy/Log4j1Test.groovy @@ -3,10 +3,12 @@ * 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.apache.log4j.Logger +import org.apache.log4j.MDC import spock.lang.Unroll import static org.assertj.core.api.Assertions.assertThat @@ -90,4 +92,34 @@ class Log4j1Test extends AgentInstrumentationSpecification { 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("log4j.mdc.key1"))).isEqualTo("val1") + assertThat(log.getAttributes().get(AttributeKey.stringKey("log4j.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()) + } }