From dcf0f5703041ec2c0797ebf60b1717211609f15f Mon Sep 17 00:00:00 2001 From: Luca Abbati Date: Thu, 20 Jun 2019 16:08:49 -0400 Subject: [PATCH] Add support for log4j 1.x --- .../trace/agent/tooling/AgentInstaller.java | 1 + .../instrumentation/log4j1/log4j1.gradle | 34 ++++++ .../log4j1/Log4j1MDCInstrumentation.java | 102 ++++++++++++++++++ .../log4j1/something/SomeClass.java | 18 ++++ .../src/test/groovy/Log4j1MDCTest.groovy | 97 +++++++++++++++++ .../instrumentation/log4j2/log4j2.gradle | 7 ++ .../ThreadContextInstrumentation.java | 2 +- settings.gradle | 1 + 8 files changed, 261 insertions(+), 1 deletion(-) create mode 100644 dd-java-agent/instrumentation/log4j1/log4j1.gradle create mode 100644 dd-java-agent/instrumentation/log4j1/src/main/java/datadog/trace/instrumentation/log4j1/Log4j1MDCInstrumentation.java create mode 100644 dd-java-agent/instrumentation/log4j1/src/main/java/datadoggggg/trace/instrumentation/log4j1/something/SomeClass.java create mode 100644 dd-java-agent/instrumentation/log4j1/src/test/groovy/Log4j1MDCTest.groovy rename dd-java-agent/instrumentation/log4j2/src/main/java/datadog/trace/instrumentation/{log4j => log4j2}/ThreadContextInstrumentation.java (98%) diff --git a/dd-java-agent/agent-tooling/src/main/java/datadog/trace/agent/tooling/AgentInstaller.java b/dd-java-agent/agent-tooling/src/main/java/datadog/trace/agent/tooling/AgentInstaller.java index ba39b39e5f..2e08c127cd 100644 --- a/dd-java-agent/agent-tooling/src/main/java/datadog/trace/agent/tooling/AgentInstaller.java +++ b/dd-java-agent/agent-tooling/src/main/java/datadog/trace/agent/tooling/AgentInstaller.java @@ -128,6 +128,7 @@ public class AgentInstaller { .or(nameStartsWith("com.jinspired.")) .or(nameStartsWith("org.jinspired.")) .or(nameStartsWith("org.apache.log4j.")) + .and(not(named("org.apache.log4j.MDC"))) .or(nameStartsWith("org.slf4j.").and(not(named("org.slf4j.MDC")))) .or(nameContains("$JaxbAccessor")) .or(nameContains("CGLIB$$")) diff --git a/dd-java-agent/instrumentation/log4j1/log4j1.gradle b/dd-java-agent/instrumentation/log4j1/log4j1.gradle new file mode 100644 index 0000000000..42ec36690c --- /dev/null +++ b/dd-java-agent/instrumentation/log4j1/log4j1.gradle @@ -0,0 +1,34 @@ +apply from: "${rootDir}/gradle/java.gradle" + +ext { + log4jVersion = '1.2.17' +} + +muzzle { + pass { + group = 'log4j' + module = 'log4j' + versions = '(,)' + } +} + +configurations { + // In order to test the real log4j library we need to remove the log4j transitive dependency + // dependency brought in by :dd-java-agent:testing over 'log4j-over-slf4j' which would shadow + // the log4j module under test. + testCompile.exclude group: 'org.slf4j', module: 'log4j-over-slf4j' +} + +dependencies { + compile project(':dd-trace-api') + compile project(':dd-java-agent:agent-tooling') + + testCompile group: 'log4j', name: 'log4j', version: log4jVersion + + compile deps.bytebuddy + compile deps.opentracing + annotationProcessor deps.autoservice + implementation deps.autoservice + + testCompile project(':dd-java-agent:testing') +} diff --git a/dd-java-agent/instrumentation/log4j1/src/main/java/datadog/trace/instrumentation/log4j1/Log4j1MDCInstrumentation.java b/dd-java-agent/instrumentation/log4j1/src/main/java/datadog/trace/instrumentation/log4j1/Log4j1MDCInstrumentation.java new file mode 100644 index 0000000000..b867a20750 --- /dev/null +++ b/dd-java-agent/instrumentation/log4j1/src/main/java/datadog/trace/instrumentation/log4j1/Log4j1MDCInstrumentation.java @@ -0,0 +1,102 @@ +package datadog.trace.instrumentation.log4j1; + +import static java.util.Collections.singletonMap; +import static net.bytebuddy.matcher.ElementMatchers.isConstructor; +import static net.bytebuddy.matcher.ElementMatchers.named; + +import com.google.auto.service.AutoService; +import datadog.trace.agent.tooling.Instrumenter; +import datadog.trace.api.Config; +import datadog.trace.api.CorrelationIdentifier; +import datadog.trace.api.GlobalTracer; +import datadog.trace.context.ScopeListener; +import java.lang.reflect.Method; +import java.util.Map; +import lombok.extern.slf4j.Slf4j; +import net.bytebuddy.asm.Advice; +import net.bytebuddy.description.method.MethodDescription; +import net.bytebuddy.description.type.TypeDescription; +import net.bytebuddy.matcher.ElementMatcher; + +@AutoService(Instrumenter.class) +public class Log4j1MDCInstrumentation extends Instrumenter.Default { + public static final String MDC_INSTRUMENTATION_NAME = "log4j-mdc"; + + private static final String mdcClassName = "org.apache.log4j.MDC"; + + public Log4j1MDCInstrumentation() { + super(MDC_INSTRUMENTATION_NAME); + } + + @Override + protected boolean defaultEnabled() { + return Config.getBooleanSettingFromEnvironment( + Config.LOGS_INJECTION_ENABLED, Config.DEFAULT_LOGS_INJECTION_ENABLED); + } + + @Override + public ElementMatcher typeMatcher() { + return named(mdcClassName); + } + + @Override + public Map, String> transformers() { + return singletonMap(isConstructor(), MDCContextAdvice.class.getName()); + } + + @Override + public String[] helperClassNames() { + return new String[] {MDCContextAdvice.class.getName() + "$MDCScopeListener"}; + } + + public static class MDCContextAdvice { + @Advice.OnMethodExit(suppress = Throwable.class) + public static void mdcClassInitialized(@Advice.This Object instance) { + try { + if (instance == null) { + return; + } + + Class mdcClass = instance.getClass(); + final Method putMethod = mdcClass.getMethod("put", String.class, Object.class); + final Method removeMethod = mdcClass.getMethod("remove", String.class); + GlobalTracer.get().addScopeListener(new MDCScopeListener(putMethod, removeMethod)); + } catch (final NoSuchMethodException e) { + } + } + + @Slf4j + public static class MDCScopeListener implements ScopeListener { + private final Method putMethod; + private final Method removeMethod; + + public MDCScopeListener(final Method putMethod, final Method removeMethod) { + System.out.println("Initializing scope listener"); + this.putMethod = putMethod; + this.removeMethod = removeMethod; + } + + @Override + public void afterScopeActivated() { + try { + putMethod.invoke( + null, CorrelationIdentifier.getTraceIdKey(), CorrelationIdentifier.getTraceId()); + putMethod.invoke( + null, CorrelationIdentifier.getSpanIdKey(), CorrelationIdentifier.getSpanId()); + } catch (final Exception e) { + log.debug("Exception setting thread context context", e); + } + } + + @Override + public void afterScopeClosed() { + try { + removeMethod.invoke(null, CorrelationIdentifier.getTraceIdKey()); + removeMethod.invoke(null, CorrelationIdentifier.getSpanIdKey()); + } catch (final Exception e) { + log.debug("Exception removing thread context context", e); + } + } + } + } +} diff --git a/dd-java-agent/instrumentation/log4j1/src/main/java/datadoggggg/trace/instrumentation/log4j1/something/SomeClass.java b/dd-java-agent/instrumentation/log4j1/src/main/java/datadoggggg/trace/instrumentation/log4j1/something/SomeClass.java new file mode 100644 index 0000000000..b72c5f4a14 --- /dev/null +++ b/dd-java-agent/instrumentation/log4j1/src/main/java/datadoggggg/trace/instrumentation/log4j1/something/SomeClass.java @@ -0,0 +1,18 @@ +package datadoggggg.trace.instrumentation.log4j1.something; + +public class SomeClass { + + private static SomeClass instance = new SomeClass(); + + public SomeClass() { + System.out.println("SomeClass Constructor.......!!!!!!!"); + } + + public static void put() { + instance.doSomething(); + } + + public void doSomething() { + System.out.println("SomeClass Doing something............"); + } +} diff --git a/dd-java-agent/instrumentation/log4j1/src/test/groovy/Log4j1MDCTest.groovy b/dd-java-agent/instrumentation/log4j1/src/test/groovy/Log4j1MDCTest.groovy new file mode 100644 index 0000000000..b54617e10d --- /dev/null +++ b/dd-java-agent/instrumentation/log4j1/src/test/groovy/Log4j1MDCTest.groovy @@ -0,0 +1,97 @@ +import datadog.trace.agent.test.AgentTestRunner +import datadog.trace.agent.test.utils.ConfigUtils +import datadog.trace.api.CorrelationIdentifier +import io.opentracing.Scope +import io.opentracing.util.GlobalTracer +import org.apache.log4j.MDC +import java.util.concurrent.atomic.AtomicReference + +class Log4j1MDCTest extends AgentTestRunner { + + static { + System.setProperty("dd.logs.injection", "true") + } + + def "MDC shows trace and span ids for active scope"() { + + when: + MDC.put("foo", "bar") + Scope rootScope = GlobalTracer.get().buildSpan("root").startActive(true) + + then: + MDC.get(CorrelationIdentifier.getTraceIdKey()) == CorrelationIdentifier.getTraceId() + MDC.get(CorrelationIdentifier.getSpanIdKey()) == CorrelationIdentifier.getSpanId() + MDC.get("foo") == "bar" + + when: + Scope childScope = GlobalTracer.get().buildSpan("child").startActive(true) + + then: + MDC.get(CorrelationIdentifier.getTraceIdKey()) == CorrelationIdentifier.getTraceId() + MDC.get(CorrelationIdentifier.getSpanIdKey()) == CorrelationIdentifier.getSpanId() + MDC.get("foo") == "bar" + + when: + childScope.close() + + then: + MDC.get(CorrelationIdentifier.getTraceIdKey()) == CorrelationIdentifier.getTraceId() + MDC.get(CorrelationIdentifier.getSpanIdKey()) == CorrelationIdentifier.getSpanId() + MDC.get("foo") == "bar" + + when: + rootScope.close() + + then: + MDC.get(CorrelationIdentifier.getTraceIdKey()) == null + MDC.get(CorrelationIdentifier.getSpanIdKey()) == null + MDC.get("foo") == "bar" + } + + def "MDC context scoped by thread"() { + setup: + ConfigUtils.updateConfig { + System.setProperty("dd.logs.injection", "true") + } + AtomicReference thread1TraceId = new AtomicReference<>() + AtomicReference thread2TraceId = new AtomicReference<>() + + final Thread thread1 = new Thread() { + @Override + void run() { + // no trace in scope + thread1TraceId.set(MDC.get(CorrelationIdentifier.getTraceIdKey())) + } + } + + final Thread thread2 = new Thread() { + @Override + void run() { + // other trace in scope + final Scope thread2Scope = GlobalTracer.get().buildSpan("root2").startActive(true) + try { + thread2TraceId.set(MDC.get(CorrelationIdentifier.getTraceIdKey())) + } finally { + thread2Scope.close() + } + } + } + final Scope mainScope = GlobalTracer.get().buildSpan("root").startActive(true) + thread1.start() + thread2.start() + final String mainThreadTraceId = MDC.get(CorrelationIdentifier.getTraceIdKey()) + final String expectedMainThreadTraceId = CorrelationIdentifier.getTraceId() + + thread1.join() + thread2.join() + + expect: + mainThreadTraceId == expectedMainThreadTraceId + thread1TraceId.get() == null + thread2TraceId.get() != null + thread2TraceId.get() != mainThreadTraceId + + cleanup: + mainScope?.close() + } +} diff --git a/dd-java-agent/instrumentation/log4j2/log4j2.gradle b/dd-java-agent/instrumentation/log4j2/log4j2.gradle index 981f623b63..b9fb992551 100644 --- a/dd-java-agent/instrumentation/log4j2/log4j2.gradle +++ b/dd-java-agent/instrumentation/log4j2/log4j2.gradle @@ -4,6 +4,13 @@ ext { log4jVersion = '2.11.2' } +configurations { + // In order to test the real log4j library we need to remove the log4j transitive dependency + // dependency brought in by :dd-java-agent:testing over 'log4j-over-slf4j' which would shadow + // the log4j module under test. + testCompile.exclude group: 'org.slf4j', module: 'log4j-over-slf4j' +} + muzzle { pass { group = 'org.apache.logging.log4j' diff --git a/dd-java-agent/instrumentation/log4j2/src/main/java/datadog/trace/instrumentation/log4j/ThreadContextInstrumentation.java b/dd-java-agent/instrumentation/log4j2/src/main/java/datadog/trace/instrumentation/log4j2/ThreadContextInstrumentation.java similarity index 98% rename from dd-java-agent/instrumentation/log4j2/src/main/java/datadog/trace/instrumentation/log4j/ThreadContextInstrumentation.java rename to dd-java-agent/instrumentation/log4j2/src/main/java/datadog/trace/instrumentation/log4j2/ThreadContextInstrumentation.java index 644a1a44cf..85ec29546e 100644 --- a/dd-java-agent/instrumentation/log4j2/src/main/java/datadog/trace/instrumentation/log4j/ThreadContextInstrumentation.java +++ b/dd-java-agent/instrumentation/log4j2/src/main/java/datadog/trace/instrumentation/log4j2/ThreadContextInstrumentation.java @@ -1,4 +1,4 @@ -package datadog.trace.instrumentation.log4j; +package datadog.trace.instrumentation.log4j2; import static java.util.Collections.singletonMap; import static net.bytebuddy.matcher.ElementMatchers.isTypeInitializer; diff --git a/settings.gradle b/settings.gradle index 4bceeaa7aa..23b68dd31f 100644 --- a/settings.gradle +++ b/settings.gradle @@ -66,6 +66,7 @@ include ':dd-java-agent:instrumentation:jsp-2.3' include ':dd-java-agent:instrumentation:kafka-clients-0.11' include ':dd-java-agent:instrumentation:kafka-streams-0.11' include ':dd-java-agent:instrumentation:lettuce-5' +include ':dd-java-agent:instrumentation:log4j1' include ':dd-java-agent:instrumentation:log4j2' include ':dd-java-agent:instrumentation:mongo' include ':dd-java-agent:instrumentation:mongo:driver-3.1'