Implement MDC auto-instrumentation for log4j1
ADD
instrumentation/log4j/log4j-1.2/log4j-1.2.gradle
+apply from: "$rootDir/gradle/instrumentation.gradle"
+
+muzzle {
+ pass {
+ group = "log4j"
+ module = "log4j"
+ versions = "[1.2,)"
+ }
+}
+
+dependencies {
+ // 1.2 introduces MDC and there's no version earlier than 1.2.4 available
+ library group: 'log4j', name: 'log4j', version: '1.2.4'
+}
+
+configurations {
+ // In order to test the real log4j library we need to remove the log4j transitive
+ // dependency 'log4j-over-slf4j' brought in by :testing-common which would shadow
+ // the log4j module under test using a proxy to slf4j instead.
+ testImplementation.exclude group: 'org.slf4j', module: 'log4j-over-slf4j'
+
+ // See: https://stackoverflow.com/a/9047963/2749853
+ testImplementation.exclude group: 'javax.jms', module: 'jms'
+}
\ No newline at end of file

ADD
instrumentation/log4j/log4j-1.2/src/main/java/io/opentelemetry/instrumentation/auto/log4j/v1_2/Log4j1Instrumentation.java
+/*
+ * Copyright The 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.
+ */
+
+package io.opentelemetry.instrumentation.auto.log4j.v1_2;
+
+import static java.util.Collections.singletonMap;
+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 com.google.auto.service.AutoService;
+import io.opentelemetry.instrumentation.auto.api.InstrumentationContext;
+import io.opentelemetry.javaagent.tooling.Instrumenter;
+import io.opentelemetry.trace.Span;
+import io.opentelemetry.trace.TracingContextUtils;
+import java.util.Map;
+import net.bytebuddy.asm.Advice;
+import net.bytebuddy.description.method.MethodDescription;
+import net.bytebuddy.description.type.TypeDescription;
+import net.bytebuddy.matcher.ElementMatcher;
+import org.apache.log4j.spi.LoggingEvent;
+
+@AutoService(Instrumenter.class)
+public class Log4j1Instrumentation extends Instrumenter.Default {
+ public Log4j1Instrumentation() {
+ super("log4j1", "log4j");
+ }
+
+ @Override
+ public ElementMatcher<? super TypeDescription> typeMatcher() {
+ return named("org.apache.log4j.Category");
+ }
+
+ @Override
+ public Map<String, String> contextStore() {
+ return singletonMap("org.apache.log4j.spi.LoggingEvent", Span.class.getName());
+ }
+
+ @Override
+ public Map<? extends ElementMatcher<? super MethodDescription>, String> transformers() {
+ return singletonMap(
+ isMethod()
+ .and(isPublic())
+ .and(named("callAppenders"))
+ .and(takesArguments(1))
+ .and(takesArgument(0, named("org.apache.log4j.spi.LoggingEvent"))),
+ Log4j1Instrumentation.class.getName() + "$CallAppendersAdvice");
+ }
+
+ public static class CallAppendersAdvice {
+ @Advice.OnMethodEnter(suppress = Throwable.class)
+ public static void onEnter(@Advice.Argument(0) LoggingEvent event) {
+ InstrumentationContext.get(LoggingEvent.class, Span.class)
+ .put(event, TracingContextUtils.getCurrentSpan());
+ }
+ }
+}

