mdc auto injection integration #630

realark · 2018-12-18T23:00:24Z

Add post-match hook to default instrumenter api
Add internal scope listener api
slf4j MDC autoinjection integration

realark · 2018-12-18T23:01:22Z

dd-java-agent/agent-tooling/src/main/java/datadog/trace/agent/tooling/AgentInstaller.java

@@ -92,7 +92,6 @@ public static ResettableClassFileTransformer installBytebuddyAgent(
            .or(nameStartsWith("org.aspectj."))
            .or(nameStartsWith("org.groovy."))
            .or(nameStartsWith("com.p6spy."))
-            .or(nameStartsWith("org.slf4j."))


This was intentional. This is actually not doing anything currently because shadow will rename the prefix to datadog.slf4j, which is already skipped.

mar-kolya · 2018-12-19T14:46:45Z

dd-java-agent/agent-tooling/src/main/java/datadog/trace/agent/tooling/Instrumenter.java

+                          protectionDomain);
+                      return true;
+                    }
+                  })


Would it make sense to pull this out into an actual named class like we do for MuzzleMatcher above to make this method more readable?

gradle/java.gradle

mar-kolya · 2018-12-19T14:55:42Z

...j-mdc/src/main/java/datadog/trace/instrumentation/slf4j/mdc/MDCInjectionInstrumentation.java