ADD
instrumentation/log4j/log4j-1.2/src/main/java/io/opentelemetry/instrumentation/auto/log4j/v1_2/Log4j1LoggingEventInstrumentation.java
+/*
+ * Copyright The 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.
+ */
+
+package io.opentelemetry.instrumentation.auto.log4j.v1_2;
+
+import static java.util.Collections.singletonMap;
+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 com.google.auto.service.AutoService;
+import io.opentelemetry.instrumentation.auto.api.InstrumentationContext;
+import io.opentelemetry.javaagent.tooling.Instrumenter;
+import io.opentelemetry.trace.Span;
+import io.opentelemetry.trace.SpanContext;
+import java.util.HashMap;
+import java.util.Hashtable;
+import java.util.Map;
+import net.bytebuddy.asm.Advice;
+import net.bytebuddy.description.method.MethodDescription;
+import net.bytebuddy.description.type.TypeDescription;
+import net.bytebuddy.matcher.ElementMatcher;
+import org.apache.log4j.MDC;
+import org.apache.log4j.spi.LoggingEvent;
+
+@AutoService(Instrumenter.class)
+public class Log4j1LoggingEventInstrumentation extends Instrumenter.Default {
+ public Log4j1LoggingEventInstrumentation() {
+ super("log4j1", "log4j");
+ }
+
+ @Override
+ public ElementMatcher<? super TypeDescription> typeMatcher() {
+ return named("org.apache.log4j.spi.LoggingEvent");
+ }
+
+ @Override
+ public Map<String, String> contextStore() {
+ return singletonMap("org.apache.log4j.spi.LoggingEvent", Span.class.getName());
+ }
+
+ @Override
+ public Map<? extends ElementMatcher<? super MethodDescription>, String> transformers() {
+ Map<ElementMatcher.Junction<MethodDescription>, String> transformers = new HashMap<>();
+
+ transformers.put(
+ isMethod()
+ .and(isPublic())
+ .and(named("getMDC"))
+ .and(takesArguments(1))
+ .and(takesArgument(0, String.class)),
+ Log4j1LoggingEventInstrumentation.class.getName() + "$GetMdcAdvice");
+
+ transformers.put(
+ isMethod().and(isPublic()).and(named("getMDCCopy")).and(takesArguments(0)),
+ Log4j1LoggingEventInstrumentation.class.getName() + "$GetMdcCopyAdvice");
+
+ return transformers;
+ }
+
+ public static class GetMdcAdvice {
+ @Advice.OnMethodExit(suppress = Throwable.class)
+ public static void onExit(
+ @Advice.This LoggingEvent event,
+ @Advice.Argument(0) String key,
+ @Advice.Return(readOnly = false) Object value) {
+ if ("traceId".equals(key) || "spanId".equals(key) || "sampled".equals(key)) {
+ if (value != null) {
+ // Assume already instrumented event if traceId/spanId/sampled is present.
+ return;
+ }
+
+ Span span = InstrumentationContext.get(LoggingEvent.class, Span.class).get(event);
+ if (span == null || !span.getContext().isValid()) {
+ return;
+ }
+
+ SpanContext spanContext = span.getContext();
+ switch (key) {
+ case "traceId":
+ value = spanContext.getTraceIdAsHexString();
+ break;
+ case "spanId":
+ value = spanContext.getSpanIdAsHexString();
+ break;
+ case "sampled":
+ if (spanContext.isSampled()) {
+ value = "true";
+ }
+ break;
+ }
+ }
+ }
+ }
+
+ public static class GetMdcCopyAdvice {
+ @SuppressWarnings({"unchecked", "rawtypes"})
+ @Advice.OnMethodEnter(suppress = Throwable.class)
+ public static void onEnter(
+ @Advice.This LoggingEvent event,
+ @Advice.FieldValue(value = "mdcCopyLookupRequired", readOnly = false) boolean copyRequired,
+ @Advice.FieldValue(value = "mdcCopy", readOnly = false) Hashtable mdcCopy) {
+ // this advice basically replaces the original method
+
+ if (copyRequired) {
+ copyRequired = false;
+
+ Hashtable mdc = new Hashtable();
+
+ Hashtable originalMdc = MDC.getContext();
+ if (originalMdc != null) {
+ mdc.putAll(originalMdc);
+ }
+
+ // Assume already instrumented event if traceId is present.
+ if (!mdc.contains("traceId")) {
+ Span span = InstrumentationContext.get(LoggingEvent.class, Span.class).get(event);
+ if (span != null && span.getContext().isValid()) {
+ SpanContext spanContext = span.getContext();
+ mdc.put("traceId", spanContext.getTraceIdAsHexString());
+ mdc.put("spanId", spanContext.getSpanIdAsHexString());
+ if (spanContext.isSampled()) {
+ mdc.put("sampled", "true");
+ }
+ }
+ }
+
+ mdcCopy = mdc;
+ }
+ }
+ }
+}

ADD
instrumentation/log4j/log4j-1.2/src/test/groovy/ListAppender.groovy
+/*
+ * Copyright The 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 org.apache.log4j.AppenderSkeleton
+import org.apache.log4j.spi.LoggingEvent
+
+class ListAppender extends AppenderSkeleton {
+ static events = new ArrayList<LoggingEvent>()
+
+ @Override
+ protected void append(LoggingEvent loggingEvent) {
+ events.add(loggingEvent)
+ }
+
+ @Override
+ boolean requiresLayout() {
+ return false
+ }
+
+ @Override
+ void close() {
+ }
+
+ static clearEvents() {
+ events.clear()
+ }
+}

ADD
instrumentation/log4j/log4j-1.2/src/test/groovy/Log4j1MdcTest.groovy
+/*
+ * Copyright The 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.AgentTestRunner
+import io.opentelemetry.auto.test.utils.TraceUtils
+import io.opentelemetry.trace.TracingContextUtils
+import org.apache.log4j.LogManager
+
+class Log4j1MdcTest extends AgentTestRunner {
+ def cleanup() {
+ ListAppender.clearEvents()
+ }
+
+ def "no ids when no span"() {
+ given:
+ def logger = LogManager.getLogger('TestLogger')
+
+ when:
+ logger.info("log message 1")
+ logger.info("log message 2")
+
+ then:
+ def events = ListAppender.events
+
+ events.size() == 2
+ events[0].message == "log message 1"
+ events[0].getMDC("traceId") == null
+ events[0].getMDC("spanId") == null
+ events[0].getMDC("traceFlags") == null
+
+ events[1].message == "log message 2"
+ events[1].getMDC("traceId") == null
+ events[1].getMDC("spanId") == null
+ events[1].getMDC("traceFlags") == null
+ }
+
+ def "ids when span"() {
+ given:
+ def logger = LogManager.getLogger('TestLogger')
+
+ when:
+ def span1 = TraceUtils.runUnderTrace("test") {
+ logger.info("log message 1")
+ TracingContextUtils.currentSpan
+ }
+
+ logger.info("log message 2")
+
+ def span2 = TraceUtils.runUnderTrace("test 2") {
+ logger.info("log message 3")
+ TracingContextUtils.currentSpan
+ }
+
+ then:
+ def events = ListAppender.events
+
+ events.size() == 3
+ events[0].message == "log message 1"
+ events[0].getMDC("traceId") == span1.context.traceIdAsHexString
+ events[0].getMDC("spanId") == span1.context.spanIdAsHexString
+ events[0].getMDC("sampled") == "true"
+
+ events[1].message == "log message 2"
+ events[1].getMDC("traceId") == null
+ events[1].getMDC("spanId") == null
+ events[1].getMDC("sampled") == null
+
+ events[2].message == "log message 3"
+ // this explicit getMDCCopy() call here is to make sure that whole instrumentation is tested
+ events[2].getMDCCopy()
+ events[2].getMDC("traceId") == span2.context.traceIdAsHexString
+ events[2].getMDC("spanId") == span2.context.spanIdAsHexString
+ events[2].getMDC("sampled") == "true"
+ }
+}

ADD
instrumentation/log4j/log4j-1.2/src/test/resources/log4j.properties
+log4j.rootLogger=INFO, LIST
+log4j.appender.LIST=ListAppender
\ No newline at end of file

MODIFY
settings.gradle
settings.gradle
@@ -126,6 +126,7 @@ include ':instrumentation:kubernetes-client-7.0'
include ':instrumentation:lettuce:lettuce-4.0'
include ':instrumentation:lettuce:lettuce-5.0'
include ':instrumentation:lettuce:lettuce-5.1'
+include ':instrumentation:log4j:log4j-1.2'
include ':instrumentation:log4j:log4j-2.13.2:library'
include ':instrumentation:logback:logback-1.0.0:auto'
include ':instrumentation:logback:logback-1.0.0:library'

Implement MDC auto-instrumentation for log4j1 (#1211)