+
+  @Override
+  protected boolean defaultEnabled() {
+    final String enableInjection = getPropOrEnv("dd." + Config.LOGS_INJECTION);


Is Config getter not available here?

It is available, but our instrumentation seems to use a parallel path to get the configuration. I tried originally using Config.get(), but that isn't compatible with our testing.

That can be addressed but it's more of a general instrumenter thing, so I'd rather not fix it in this PR.

mar-kolya · 2018-12-19T14:58:58Z

dd-java-agent/agent-tooling/src/main/java/datadog/trace/agent/tooling/Instrumenter.java

@@ -179,6 +197,23 @@ protected ReferenceMatcher getInstrumentationMuzzle() {
    /** @return A type matcher used to match the class under transform. */
    public abstract ElementMatcher<? super TypeDescription> typeMatcher();

+    /**
+     * A hook invoked after matching has succeeded and before transformers have run.


Could you please add some sort of a note here that this is being run from matcher context, not from transformation context?

mar-kolya · 2018-12-19T15:00:26Z

dd-trace-api/src/main/java/datadog/trace/api/Config.java

@@ -91,6 +94,8 @@
  @Getter private final Integer jmxFetchRefreshBeansPeriod;
  @Getter private final String jmxFetchStatsdHost;
  @Getter private final Integer jmxFetchStatsdPort;
+  // Use (capital) Boolean to prefix generated getter with "get"
+  @Getter private final Boolean logsInjection;


you may want to make this boolean logsInjectionEnabled to avoid boxed fields.

isLogsInjection sounds awkward, but I guess I'm okay with it.

The annotation might allow customizing the method name if you want something different.

logsInjectionEnabled would lead to isLogsInjectionEnabled which sounds reasonable to me :)

The annotation doesn't allow customizing the name in this case unfortunately.

logsInjectionEnabled sounds good!

mar-kolya · 2018-12-19T15:56:25Z

...j-mdc/src/main/java/datadog/trace/instrumentation/slf4j/mdc/MDCInjectionInstrumentation.java

+      JavaModule module,
+      Class<?> classBeingRedefined,
+      ProtectionDomain protectionDomain) {
+    MDCAdvice.mdcClassInitialized(classBeingRedefined);


This method is annotated with BB stuff, are we sure it is safe to call is from 'outside' of BB logic?

It's safe to do in this case specifically because the advice only uses bootstrap classes. Also, this bit of code runs underneath the jvm transformer, so any errors can't escape into the application.

mar-kolya · 2018-12-19T15:57:12Z

...j-mdc/src/main/java/datadog/trace/instrumentation/slf4j/mdc/MDCInjectionInstrumentation.java

+          putMethod = mdcClass.getMethod("put", String.class, String.class);
+        } catch (NoSuchMethodException e) {
+          putMethod = mdcClass.getMethod("put", String.class, Object.class);
+        }


Could you please add a comment about why there is this try/catch and why you do not need one for remove.

Maybe include the versions on which the signature changed?

That was actually something I was doing for logback specifically. I ended up only instrumenting the slf4j api, so I'll remove the Object fallback.

mar-kolya · 2018-12-19T15:58:09Z

...j-mdc/src/main/java/datadog/trace/instrumentation/slf4j/mdc/MDCInjectionInstrumentation.java

+  }
+
+  public static class MDCAdvice {
+    @Advice.OnMethodExit


Should there be 'suppress' stuff?

Yes, thanks!

mar-kolya · 2018-12-19T16:00:14Z

...j-mdc/src/main/java/datadog/trace/instrumentation/slf4j/mdc/MDCInjectionInstrumentation.java

+    public static class MDCScopeListener implements ScopeListener {
+      private static final Logger log = org.slf4j.LoggerFactory.getLogger("mdc-scope-listener");
+      private static final String traceIdKey = "dd.trace_id";
+      private static final String spanIdKey = "dd.span_id";


These string seem to be constants, could you please capitalize them. Also you may want to make them visible for tests to avoid repeating them there.

mar-kolya · 2018-12-19T16:05:41Z

dd-trace-api/src/main/java/datadog/trace/context/ScopeListener.java

+
+  /** Called just after a scope is closed. */
+  void afterScopeClose();
+}


This seems to be highly asymmetrical API. I would suggest changing this to:

void afterScopeActivated(); void beforeScopeDeactivated();

And make sure that these are called whenever active scope changes (i.e. beforeScopeDeactivated is called on a scope being replaced as well).

I intentionally did that because we only need hooks for when the scope activates (multiple times) and when it closes (just once).

A fuller api would probably include four hooks:

open (once)

activated (>= 1)

deactivated (>= 1)

closed (once)

I was thinking for now just create the two we need and add the rest later as-needed.

That's fine by me, but I guess in your terms activated/deactivated is essentially same things I've proposed with afterScopeActivated/beforeScopeDeactivated. I'm slightly concerned that this is declared public and is not in a state we want that to be longer term - at the same time.

Yes, they are the the same thing. I think your names would be better for a real api; I just meant to point out that the current ScopeListener is intentionally incomplete.

I have concerns about this as well, but it's the least evil option I see until we can replace dd-trace-ot with a the new api.

Perhaps at least change it to afterScopeClosed to maintain some consistency.

Works for me. Done

mar-kolya · 2018-12-19T16:12:31Z

dd-trace-ot/src/test/groovy/datadog/opentracing/scopemanager/ScopeManagerTest.groovy

@@ -407,6 +409,52 @@ class ScopeManagerTest extends Specification {
    [new AtomicReferenceScope(true), new AtomicReferenceScope(true)] | _
  }

+  def "add scope listener"() {


Looks like changes to ContinuableScope remain untested.

I see ContinuableScope changes are exercised by Slf4jMDCTest but it still would be nice to have tests for them 'locally'.

Sure, I think that's easy to add.

tylerbenson

Nice work. I like the postMatch changes. I have some questions about making the ScopeListener public right now.

tylerbenson · 2018-12-19T16:12:50Z

dd-java-agent/agent-tooling/src/main/java/datadog/trace/agent/tooling/Instrumenter.java

@@ -86,6 +86,24 @@ public final AgentBuilder instrument(final AgentBuilder parentAgentBuilder) {
                      "Instrumentation class loader matcher unexpected exception: "
                          + getClass().getName()))
              .and(new MuzzleMatcher())
+              .and(
+                  new AgentBuilder.RawMatcher() {


Would it be possible/better to only add this if a postMatch is defined? (maybe !(this instanceof Default)?)

Only Defaults can hook the post-match, so we'd need another way to check if one is defined. I don't think it's worth the extra effort since this only runs when there's an actual match (not very often as far as classloads go)

tylerbenson · 2018-12-19T16:22:54Z

...j-mdc/src/main/java/datadog/trace/instrumentation/slf4j/mdc/MDCInjectionInstrumentation.java

+    public static class MDCScopeListener implements ScopeListener {
+      private static final Logger log = org.slf4j.LoggerFactory.getLogger("mdc-scope-listener");
+      private static final String traceIdKey = "dd.trace_id";
+      private static final String spanIdKey = "dd.span_id";


Are these keys defined in a spec? Do we want to allow users to configure different keys?

Yes, in the trace-logs rfc. For now the spec doesn't specify configuring different keys.

tylerbenson · 2018-12-19T16:23:57Z

...j-mdc/src/main/java/datadog/trace/instrumentation/slf4j/mdc/MDCInjectionInstrumentation.java

+    }
+
+    public static class MDCScopeListener implements ScopeListener {
+      private static final Logger log = org.slf4j.LoggerFactory.getLogger("mdc-scope-listener");


You don't want to use @Slf4j?

👍

I'm in the habit of not doing that in instrumentation, but it would work in this case since it's a helper class.

tylerbenson · 2018-12-19T16:27:49Z

...j-mdc/src/main/java/datadog/trace/instrumentation/slf4j/mdc/MDCInjectionInstrumentation.java

+          putMethod = mdcClass.getMethod("put", String.class, String.class);
+        } catch (NoSuchMethodException e) {
+          putMethod = mdcClass.getMethod("put", String.class, Object.class);
+        }


Maybe include the versions on which the signature changed?

tylerbenson · 2018-12-19T16:34:10Z

dd-trace-api/src/main/java/datadog/trace/api/Config.java

@@ -59,6 +59,9 @@
  public static final String DEFAULT_AGENT_HOST = "localhost";
  public static final int DEFAULT_TRACE_AGENT_PORT = 8126;

+  public static final String LOGS_INJECTION = "logs.injection";


This is fine, but throwing out some alternatives:

logs.correlation

logs.associate

I think those are fine, but we'll need an rfc change first. We're just following the rfc for configuring a common env variable.

tylerbenson · 2018-12-19T16:37:35Z

dd-trace-api/src/main/java/datadog/trace/api/Config.java

@@ -91,6 +94,8 @@
  @Getter private final Integer jmxFetchRefreshBeansPeriod;
  @Getter private final String jmxFetchStatsdHost;
  @Getter private final Integer jmxFetchStatsdPort;
+  // Use (capital) Boolean to prefix generated getter with "get"
+  @Getter private final Boolean logsInjection;


The annotation might allow customizing the method name if you want something different.

tylerbenson · 2018-12-19T16:38:39Z

dd-trace-api/src/main/java/datadog/trace/context/ScopeListener.java

+package datadog.trace.context;
+
+/** Hooks for scope activation */
+public interface ScopeListener {


Are we sure we want this on the public API right now?

I'd rather not, but unfortunately this is the only project available to both dd-trace-ot and instrumentation.

We already mix semi-private APIs in this project (see other classes in context package). It's not great, but it's the lesser of two evils. The alternative would be to expose agent-bootstrap to dd-trace-ot, which then brings a lot of stuff into the published dd-trace-ot artifact.

tylerbenson · 2018-12-19T16:39:24Z

dd-trace-api/src/main/java/datadog/trace/context/ScopeListener.java

+   * <p>May be called multiple times. When a scope is initially created, or after a child scope is
+   * deactivated.
+   */
+  void afterScopeActivated();


Would it be better to allow the scope/span to be passed into both methods? It might not be necessary here, but I can imagine it might be useful in other cases.

I would like to do that, but dd-trace-api doesn't depend on OpenTracing. So we'd have create another scope-like interface or overload the existing TraceScope.

realark · 2018-12-19T21:23:51Z

@mar-kolya new changes pushed. I believe this address all the feedback Can you please re-review? Once the review gets to a good state I'll doe one final rebase for the fixup: commits.

realark added this to the 0.21.0 milestone Dec 18, 2018

realark commented Dec 18, 2018

View reviewed changes

realark force-pushed the ark/mdc-auto-injection branch 3 times, most recently from 1ebc49b to b3b0d5e Compare December 19, 2018 01:16

realark requested a review from mar-kolya December 19, 2018 01:43

mar-kolya reviewed Dec 19, 2018

View reviewed changes

gradle/java.gradle Outdated Show resolved Hide resolved

mar-kolya reviewed Dec 19, 2018

View reviewed changes

tylerbenson reviewed Dec 19, 2018

View reviewed changes

realark mentioned this pull request Dec 19, 2018

remove errorprone #632

Merged

realark force-pushed the ark/mdc-auto-injection branch from b3b0d5e to e7d22b0 Compare December 19, 2018 21:20

Add internal scope listener api

1ed64da

realark force-pushed the ark/mdc-auto-injection branch from e7d22b0 to 60d2ec1 Compare December 19, 2018 21:21

mar-kolya approved these changes Dec 19, 2018

View reviewed changes

Andrew Kent added 3 commits December 19, 2018 17:07

Add post-match hook to default instrumenter api

4dc3528

slf4j MDC autoinjection integration

2861d87

Additional continuable-scope tests

e9f1436

realark force-pushed the ark/mdc-auto-injection branch from 60d2ec1 to e9f1436 Compare December 20, 2018 01:14

realark merged commit f6818fa into master Dec 20, 2018

realark deleted the ark/mdc-auto-injection branch December 20, 2018 01:42

mdc auto injection integration #630

mdc auto injection integration #630

Conversation

realark commented Dec 18, 2018 • edited

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

mar-kolya Dec 19, 2018 • edited

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

mar-kolya Dec 19, 2018 • edited

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

tylerbenson left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

realark commented Dec 19, 2018

realark commented Dec 18, 2018 •

edited

mar-kolya Dec 19, 2018 •

edited

mar-kolya Dec 19, 2018 •

edited