diff --git a/.agents/skills/apm-integrations/SKILL.md b/.agents/skills/apm-integrations/SKILL.md index 6553df66b1c..ebfcd4920a0 100644 --- a/.agents/skills/apm-integrations/SKILL.md +++ b/.agents/skills/apm-integrations/SKILL.md @@ -150,8 +150,11 @@ After `updateAgentJarIntegrationsGoldenFile` runs, commit the updated `metadata/ **If `checkDecoratorAnalyticsConfigurations` fails:** a name returned by the decorator's `instrumentationNames()` is missing `DD_TRACE__ANALYTICS_ENABLED` / `DD_TRACE__ANALYTICS_SAMPLE_RATE` entries in `metadata/supported-configurations.json` — add them per [Supported Configurations](references/supported-configurations.md). -**If tests fail:** verify span lifecycle order (start → activate → error → close → finish), helper registration, -and `contextStore()` map entries match actual usage. +**If tests fail:** verify span lifecycle order (start → activate → error → close → finish), helper +registration, and `contextStore()` map entries match actual usage. If the output contains +`Scope/continuation timeline`, read and follow +`.agents/skills/fix-continuation-leakage/SKILL.md`; fix the broken ownership edge rather than +adding `strictTraceWrites(false)` or disabling the diagnostic. ## Step 11 – Checklist before finishing diff --git a/.agents/skills/fix-continuation-leakage/SKILL.md b/.agents/skills/fix-continuation-leakage/SKILL.md new file mode 100644 index 00000000000..d87a570cca6 --- /dev/null +++ b/.agents/skills/fix-continuation-leakage/SKILL.md @@ -0,0 +1,59 @@ +--- +name: fix-continuation-leakage +description: > + Diagnose and fix scope or continuation lifecycle failures in dd-trace-java instrumentation + tests. Use when a test reports a continuation leak, double resolution, activation after resolve, + or an unclosed scope, or when strictTraceWrites(false) appears to hide one. Reads the automatic + diagnostic timeline, finds the broken lifecycle edge, fixes it, and explains it with a compact + Mermaid diagram. +user-invocable: true +context: fork +allowed-tools: + - Bash + - Read + - Edit + - Glob + - Grep + - AskUserQuestion +--- + +# Fix continuation leakage + +Instrumentation tests run the diagnostic automatically. A failure includes the capture, resume, +resolution, scope, thread, timing, and callsite data needed to find the missing lifecycle edge. + +## Work the failure + +1. Run the smallest failing test with full output: + +```bash +./gradlew :dd-java-agent:instrumentation:-:test --tests '' --info 2>&1 | tee /tmp/scopediag-run.txt +``` + +2. Find `Scope/continuation timeline` in the output. If Gradle hides it, inspect the test XML's + `` under the module's `build/test-results` directory. +3. Follow the failing record from its first event: + - `LEAKED` / `NEVER_CLOSED`: find the success, error, cancellation, and rejection exits that + skipped `release()` or `close()`. + - `DOUBLE_FINISH`: find two owners of the same cleanup. + - `ACTIVATE_AFTER_RESOLVE`: find work scheduled after ownership ended. + - `LATE_FINISH` / `CLOSE_WRONG_THREAD`: advisory evidence; verify whether ordering is valid. + - `[deferred-cleanup]`: a root iteration scope transferred cleanup to the bounded iteration + cleaner. It may remain open at the test boundary and is not a leak. Do not generalize this to + other `ITERATION` scopes; an unregistered iteration scope must still close normally. +4. Fix ownership where it breaks. Prefer one owner and `try/finally` cleanup across every exit. +5. Rerun the failing test, then its module. + +Do not make the test green with `strictTraceWrites(false)` or +`@TrackScopeContinuations(enabled=false, reason="...")`. Those hide evidence. The opt-out requires +a reason and is only for a proven diagnostic incompatibility. If the failure is genuinely +intermittent, treat that as a flaky-test finding, keep diagnostics enabled, and link the `@Flaky` +annotation to a tracked issue. + +## Explain it to a human + +Lead with one sentence: what was captured, which cleanup edge was missing, and where. Cite the +timeline callsites. Then include a small Mermaid `flowchart LR`; use green for healthy edges, red +for the broken edge, and label thread handoffs. Use a Gantt only when timing itself caused the bug. + +End with the code fix and the exact tests that passed. diff --git a/.claude/skills/fix-continuation-leakage/SKILL.md b/.claude/skills/fix-continuation-leakage/SKILL.md new file mode 100644 index 00000000000..fa436670a4b --- /dev/null +++ b/.claude/skills/fix-continuation-leakage/SKILL.md @@ -0,0 +1,23 @@ +--- +name: fix-continuation-leakage +description: > + Diagnose and fix scope or continuation lifecycle failures in dd-trace-java instrumentation + tests. Use when a test reports a continuation leak, double resolution, activation after resolve, + or an unclosed scope, or when strictTraceWrites(false) appears to hide one. Reads the automatic + diagnostic timeline, finds the broken lifecycle edge, fixes it, and explains it with a compact + Mermaid diagram. +user-invocable: true +context: fork +allowed-tools: + - Bash + - Read + - Edit + - Glob + - Grep + - AskUserQuestion +--- + +# Fix continuation leakage + +Read `.agents/skills/fix-continuation-leakage/SKILL.md` in full and follow it. That file is the +shared playbook for repository agents. diff --git a/dd-java-agent/instrumentation-testing/src/main/groovy/datadog/trace/agent/test/InstrumentationSpecification.groovy b/dd-java-agent/instrumentation-testing/src/main/groovy/datadog/trace/agent/test/InstrumentationSpecification.groovy index 951c2ecff3e..6365c4d6a81 100644 --- a/dd-java-agent/instrumentation-testing/src/main/groovy/datadog/trace/agent/test/InstrumentationSpecification.groovy +++ b/dd-java-agent/instrumentation-testing/src/main/groovy/datadog/trace/agent/test/InstrumentationSpecification.groovy @@ -33,6 +33,8 @@ import datadog.metrics.impl.DDSketchHistograms import datadog.metrics.impl.MonitoringImpl import datadog.trace.agent.test.asserts.ListWriterAssert import datadog.trace.agent.test.asserts.TagsAssert +import datadog.trace.agent.test.scopediag.ScopeDiagnostics +import datadog.trace.agent.test.scopediag.TrackScopeContinuations import datadog.trace.agent.test.datastreams.MockFeaturesDiscovery import datadog.trace.agent.test.datastreams.RecordingDatastreamsPayloadWriter import datadog.trace.agent.tooling.AgentInstaller @@ -467,6 +469,9 @@ abstract class InstrumentationSpecification extends DDSpecification implements A } TEST_WRITER.start() + if (scopeDiagnosticsEnabled()) { + ScopeDiagnostics.startRecording() + } TEST_DATA_STREAMS_WRITER.clear() TEST_DATA_STREAMS_MONITORING.clear() @@ -500,27 +505,73 @@ abstract class InstrumentationSpecification extends DDSpecification implements A } TEST_TRACER.flush() - def util = new MockUtil() - util.detachMock(STATS_D_CLIENT) + def scopeDiagnosticsFailure = reportScopeDiagnostics() + + try { + def util = new MockUtil() + util.detachMock(STATS_D_CLIENT) + + ActiveSubsystems.APPSEC_ACTIVE = originalAppSecRuntimeValue + + if (Config.get().isDebuggerCodeOriginEnabled()) { + injectSysConfig(CODE_ORIGIN_FOR_SPANS_ENABLED, "false", true) + rebuildConfig() + } - ActiveSubsystems.APPSEC_ACTIVE = originalAppSecRuntimeValue + try { + if (enabledFinishTimingChecks()) { + doCheckRepeatedFinish() + } + } finally { + spanFinishLocations.clear() + originalToTrackingSpan.clear() + } - if (Config.get().isDebuggerCodeOriginEnabled()) { - injectSysConfig(CODE_ORIGIN_FOR_SPANS_ENABLED, "false", true) - rebuildConfig() + // check for instrumentation issues while running each test + assert InstrumentationErrors.noErrors(): InstrumentationErrors.describeErrors() + } catch (Throwable cleanupFailure) { + if (scopeDiagnosticsFailure != null) { + cleanupFailure.addSuppressed(scopeDiagnosticsFailure) + } + throw cleanupFailure + } + if (scopeDiagnosticsFailure != null) { + throw scopeDiagnosticsFailure } + } + + private TrackScopeContinuations scopeDiagConfig() { + def method = specificationContext?.currentFeature?.featureMethod?.reflection + def ann = method?.getAnnotation(TrackScopeContinuations) + if (ann == null) { + ann = this.class.getAnnotation(TrackScopeContinuations) + } + return ann + } + + private boolean scopeDiagnosticsEnabled() { + return ScopeDiagnostics.isEnabled(scopeDiagConfig()) + } + private Throwable reportScopeDiagnostics() { + def config = scopeDiagConfig() + if (!ScopeDiagnostics.isEnabled(config)) { + return null + } try { - if (enabledFinishTimingChecks()) { - doCheckRepeatedFinish() + ScopeDiagnostics.awaitQuiescence() + ScopeDiagnostics.stop() + def report = ScopeDiagnostics.report() + if (report.hasFindings()) { + println(report.renderTimeline()) } + ScopeDiagnostics.assertNoLeaks(report) + return null + } catch (Throwable failure) { + return failure } finally { - spanFinishLocations.clear() - originalToTrackingSpan.clear() + ScopeDiagnostics.reset() } - - // check for instrumentation issues while running each test - assert InstrumentationErrors.noErrors(): InstrumentationErrors.describeErrors() } private void doCheckRepeatedFinish() { diff --git a/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/AbstractInstrumentationTest.java b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/AbstractInstrumentationTest.java index e8fe97f00de..4f498cd7e0b 100644 --- a/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/AbstractInstrumentationTest.java +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/AbstractInstrumentationTest.java @@ -7,6 +7,7 @@ import datadog.instrument.classinject.ClassInjector; import datadog.trace.agent.test.assertions.TraceAssertions; import datadog.trace.agent.test.assertions.TraceMatcher; +import datadog.trace.agent.test.scopediag.ScopeDiagnosticsExtension; import datadog.trace.agent.tooling.AgentInstaller; import datadog.trace.agent.tooling.InstrumenterModule; import datadog.trace.agent.tooling.TracerInstaller; @@ -58,7 +59,8 @@ @ExtendWith({ TestClassShadowingExtension.class, AllowContextTestingExtension.class, - LegacyContextTestingExtension.class + LegacyContextTestingExtension.class, + ScopeDiagnosticsExtension.class }) public abstract class AbstractInstrumentationTest { static final Instrumentation INSTRUMENTATION = ByteBuddyAgent.getInstrumentation(); diff --git a/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ContinuableScopeAdvice.java b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ContinuableScopeAdvice.java new file mode 100644 index 00000000000..59b2a3c23b1 --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ContinuableScopeAdvice.java @@ -0,0 +1,22 @@ +package datadog.trace.agent.test.scopediag; + +import net.bytebuddy.asm.Advice; + +/** Test-only advice for {@code ContinuableScope}. */ +public final class ContinuableScopeAdvice { + private ContinuableScopeAdvice() {} + + public static final class OnProperClose { + @Advice.OnMethodExit(suppress = Throwable.class) + public static void exit(@Advice.This Object scope) { + ScopeContinuationProbe.onScopeClose(scope); + } + } + + public static final class Close { + @Advice.OnMethodEnter(suppress = Throwable.class) + public static void enter(@Advice.This Object scope) { + ScopeContinuationProbe.onScopeClosing(scope); + } + } +} diff --git a/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ContinuableScopeManagerAdvice.java b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ContinuableScopeManagerAdvice.java new file mode 100644 index 00000000000..c98cfa301c9 --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ContinuableScopeManagerAdvice.java @@ -0,0 +1,15 @@ +package datadog.trace.agent.test.scopediag; + +import net.bytebuddy.asm.Advice; + +/** Test-only advice for scopes owned by the iteration cleaner. */ +public final class ContinuableScopeManagerAdvice { + private ContinuableScopeManagerAdvice() {} + + public static final class ScheduleRootIterationCleanup { + @Advice.OnMethodExit(suppress = Throwable.class) + public static void exit(@Advice.Argument(1) Object scope) { + ScopeContinuationProbe.onDeferredScopeCleanup(scope); + } + } +} diff --git a/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ContinuationAdvice.java b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ContinuationAdvice.java new file mode 100644 index 00000000000..cf430b5ed22 --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ContinuationAdvice.java @@ -0,0 +1,50 @@ +package datadog.trace.agent.test.scopediag; + +import net.bytebuddy.asm.Advice; + +/** Test-only advice for {@code ScopeContinuation}. */ +public final class ContinuationAdvice { + private ContinuationAdvice() {} + + public static final class Register { + @Advice.OnMethodExit(suppress = Throwable.class) + public static void exit(@Advice.This Object self) { + ScopeContinuationProbe.onCapture(self); + } + } + + /** Timestamps entry because {@code resume()} may resolve the continuation before returning. */ + public static final class Activate { + @Advice.OnMethodEnter + public static long enter() { + return System.nanoTime(); + } + + @Advice.OnMethodExit(suppress = Throwable.class) + public static void exit( + @Advice.This Object self, @Advice.Enter long ddActivateNanos, @Advice.Return Object scope) { + ScopeContinuationProbe.onActivate(self, scope, ddActivateNanos); + } + } + + /** Timestamps entry because resolution may write the trace before the method returns. */ + public static final class Cancel { + @Advice.OnMethodEnter + public static int enter( + @Advice.FieldValue("count") int count, + @Advice.Local("ddResolveNanos") long ddResolveNanos) { + ddResolveNanos = System.nanoTime(); + return count; + } + + @Advice.OnMethodExit(suppress = Throwable.class) + public static void exit( + @Advice.This Object self, + @Advice.Origin("#m") String method, + @Advice.Enter int countBefore, + @Advice.Local("ddResolveNanos") long ddResolveNanos, + @Advice.FieldValue("count") int countAfter) { + ScopeContinuationProbe.onResolve(self, method, countBefore, countAfter, ddResolveNanos); + } + } +} diff --git a/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ContinuationRecord.java b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ContinuationRecord.java new file mode 100644 index 00000000000..845218efa2f --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ContinuationRecord.java @@ -0,0 +1,220 @@ +package datadog.trace.agent.test.scopediag; + +import datadog.trace.api.DDTraceId; +import java.util.ArrayList; +import java.util.EnumSet; +import java.util.List; + +/** Records a continuation's capture, activations, scopes, and resolution. */ +public final class ContinuationRecord { + public final long seq; + public final DDTraceId traceId; + public final long spanId; + public final String spanName; + public final byte source; + + /** {@code true} when a resume/resolution was seen without a preceding capture in this window. */ + public final boolean orphan; + + private final ScopeEvent capture; + private final List resumes = new ArrayList<>(1); + private final List failedActivations = new ArrayList<>(0); + private ScopeEvent terminal; + private final List extraTerminals = new ArrayList<>(0); + private final List scopeRecordSeqs = new ArrayList<>(1); + + ContinuationRecord( + long seq, + DDTraceId traceId, + long spanId, + String spanName, + byte source, + boolean orphan, + ScopeEvent capture) { + this.seq = seq; + this.traceId = traceId; + this.spanId = spanId; + this.spanName = spanName; + this.source = source; + this.orphan = orphan; + this.capture = capture; + } + + synchronized void addResume(ScopeEvent event) { + resumes.add(event); + } + + synchronized void addFailedActivation(ScopeEvent event) { + failedActivations.add(event); + } + + /** First terminal sets {@link #terminal}; any subsequent terminal is a double-finish signal. */ + synchronized void setTerminalOrExtra(ScopeEvent event) { + if (terminal == null) { + terminal = event; + } else { + extraTerminals.add(event); + } + } + + synchronized void linkScope(long scopeSeq) { + scopeRecordSeqs.add(scopeSeq); + } + + synchronized ContinuationRecord snapshot() { + ContinuationRecord copy = + new ContinuationRecord( + seq, + traceId, + spanId, + spanName, + source, + orphan, + capture == null ? null : capture.snapshot()); + for (ScopeEvent event : resumes) { + copy.resumes.add(event.snapshot()); + } + for (ScopeEvent event : failedActivations) { + copy.failedActivations.add(event.snapshot()); + } + copy.terminal = terminal == null ? null : terminal.snapshot(); + for (ScopeEvent event : extraTerminals) { + copy.extraTerminals.add(event.snapshot()); + } + copy.scopeRecordSeqs.addAll(scopeRecordSeqs); + return copy; + } + + public synchronized ScopeEvent capture() { + return capture; + } + + public synchronized List resumes() { + return new ArrayList<>(resumes); + } + + public synchronized List failedActivations() { + return new ArrayList<>(failedActivations); + } + + public synchronized ScopeEvent terminal() { + return terminal; + } + + public synchronized List extraTerminals() { + return new ArrayList<>(extraTerminals); + } + + public synchronized List scopeRecordSeqs() { + return new ArrayList<>(scopeRecordSeqs); + } + + public synchronized boolean isResolved() { + return terminal != null; + } + + public synchronized ContinuationStatus status() { + if (terminal != null) { + return terminal.type == ScopeEvent.Type.RESOLVE_CANCEL + ? ContinuationStatus.CANCELLED + : ContinuationStatus.FINISHED; + } + return ContinuationStatus.LEAKED; + } + + /** Derives failures, including events after {@code rootWrittenNanos} when provided. */ + public synchronized EnumSet failures(Long rootWrittenNanos) { + EnumSet failures = EnumSet.noneOf(Failure.class); + if (terminal == null) { + failures.add(Failure.LEAKED); + } + if (!extraTerminals.isEmpty()) { + failures.add(Failure.DOUBLE_FINISH); + } + if (!failedActivations.isEmpty() || resumedAfterTerminal()) { + failures.add(Failure.ACTIVATE_AFTER_RESOLVE); + } + if (rootWrittenNanos != null + && (laterThan(terminal, rootWrittenNanos) || laterThan(resumes, rootWrittenNanos))) { + failures.add(Failure.LATE_FINISH); + } + return failures; + } + + private boolean resumedAfterTerminal() { + if (terminal == null) { + return false; + } + for (ScopeEvent r : resumes) { + if (r.nanos > terminal.nanos) { + return true; + } + } + return false; + } + + /** {@code true} when capture and any resume/terminal happened on different threads. */ + public synchronized boolean threadHandoff() { + if (capture == null) { + return false; + } + String captureThread = capture.threadName; + for (ScopeEvent r : resumes) { + if (!captureThread.equals(r.threadName)) { + return true; + } + } + return terminal != null && !captureThread.equals(terminal.threadName); + } + + /** Nanos between capture and the first resume, or {@code null} if not both observed. */ + public synchronized Long captureToFirstResumeNanos() { + if (capture == null || resumes.isEmpty()) { + return null; + } + return resumes.get(0).nanos - capture.nanos; + } + + /** Nanos between capture and the terminal resolution, or {@code null} if not both observed. */ + public synchronized Long ageAtTerminalNanos() { + if (capture == null || terminal == null) { + return null; + } + return terminal.nanos - capture.nanos; + } + + /** Earliest known event time for ordering the timeline. */ + public synchronized long firstNanos() { + long min = capture != null ? capture.nanos : Long.MAX_VALUE; + for (ScopeEvent e : resumes) { + min = Math.min(min, e.nanos); + } + for (ScopeEvent e : failedActivations) { + min = Math.min(min, e.nanos); + } + if (terminal != null) { + min = Math.min(min, terminal.nanos); + } + for (ScopeEvent e : extraTerminals) { + min = Math.min(min, e.nanos); + } + return min; + } + + public String sourceName() { + return ScopeSources.name(source); + } + + private static boolean laterThan(ScopeEvent event, long nanos) { + return event != null && event.nanos > nanos; + } + + private static boolean laterThan(List events, long nanos) { + for (ScopeEvent e : events) { + if (e.nanos > nanos) { + return true; + } + } + return false; + } +} diff --git a/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ContinuationStatus.java b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ContinuationStatus.java new file mode 100644 index 00000000000..e26bf691fa4 --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ContinuationStatus.java @@ -0,0 +1,11 @@ +package datadog.trace.agent.test.scopediag; + +/** Derived continuation state used when rendering a timeline. */ +public enum ContinuationStatus { + /** Resolved normally (all activations closed or a clean cancel with no outstanding work). */ + FINISHED, + /** Resolved via the cancel-with-outstanding-work path. */ + CANCELLED, + /** Captured (and possibly resumed) but never resolved within the recording window. */ + LEAKED +} diff --git a/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/Failure.java b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/Failure.java new file mode 100644 index 00000000000..64a596bf473 --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/Failure.java @@ -0,0 +1,17 @@ +package datadog.trace.agent.test.scopediag; + +/** A derived scope or continuation lifecycle finding. */ +public enum Failure { + /** Continuation captured but never resolved within the window. */ + LEAKED, + /** Continuation resolved/resumed after the root span of its trace was already written. */ + LATE_FINISH, + /** Continuation resolved more than once. */ + DOUBLE_FINISH, + /** Continuation activated after it had already been resolved. */ + ACTIVATE_AFTER_RESOLVE, + /** Scope closed while not on top of its thread's stack (closed on the wrong thread / order). */ + CLOSE_WRONG_THREAD, + /** Scope opened but never closed within the window. */ + NEVER_CLOSED +} diff --git a/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/PendingTraceAdvice.java b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/PendingTraceAdvice.java new file mode 100644 index 00000000000..a93b2936b7c --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/PendingTraceAdvice.java @@ -0,0 +1,29 @@ +package datadog.trace.agent.test.scopediag; + +import net.bytebuddy.asm.Advice; + +/** + * Records a root write only after {@code PendingTrace.write(boolean)} sets {@code rootSpanWritten}. + */ +public final class PendingTraceAdvice { + private PendingTraceAdvice() {} + + public static final class Write { + @Advice.OnMethodEnter(suppress = Throwable.class) + public static boolean enter( + @Advice.Argument(0) boolean isPartial, + @Advice.FieldValue("rootSpanWritten") boolean alreadyWritten) { + return !isPartial && !alreadyWritten; + } + + @Advice.OnMethodExit(suppress = Throwable.class) + public static void exit( + @Advice.Enter boolean candidate, + @Advice.FieldValue("rootSpanWritten") boolean written, + @Advice.FieldValue("traceId") Object traceId) { + if (candidate && written) { + ScopeContinuationProbe.onRootWritten(traceId); + } + } + } +} diff --git a/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeContinuationProbe.java b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeContinuationProbe.java new file mode 100644 index 00000000000..4cd5ef08003 --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeContinuationProbe.java @@ -0,0 +1,272 @@ +package datadog.trace.agent.test.scopediag; + +import datadog.context.ContextContinuation; +import datadog.trace.api.DDTraceId; +import datadog.trace.bootstrap.instrumentation.api.AgentScope; +import datadog.trace.bootstrap.instrumentation.api.AgentSpan; +import datadog.trace.bootstrap.instrumentation.api.NoopScope; +import java.lang.reflect.Field; +import java.lang.reflect.Method; + +/** Forwards test-only Byte Buddy advice events to {@link ScopeDiagnostics}. */ +public final class ScopeContinuationProbe { + /** + * Mirrors {@code ScopeContinuation.CANCELLED}. Reaching this value marks a resolved continuation; + * {@code ScopeContinuationProbeTest} detects drift. + */ + static final int CANCELLED = Integer.MIN_VALUE >> 1; + + private static volatile boolean recording = false; + + private static volatile Field sourceField; + + private static volatile Field scopeSourceField; + private static volatile Field continuationField; + private static volatile Field scopeManagerField; + private static volatile Method scopeStackMethod; + private static volatile Method checkTopMethod; + + private ScopeContinuationProbe() {} + + /** Installs the transformer once and starts recording. */ + static synchronized void enable() { + ScopeContinuationTransformer.install(); + recording = true; + } + + /** Stops recording without uninstalling the transformer. */ + static void disable() { + recording = false; + } + + public static void onCapture(Object self) { + if (!recording) { + return; + } + try { + ContextContinuation continuation = (ContextContinuation) self; + AgentSpan span = AgentSpan.fromContext(continuation.context()); + if (span != null) { + ScopeDiagnostics.recordCapture( + continuation, span.getTraceId(), span.getSpanId(), spanName(span), sourceOf(self)); + } + } catch (Throwable ignored) { + // Diagnostics must never affect the tracer. + } + } + + public static void onActivate(Object self, Object returnedScope, long activateNanos) { + if (!recording) { + return; + } + try { + ContextContinuation continuation = (ContextContinuation) self; + if (returnedScope == NoopScope.INSTANCE) { + // A noop result may indicate activation after resolution. + ScopeDiagnostics.recordActivateFailed(continuation); + return; + } + AgentSpan span = AgentSpan.fromContext(continuation.context()); + if (span != null) { + ScopeDiagnostics.recordActivate( + continuation, + span.getTraceId(), + span.getSpanId(), + spanName(span), + sourceOf(self), + activateNanos); + } + } catch (Throwable ignored) { + } + } + + public static void onResolve( + Object self, String method, int countBefore, int countAfter, long resolveNanos) { + if (!recording) { + return; + } + if (countAfter != CANCELLED) { + return; + } + // release discards; cancelFromContinuedScopeClose finishes. Its slow path delegates to release, + // so a multi-activation finish can appear as a cancellation. + boolean cancelled = "release".equals(method); + try { + ContextContinuation continuation = (ContextContinuation) self; + ScopeDiagnostics.recordResolve( + continuation, cancelled, resolveNanos, countBefore == CANCELLED); + } catch (Throwable ignored) { + } + } + + public static void onRootWritten(Object traceId) { + if (!recording) { + return; + } + try { + ScopeDiagnostics.recordRootWritten((DDTraceId) traceId); + } catch (Throwable ignored) { + } + } + + public static void onScopeOpen(Object scope) { + if (!recording) { + return; + } + try { + AgentSpan span = ((AgentScope) scope).span(); + DDTraceId traceId = span != null ? span.getTraceId() : DDTraceId.ZERO; + long spanId = span != null ? span.getSpanId() : 0L; + String name = span != null ? spanName(span) : null; + ScopeDiagnostics.recordScopeOpen( + scope, traceId, spanId, name, scopeSourceOf(scope), continuationOf(scope)); + } catch (Throwable ignored) { + } + } + + public static void onScopeClose(Object scope) { + if (!recording) { + return; + } + try { + ScopeDiagnostics.recordScopeClose(scope); + } catch (Throwable ignored) { + } + } + + public static void onDeferredScopeCleanup(Object scope) { + if (!recording) { + return; + } + try { + ScopeDiagnostics.recordDeferredScopeCleanup(scope); + } catch (Throwable ignored) { + } + } + + /** Records an out-of-order close when the internal stack can be inspected. */ + public static void onScopeClosing(Object scope) { + if (!recording) { + return; + } + try { + if (isNotOnTop(scope)) { + ScopeDiagnostics.recordScopeCloseWrongThread(scope); + } + } catch (Throwable ignored) { + } + } + + /** Copies the possibly mutable span name. */ + private static String spanName(AgentSpan span) { + try { + CharSequence name = span.getSpanName(); + return name == null ? null : name.toString(); + } catch (Throwable ignored) { + return null; + } + } + + private static byte sourceOf(Object self) { + try { + Field field = sourceField; + if (field == null) { + field = self.getClass().getDeclaredField("source"); + field.setAccessible(true); + sourceField = field; + } + return field.getByte(self); + } catch (Throwable ignored) { + return (byte) -1; + } + } + + private static byte scopeSourceOf(Object scope) { + try { + Field field = scopeSourceField; + if (field == null) { + field = findField(scope.getClass(), "source"); + scopeSourceField = field; + } + return field != null ? field.getByte(scope) : (byte) -1; + } catch (Throwable ignored) { + return (byte) -1; + } + } + + private static ContextContinuation continuationOf(Object scope) { + try { + Field field = continuationField; + if (field == null) { + field = findField(scope.getClass(), "continuation"); + continuationField = field; + } + if (field == null || !field.getDeclaringClass().isInstance(scope)) { + return null; + } + Object value = field.get(scope); + return value instanceof ContextContinuation ? (ContextContinuation) value : null; + } catch (Throwable ignored) { + return null; + } + } + + private static boolean isNotOnTop(Object scope) { + try { + Field managerField = scopeManagerField; + if (managerField == null) { + managerField = findField(scope.getClass(), "scopeManager"); + scopeManagerField = managerField; + } + Object manager = managerField != null ? managerField.get(scope) : null; + if (manager == null) { + return false; + } + Method stackMethod = scopeStackMethod; + if (stackMethod == null) { + stackMethod = findMethod(manager.getClass(), "scopeStack", 0); + scopeStackMethod = stackMethod; + } + Object stack = stackMethod != null ? stackMethod.invoke(manager) : null; + if (stack == null) { + return false; + } + Method check = checkTopMethod; + if (check == null) { + check = findMethod(stack.getClass(), "checkTop", 1); + checkTopMethod = check; + } + if (check == null) { + return false; + } + Object onTop = check.invoke(stack, scope); + return onTop instanceof Boolean && !((Boolean) onTop); + } catch (Throwable ignored) { + return false; + } + } + + private static Field findField(Class cls, String name) { + for (Class c = cls; c != null; c = c.getSuperclass()) { + try { + Field f = c.getDeclaredField(name); + f.setAccessible(true); + return f; + } catch (NoSuchFieldException ignored) { + } + } + return null; + } + + private static Method findMethod(Class cls, String name, int paramCount) { + for (Class c = cls; c != null; c = c.getSuperclass()) { + for (Method m : c.getDeclaredMethods()) { + if (m.getName().equals(name) && m.getParameterCount() == paramCount) { + m.setAccessible(true); + return m; + } + } + } + return null; + } +} diff --git a/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeContinuationTransformer.java b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeContinuationTransformer.java new file mode 100644 index 00000000000..f00a942eb2f --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeContinuationTransformer.java @@ -0,0 +1,137 @@ +package datadog.trace.agent.test.scopediag; + +import static datadog.trace.agent.tooling.bytebuddy.matcher.NameMatchers.named; +import static net.bytebuddy.matcher.ElementMatchers.isMethod; +import static net.bytebuddy.matcher.ElementMatchers.returns; +import static net.bytebuddy.matcher.ElementMatchers.takesArgument; +import static net.bytebuddy.matcher.ElementMatchers.takesArguments; + +import java.lang.instrument.Instrumentation; +import net.bytebuddy.agent.ByteBuddyAgent; +import net.bytebuddy.agent.builder.AgentBuilder; +import net.bytebuddy.agent.builder.ResettableClassFileTransformer; +import net.bytebuddy.asm.Advice; + +/** + * Installs test-only advice with a separate {@link AgentBuilder} because the tracer ignores its own + * core classes. Retransformation covers classes loaded before the diagnostic starts. + */ +final class ScopeContinuationTransformer { + private static volatile ResettableClassFileTransformer transformer; + + private ScopeContinuationTransformer() {} + + static synchronized void install() { + if (transformer != null) { + return; + } + try { + // Related core types can otherwise load this target reentrantly while they are transformed. + Class.forName( + "datadog.trace.core.scopemanager.ScopeContinuation", + false, + ScopeContinuationTransformer.class.getClassLoader()); + } catch (ClassNotFoundException missingCoreTracer) { + throw new IllegalStateException( + "Scope continuation diagnostics require dd-trace-core", missingCoreTracer); + } + Instrumentation instrumentation = ByteBuddyAgent.getInstrumentation(); + transformer = + new AgentBuilder.Default() + .disableClassFormatChanges() + .with(AgentBuilder.RedefinitionStrategy.RETRANSFORMATION) + .with(AgentBuilder.TypeStrategy.Default.REDEFINE) + .type(named("datadog.trace.core.scopemanager.ScopeContinuation")) + .transform( + (builder, type, classLoader, module, pd) -> + builder + .visit( + Advice.to(ContinuationAdvice.Register.class) + .on( + isMethod() + .and(named("register")) + .and(takesArguments(0)) + .and( + returns( + named( + "datadog.trace.core.scopemanager.ScopeContinuation"))))) + .visit( + Advice.to(ContinuationAdvice.Activate.class) + .on( + isMethod() + .and(named("resume")) + .and(takesArguments(0)) + .and(returns(named("datadog.context.ContextScope"))))) + .visit( + Advice.to(ContinuationAdvice.Cancel.class) + .on( + isMethod() + .and( + named("release") + .or(named("cancelFromContinuedScopeClose"))) + .and(takesArguments(0)) + .and(returns(void.class))))) + .type(named("datadog.trace.core.PendingTrace")) + .transform( + (builder, type, classLoader, module, pd) -> + builder.visit( + Advice.to(PendingTraceAdvice.Write.class) + .on( + isMethod() + .and(named("write")) + .and(takesArguments(boolean.class)) + .and(returns(int.class))))) + .type(named("datadog.trace.core.scopemanager.ContinuableScope")) + .transform( + (builder, type, classLoader, module, pd) -> + builder + .visit( + Advice.to(ContinuableScopeAdvice.OnProperClose.class) + .on( + isMethod() + .and(named("onProperClose")) + .and(takesArguments(0)) + .and(returns(void.class)))) + .visit( + Advice.to(ContinuableScopeAdvice.Close.class) + .on( + isMethod() + .and(named("close")) + .and(takesArguments(0)) + .and(returns(void.class))))) + .type(named("datadog.trace.core.scopemanager.ScopeStack")) + .transform( + (builder, type, classLoader, module, pd) -> + builder.visit( + Advice.to(ScopeStackAdvice.Push.class) + .on( + isMethod() + .and(named("push")) + .and(takesArguments(1)) + .and( + takesArgument( + 0, + named( + "datadog.trace.core.scopemanager.ContinuableScope"))) + .and(returns(void.class))))) + .type(named("datadog.trace.core.scopemanager.ContinuableScopeManager")) + .transform( + (builder, type, classLoader, module, pd) -> + builder.visit( + Advice.to(ContinuableScopeManagerAdvice.ScheduleRootIterationCleanup.class) + .on( + isMethod() + .and(named("scheduleRootIterationScopeCleanup")) + .and(takesArguments(2)) + .and( + takesArgument( + 0, named("datadog.trace.core.scopemanager.ScopeStack"))) + .and( + takesArgument( + 1, + named( + "datadog.trace.core.scopemanager.ContinuableScope"))) + .and(returns(void.class))))) + .installOn(instrumentation); + } +} diff --git a/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeDiagnostics.java b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeDiagnostics.java new file mode 100644 index 00000000000..c95582b545f --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeDiagnostics.java @@ -0,0 +1,383 @@ +package datadog.trace.agent.test.scopediag; + +import datadog.context.ContextContinuation; +import datadog.trace.api.DDTraceId; +import java.util.ArrayList; +import java.util.Collections; +import java.util.HashMap; +import java.util.IdentityHashMap; +import java.util.Map; +import java.util.Set; + +/** Records test-time scope and continuation lifecycles and reports leaks. */ +public final class ScopeDiagnostics { + private static final int DEFAULT_MAX_FRAMES = 6; + private static final long DEFAULT_QUIESCENCE_TIMEOUT_MILLIS = 250; + + private static final ScopeDiagnostics INSTANCE = new ScopeDiagnostics(); + + /** Linearizes event admission, stop/reset, and report snapshots. */ + private final Object lifecycleLock = new Object(); + + private final Map records = new IdentityHashMap<>(); + private final Map scopeRecords = new IdentityHashMap<>(); + private final Set deferredCleanupScopes = + Collections.newSetFromMap(new IdentityHashMap()); + private final Map rootWrittenNanos = new HashMap<>(); + private final Set resolved = + Collections.newSetFromMap(new IdentityHashMap()); + private long seq; + private long scopeSeq; + private boolean recording; + private StackFilter stackFilter = new StackFilter(DEFAULT_MAX_FRAMES); + + private final Listener listener = new Listener(); + + private ScopeDiagnostics() {} + + /** Clears any prior data and starts recording with the default stack depth. */ + public static void startRecording() { + startRecording(DEFAULT_MAX_FRAMES); + } + + /** Clears any prior data and starts recording, keeping up to {@code maxFrames} per stack. */ + public static void startRecording(int maxFrames) { + ScopeContinuationProbe.disable(); + synchronized (INSTANCE.lifecycleLock) { + INSTANCE.recording = false; + INSTANCE.clear(); + INSTANCE.stackFilter = new StackFilter(maxFrames); + } + ScopeContinuationProbe.enable(); + synchronized (INSTANCE.lifecycleLock) { + INSTANCE.recording = true; + } + } + + /** Stops recording (the probe goes inert). Recorded data remains queryable until reset. */ + public static void stop() { + ScopeContinuationProbe.disable(); + synchronized (INSTANCE.lifecycleLock) { + INSTANCE.recording = false; + } + } + + /** Discards all recorded data. */ + public static void reset() { + ScopeContinuationProbe.disable(); + synchronized (INSTANCE.lifecycleLock) { + INSTANCE.recording = false; + INSTANCE.clear(); + } + } + + /** Returns an immutable snapshot of the events recorded so far. */ + public static ScopeDiagnosticsReport report() { + synchronized (INSTANCE.lifecycleLock) { + return INSTANCE.snapshot(); + } + } + + /** Gives asynchronous cleanup a bounded opportunity to resolve lifecycles still in flight. */ + public static void awaitQuiescence() { + long deadline = System.nanoTime() + DEFAULT_QUIESCENCE_TIMEOUT_MILLIS * 1_000_000L; + synchronized (INSTANCE.lifecycleLock) { + while (INSTANCE.recording && INSTANCE.snapshot().hasIncompleteLifecycles()) { + long remaining = deadline - System.nanoTime(); + if (remaining <= 0) { + return; + } + try { + long millis = remaining / 1_000_000L; + int nanos = (int) (remaining % 1_000_000L); + INSTANCE.lifecycleLock.wait(millis, nanos); + } catch (InterruptedException interrupted) { + Thread.currentThread().interrupt(); + return; + } + } + } + } + + /** + * Fails with an {@link AssertionError} (carrying the problem summary) if the report flags a + * genuine bug (see {@link ScopeDiagnosticsReport#hasProblems()}). Report-only signals such as + * late-after-root and close-on-wrong-thread do not fail. + */ + public static void assertNoLeaks() { + assertNoLeaks(report()); + } + + /** Fails using the supplied snapshot, so rendering and assertion examine the same events. */ + public static void assertNoLeaks(ScopeDiagnosticsReport report) { + if (report.hasProblems()) { + throw new AssertionError("Scope continuation problems detected:\n" + report.renderSummary()); + } + } + + /** Resolves the default-on policy and rejects opt-outs without a reason. */ + public static boolean isEnabled(TrackScopeContinuations config) { + if (config == null || config.enabled()) { + return true; + } + if (config.reason().trim().isEmpty()) { + throw new IllegalArgumentException( + "@TrackScopeContinuations(enabled = false) requires a reason"); + } + return false; + } + + private void clear() { + records.clear(); + scopeRecords.clear(); + deferredCleanupScopes.clear(); + rootWrittenNanos.clear(); + resolved.clear(); + seq = 0; + scopeSeq = 0; + } + + private ScopeDiagnosticsReport snapshot() { + return new ScopeDiagnosticsReport( + new ArrayList<>(records.values()), + new ArrayList<>(scopeRecords.values()), + new HashMap<>(rootWrittenNanos)); + } + + private static final StackTraceElement[] NO_STACK = new StackTraceElement[0]; + + private ScopeEvent event(ScopeEvent.Type type) { + return event(type, System.nanoTime()); + } + + /** Uses the supplied event time while capturing the thread and stack at the call site. */ + private ScopeEvent event(ScopeEvent.Type type, long nanos) { + // Avoid stack walking when call sites are disabled because it perturbs recorded timings. + StackFilter filter = stackFilter; + StackTraceElement[] stack = + filter.maxFrames() <= 0 ? NO_STACK : filter.filter(new Throwable().getStackTrace()); + ScopeEvent event = new ScopeEvent(type, Thread.currentThread().getName(), nanos, stack); + lifecycleLock.notifyAll(); + return event; + } + + static void recordCapture( + ContextContinuation id, DDTraceId traceId, long spanId, String spanName, byte source) { + synchronized (INSTANCE.lifecycleLock) { + if (INSTANCE.recording) { + INSTANCE.listener.onCapture(id, traceId, spanId, spanName, source); + } + } + } + + static void recordActivate( + ContextContinuation id, + DDTraceId traceId, + long spanId, + String spanName, + byte source, + long nanos) { + synchronized (INSTANCE.lifecycleLock) { + if (INSTANCE.recording) { + INSTANCE.listener.onActivate(id, traceId, spanId, spanName, source, nanos); + } + } + } + + static void recordActivateFailed(ContextContinuation id) { + synchronized (INSTANCE.lifecycleLock) { + if (INSTANCE.recording) { + INSTANCE.listener.onActivateFailed(id); + } + } + } + + static void recordResolve( + ContextContinuation id, boolean cancelled, long resolveNanos, boolean alreadyResolved) { + synchronized (INSTANCE.lifecycleLock) { + if (INSTANCE.recording && (alreadyResolved || INSTANCE.resolved.add(id))) { + INSTANCE.listener.onResolve(id, cancelled, resolveNanos); + } + } + } + + static void recordRootWritten(DDTraceId traceId) { + synchronized (INSTANCE.lifecycleLock) { + if (INSTANCE.recording) { + INSTANCE.listener.onRootWritten(traceId); + } + } + } + + static void recordScopeOpen( + Object scope, + DDTraceId traceId, + long spanId, + String spanName, + byte source, + ContextContinuation continuation) { + synchronized (INSTANCE.lifecycleLock) { + if (INSTANCE.recording) { + INSTANCE.listener.onScopeOpen(scope, traceId, spanId, spanName, source, continuation); + } + } + } + + static void recordScopeClose(Object scope) { + synchronized (INSTANCE.lifecycleLock) { + if (INSTANCE.recording) { + INSTANCE.listener.onScopeClose(scope); + } + } + } + + static void recordScopeCloseWrongThread(Object scope) { + synchronized (INSTANCE.lifecycleLock) { + if (INSTANCE.recording) { + INSTANCE.listener.onScopeCloseWrongThread(scope); + } + } + } + + static void recordDeferredScopeCleanup(Object scope) { + synchronized (INSTANCE.lifecycleLock) { + if (INSTANCE.recording) { + INSTANCE.listener.onDeferredScopeCleanup(scope); + } + } + } + + private final class Listener { + void onCapture( + ContextContinuation id, DDTraceId traceId, long spanId, String spanName, byte source) { + try { + ContinuationRecord record = + new ContinuationRecord( + seq++, traceId, spanId, spanName, source, false, event(ScopeEvent.Type.CAPTURE)); + records.put(id, record); + } catch (Throwable ignored) { + // diagnostics must never disturb the tracer + } + } + + void onActivate( + ContextContinuation id, + DDTraceId traceId, + long spanId, + String spanName, + byte source, + long nanos) { + try { + recordFor(id, traceId, spanId, spanName, source) + .addResume(event(ScopeEvent.Type.ACTIVATE, nanos)); + } catch (Throwable ignored) { + } + } + + void onActivateFailed(ContextContinuation id) { + try { + ContinuationRecord record = records.get(id); + // only an activation of an already-resolved continuation is a real failure; a plain + // rollback (e.g. cancelled before any capture was recorded) is benign and ignored + if (record != null && record.isResolved()) { + record.addFailedActivation(event(ScopeEvent.Type.ACTIVATE_FAILED)); + } + } catch (Throwable ignored) { + } + } + + void onResolve(ContextContinuation id, boolean cancelled, long resolveNanos) { + try { + ScopeEvent.Type type = + cancelled ? ScopeEvent.Type.RESOLVE_CANCEL : ScopeEvent.Type.RESOLVE_FINISH; + recordFor(id, DDTraceId.ZERO, 0, null, (byte) -1) + .setTerminalOrExtra(event(type, resolveNanos)); + } catch (Throwable ignored) { + } + } + + void onRootWritten(DDTraceId traceId) { + try { + rootWrittenNanos.putIfAbsent(traceId, System.nanoTime()); + } catch (Throwable ignored) { + } + } + + void onScopeOpen( + Object scope, + DDTraceId traceId, + long spanId, + String spanName, + byte source, + ContextContinuation continuation) { + try { + if (scopeRecords.containsKey(scope)) { + return; // re-activation of an already-open scope, not a new open + } + ContinuationRecord owner = continuation != null ? records.get(continuation) : null; + Long continuationSeq = owner != null ? owner.seq : null; + long s = scopeSeq++; + scopeRecords.put( + scope, + new ScopeRecord( + s, + traceId, + spanId, + spanName, + source, + continuationSeq, + deferredCleanupScopes.remove(scope), + event(ScopeEvent.Type.SCOPE_OPEN))); + if (owner != null) { + owner.linkScope(s); + } + } catch (Throwable ignored) { + } + } + + void onScopeClose(Object scope) { + try { + ScopeRecord record = scopeRecords.get(scope); + if (record != null) { + record.setClose(event(ScopeEvent.Type.SCOPE_CLOSE)); + } + } catch (Throwable ignored) { + } + } + + void onScopeCloseWrongThread(Object scope) { + try { + ScopeRecord record = scopeRecords.get(scope); + if (record != null) { + record.addWrongThreadClose(event(ScopeEvent.Type.SCOPE_CLOSE_WRONG_THREAD)); + } + } catch (Throwable ignored) { + } + } + + void onDeferredScopeCleanup(Object scope) { + try { + ScopeRecord record = scopeRecords.get(scope); + if (record != null) { + record.markDeferredCleanup(); + } else { + deferredCleanupScopes.add(scope); + } + } catch (Throwable ignored) { + } + } + + /** Returns the record for an id, creating an orphan record if capture was not observed. */ + private ContinuationRecord recordFor( + ContextContinuation id, DDTraceId traceId, long spanId, String spanName, byte source) { + ContinuationRecord existing = records.get(id); + if (existing != null) { + return existing; + } + ContinuationRecord orphan = + new ContinuationRecord(seq++, traceId, spanId, spanName, source, true, null); + records.put(id, orphan); + return orphan; + } + } +} diff --git a/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeDiagnosticsExtension.java b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeDiagnosticsExtension.java new file mode 100644 index 00000000000..7ba889284d0 --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeDiagnosticsExtension.java @@ -0,0 +1,58 @@ +package datadog.trace.agent.test.scopediag; + +import java.lang.reflect.AnnotatedElement; +import java.util.Optional; +import org.junit.jupiter.api.extension.AfterEachCallback; +import org.junit.jupiter.api.extension.BeforeEachCallback; +import org.junit.jupiter.api.extension.ExtensionContext; +import org.junit.platform.commons.support.AnnotationSupport; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +/** Runs {@link ScopeDiagnostics} around each JUnit instrumentation test. */ +public final class ScopeDiagnosticsExtension implements BeforeEachCallback, AfterEachCallback { + private static final Logger log = LoggerFactory.getLogger(ScopeDiagnosticsExtension.class); + + @Override + public void beforeEach(ExtensionContext context) { + TrackScopeContinuations config = resolve(context); + if (ScopeDiagnostics.isEnabled(config)) { + ScopeDiagnostics.startRecording(); + } + } + + @Override + public void afterEach(ExtensionContext context) { + TrackScopeContinuations config = resolve(context); + if (!ScopeDiagnostics.isEnabled(config)) { + return; + } + try { + ScopeDiagnostics.awaitQuiescence(); + ScopeDiagnostics.stop(); + ScopeDiagnosticsReport report = ScopeDiagnostics.report(); + if (report.hasFindings()) { + log.info("[{}] {}", context.getDisplayName(), report.renderTimeline()); + } + ScopeDiagnostics.assertNoLeaks(report); + } finally { + ScopeDiagnostics.reset(); + } + } + + /** Resolves method configuration before inherited class configuration. */ + private static TrackScopeContinuations resolve(ExtensionContext context) { + Optional element = context.getElement(); + if (element.isPresent()) { + Optional onElement = + AnnotationSupport.findAnnotation(element.get(), TrackScopeContinuations.class); + if (onElement.isPresent()) { + return onElement.get(); + } + } + return context + .getTestClass() + .flatMap(c -> AnnotationSupport.findAnnotation(c, TrackScopeContinuations.class)) + .orElse(null); + } +} diff --git a/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeDiagnosticsReport.java b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeDiagnosticsReport.java new file mode 100644 index 00000000000..d7e3c56595a --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeDiagnosticsReport.java @@ -0,0 +1,372 @@ +package datadog.trace.agent.test.scopediag; + +import datadog.trace.api.DDTraceId; +import java.util.ArrayList; +import java.util.EnumSet; +import java.util.LinkedHashMap; +import java.util.List; +import java.util.Map; + +/** Immutable scope and continuation lifecycle snapshot with derived failures. */ +public final class ScopeDiagnosticsReport { + private final List continuations; + private final List scopes; + private final long t0; + private final Map> continuationFailures; + private final Map> scopeFailures; + private final Map scopeBySeq; + + ScopeDiagnosticsReport( + List continuations, + List scopes, + Map rootWrittenNanos) { + this.continuations = new ArrayList<>(continuations.size()); + for (ContinuationRecord continuation : continuations) { + this.continuations.add(continuation.snapshot()); + } + this.continuations.sort((a, b) -> Long.compare(a.firstNanos(), b.firstNanos())); + this.scopes = new ArrayList<>(scopes.size()); + for (ScopeRecord scope : scopes) { + this.scopes.add(scope.snapshot()); + } + this.scopes.sort((a, b) -> Long.compare(a.firstNanos(), b.firstNanos())); + this.t0 = computeT0(this.continuations, this.scopes); + this.continuationFailures = classifyContinuations(this.continuations, rootWrittenNanos); + this.scopeFailures = classifyScopes(this.scopes); + this.scopeBySeq = new LinkedHashMap<>(); + for (ScopeRecord s : this.scopes) { + scopeBySeq.put(s.seq, s); + } + } + + private static long computeT0(List continuations, List scopes) { + long min = Long.MAX_VALUE; + for (ContinuationRecord r : continuations) { + min = Math.min(min, r.firstNanos()); + } + for (ScopeRecord s : scopes) { + min = Math.min(min, s.firstNanos()); + } + return min == Long.MAX_VALUE ? 0 : min; + } + + private static Map> classifyContinuations( + List records, Map rootWrittenNanos) { + Map> result = new LinkedHashMap<>(); + for (ContinuationRecord r : records) { + EnumSet failures = r.failures(rootWrittenNanos.get(r.traceId)); + if (!failures.isEmpty()) { + result.put(r, failures); + } + } + return result; + } + + private static Map> classifyScopes(List scopes) { + Map> result = new LinkedHashMap<>(); + for (ScopeRecord s : scopes) { + EnumSet failures = s.failures(); + if (!failures.isEmpty()) { + result.put(s, failures); + } + } + return result; + } + + public List records() { + return new ArrayList<>(continuations); + } + + public List scopeRecords() { + return new ArrayList<>(scopes); + } + + public Map> findings() { + return new LinkedHashMap<>(continuationFailures); + } + + public Map> scopeFindings() { + return new LinkedHashMap<>(scopeFailures); + } + + public int leakCount() { + return countWith(continuationFailures, Failure.LEAKED); + } + + public int lateCount() { + return countWith(continuationFailures, Failure.LATE_FINISH); + } + + public int doubleCount() { + return countWith(continuationFailures, Failure.DOUBLE_FINISH); + } + + public int activateAfterResolveCount() { + return countWith(continuationFailures, Failure.ACTIVATE_AFTER_RESOLVE); + } + + public int neverClosedScopeCount() { + return countWith(scopeFailures, Failure.NEVER_CLOSED); + } + + public int closeWrongThreadCount() { + return countWith(scopeFailures, Failure.CLOSE_WRONG_THREAD); + } + + public int deferredCleanupScopeCount() { + int count = 0; + for (ScopeRecord scope : scopes) { + if (scope.deferredCleanup() && !scope.closed()) { + count++; + } + } + return count; + } + + boolean hasIncompleteLifecycles() { + return leakCount() > 0 || neverClosedScopeCount() > 0; + } + + private static int countWith(Map> findings, Failure failure) { + int n = 0; + for (EnumSet f : findings.values()) { + if (f.contains(failure)) { + n++; + } + } + return n; + } + + /** Returns whether the report contains a failure that should fail the test. */ + public boolean hasProblems() { + return leakCount() > 0 + || doubleCount() > 0 + || activateAfterResolveCount() > 0 + || neverClosedScopeCount() > 0; + } + + /** True when the report contains either a failing problem or an advisory signal. */ + public boolean hasFindings() { + return !continuationFailures.isEmpty() || !scopeFailures.isEmpty(); + } + + private void appendHeader(StringBuilder sb, String title) { + sb.append(title) + .append(" (") + .append(continuations.size()) + .append(" continuations, ") + .append(scopes.size()) + .append(" scopes; ") + .append(leakCount()) + .append(" leaked, ") + .append(lateCount()) + .append(" late, ") + .append(doubleCount()) + .append(" double, ") + .append(activateAfterResolveCount()) + .append(" activate-after-resolve | scopes: ") + .append(neverClosedScopeCount()) + .append(" never-closed, ") + .append(deferredCleanupScopeCount()) + .append(" deferred, ") + .append(closeWrongThreadCount()) + .append(" wrong-thread)\n"); + } + + /** Renders flagged continuations and scopes with their call sites. */ + public String renderSummary() { + StringBuilder sb = new StringBuilder(); + appendHeader(sb, "Scope/continuation problems"); + if (continuationFailures.isEmpty() && scopeFailures.isEmpty()) { + sb.append(" (none)\n"); + return sb.toString(); + } + for (Map.Entry> e : continuationFailures.entrySet()) { + ContinuationRecord r = e.getKey(); + ScopeEvent capture = r.capture(); + sb.append(" ") + .append(e.getValue()) + .append(" #") + .append(r.seq) + .append(" trace=") + .append(r.traceId) + .append(" src=") + .append(r.sourceName()) + .append(" captured at ") + .append(capture == null || capture.callsite() == null ? "" : capture.callsite()) + .append('\n'); + } + for (Map.Entry> e : scopeFailures.entrySet()) { + ScopeRecord s = e.getKey(); + ScopeEvent open = s.open(); + sb.append(" ") + .append(e.getValue()) + .append(" scope#") + .append(s.seq) + .append(" trace=") + .append(s.traceId) + .append(" src=") + .append(s.sourceName()) + .append(" opened at ") + .append(open == null || open.callsite() == null ? "" : open.callsite()) + .append('\n'); + } + return sb.toString(); + } + + private static final int TIMELINE_FRAMES = 3; + + /** Renders all events with relative times, threads, call sites, and linked scopes. */ + public String renderTimeline() { + StringBuilder sb = new StringBuilder(); + appendHeader(sb, "Scope/continuation timeline"); + if (continuations.isEmpty() && scopes.isEmpty()) { + sb.append(" (nothing captured)\n"); + return sb.toString(); + } + + for (ContinuationRecord r : continuations) { + EnumSet failures = + continuationFailures.getOrDefault(r, EnumSet.noneOf(Failure.class)); + sb.append("\n#") + .append(r.seq) + .append(' ') + .append(r.status()) + .append(" trace=") + .append(r.traceId) + .append(" span=") + .append(r.spanId); + if (r.spanName != null) { + sb.append(" \"").append(r.spanName).append('"'); + } + sb.append(" src=").append(r.sourceName()); + if (r.orphan) { + sb.append(" [ORPHAN]"); + } + if (r.threadHandoff()) { + sb.append(" [handoff]"); + } + if (!failures.isEmpty()) { + sb.append(' ').append(failures); + } + sb.append(timing(r)).append('\n'); + + appendEvent(sb, "capture ", r.capture()); + for (ScopeEvent a : r.resumes()) { + appendEvent(sb, "resume ", a); + } + for (ScopeEvent f : r.failedActivations()) { + appendEvent(sb, "act-fail", f); + } + ScopeEvent terminal = r.terminal(); + if (terminal != null) { + appendEvent( + sb, + terminal.type == ScopeEvent.Type.RESOLVE_CANCEL ? "cancel " : "finish ", + terminal); + } + for (ScopeEvent extra : r.extraTerminals()) { + appendEvent(sb, "DOUBLE ", extra); + } + for (long scopeSeq : r.scopeRecordSeqs()) { + ScopeRecord scope = scopeBySeq.get(scopeSeq); + if (scope != null) { + appendScopeLine(sb, " ", scope); + } + } + if (terminal == null) { + sb.append(" LEAKED (never finished or cancelled)\n"); + } + } + + List orphanScopes = new ArrayList<>(); + for (ScopeRecord s : scopes) { + if (s.continuationSeq == null) { + orphanScopes.add(s); + } + } + if (!orphanScopes.isEmpty()) { + sb.append("\nNon-continuation scopes:\n"); + for (ScopeRecord s : orphanScopes) { + appendScopeLine(sb, " ", s); + } + } + return sb.toString(); + } + + private String timing(ContinuationRecord r) { + StringBuilder sb = new StringBuilder(); + Long capToResume = r.captureToFirstResumeNanos(); + Long age = r.ageAtTerminalNanos(); + if (capToResume != null) { + sb.append(" cap->resume=").append(millis(capToResume)).append("ms"); + } + if (age != null) { + sb.append(" age=").append(millis(age)).append("ms"); + } + return sb.toString(); + } + + private void appendScopeLine(StringBuilder sb, String indent, ScopeRecord scope) { + EnumSet failures = scopeFailures.getOrDefault(scope, EnumSet.noneOf(Failure.class)); + sb.append(indent).append("scope#").append(scope.seq).append(' ').append(scope.sourceName()); + if (scope.spanName != null) { + sb.append(" \"").append(scope.spanName).append('"'); + } + ScopeEvent open = scope.open(); + ScopeEvent close = scope.close(); + if (open != null) { + sb.append(" open +").append(relMillis(open.nanos)).append("ms @ ").append(open.threadName); + } + if (close != null) { + sb.append(" close +") + .append(relMillis(close.nanos)) + .append("ms @ ") + .append(close.threadName); + Long active = scope.activeDurationNanos(); + if (active != null) { + sb.append(" (active ").append(millis(active)).append("ms)"); + } + } + if (scope.threadHandoff()) { + sb.append(" [handoff]"); + } + if (scope.deferredCleanup() && !scope.closed()) { + sb.append(" [deferred-cleanup]"); + } + if (!failures.isEmpty()) { + sb.append(' ').append(failures); + } + sb.append('\n'); + } + + private void appendEvent(StringBuilder sb, String label, ScopeEvent event) { + if (event == null) { + sb.append(" ").append(label).append(" (not observed)\n"); + return; + } + sb.append(" ") + .append(label) + .append(" +") + .append(relMillis(event.nanos)) + .append("ms @ ") + .append(event.threadName) + .append(" at ") + .append(event.callsite() == null ? "" : event.callsite()) + .append('\n'); + StackTraceElement[] stack = event.stack; + if (stack != null) { + for (int i = 1; i < stack.length && i < TIMELINE_FRAMES; i++) { + sb.append(" from ").append(stack[i]).append('\n'); + } + } + } + + private String relMillis(long nanos) { + return String.format("%.3f", (nanos - t0) / 1_000_000.0); + } + + private static String millis(long nanos) { + return String.format("%.3f", nanos / 1_000_000.0); + } +} diff --git a/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeEvent.java b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeEvent.java new file mode 100644 index 00000000000..c1b77c461e5 --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeEvent.java @@ -0,0 +1,38 @@ +package datadog.trace.agent.test.scopediag; + +/** A timestamped scope or continuation lifecycle event with its thread and call site. */ +public final class ScopeEvent { + public enum Type { + CAPTURE, + ACTIVATE, + /** An {@code activate()} that returned the noop scope after the continuation was resolved. */ + ACTIVATE_FAILED, + RESOLVE_FINISH, + RESOLVE_CANCEL, + SCOPE_OPEN, + SCOPE_CLOSE, + /** A scope was closed while not on top of its thread's stack. */ + SCOPE_CLOSE_WRONG_THREAD + } + + public final Type type; + public final String threadName; + public final long nanos; + public final StackTraceElement[] stack; + + ScopeEvent(Type type, String threadName, long nanos, StackTraceElement[] stack) { + this.type = type; + this.threadName = threadName; + this.nanos = nanos; + this.stack = stack; + } + + ScopeEvent snapshot() { + return new ScopeEvent(type, threadName, nanos, stack == null ? null : stack.clone()); + } + + /** The most relevant (top, post-filter) frame, or {@code null} if none survived filtering. */ + public StackTraceElement callsite() { + return stack != null && stack.length > 0 ? stack[0] : null; + } +} diff --git a/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeRecord.java b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeRecord.java new file mode 100644 index 00000000000..6d1e1d66116 --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeRecord.java @@ -0,0 +1,133 @@ +package datadog.trace.agent.test.scopediag; + +import datadog.trace.api.DDTraceId; +import java.util.ArrayList; +import java.util.EnumSet; +import java.util.List; + +/** Records a scope's activation and close events. */ +public final class ScopeRecord { + public final long seq; + public final DDTraceId traceId; + public final long spanId; + public final String spanName; + public final byte source; + + /** The continuation that spawned this scope, or {@code null} for a plain activation. */ + public final Long continuationSeq; + + private final ScopeEvent open; + private ScopeEvent close; + private boolean deferredCleanup; + private final List wrongThreadCloses = new ArrayList<>(0); + + ScopeRecord( + long seq, + DDTraceId traceId, + long spanId, + String spanName, + byte source, + Long continuationSeq, + boolean deferredCleanup, + ScopeEvent open) { + this.seq = seq; + this.traceId = traceId; + this.spanId = spanId; + this.spanName = spanName; + this.source = source; + this.continuationSeq = continuationSeq; + this.deferredCleanup = deferredCleanup; + this.open = open; + } + + synchronized void setClose(ScopeEvent event) { + if (close == null) { + close = event; + } + } + + synchronized void addWrongThreadClose(ScopeEvent event) { + wrongThreadCloses.add(event); + } + + synchronized ScopeRecord snapshot() { + ScopeRecord copy = + new ScopeRecord( + seq, + traceId, + spanId, + spanName, + source, + continuationSeq, + deferredCleanup, + open == null ? null : open.snapshot()); + copy.close = close == null ? null : close.snapshot(); + for (ScopeEvent event : wrongThreadCloses) { + copy.wrongThreadCloses.add(event.snapshot()); + } + return copy; + } + + public synchronized ScopeEvent open() { + return open; + } + + public synchronized ScopeEvent close() { + return close; + } + + public synchronized List wrongThreadCloses() { + return new ArrayList<>(wrongThreadCloses); + } + + public synchronized boolean closed() { + return close != null; + } + + synchronized void markDeferredCleanup() { + deferredCleanup = true; + } + + public synchronized boolean deferredCleanup() { + return deferredCleanup; + } + + /** {@code true} when the scope was opened and closed on different threads. */ + public synchronized boolean threadHandoff() { + return open != null && close != null && !open.threadName.equals(close.threadName); + } + + /** Nanos the scope was active, or {@code null} if it was never closed. */ + public synchronized Long activeDurationNanos() { + if (open == null || close == null) { + return null; + } + return close.nanos - open.nanos; + } + + public synchronized EnumSet failures() { + EnumSet failures = EnumSet.noneOf(Failure.class); + if (open != null && close == null && !deferredCleanup) { + failures.add(Failure.NEVER_CLOSED); + } + if (!wrongThreadCloses.isEmpty()) { + failures.add(Failure.CLOSE_WRONG_THREAD); + } + return failures; + } + + public synchronized long firstNanos() { + long min = open != null ? open.nanos : Long.MAX_VALUE; + if (close != null) { + min = Math.min(min, close.nanos); + } + for (ScopeEvent e : wrongThreadCloses) { + min = Math.min(min, e.nanos); + } + return min; + } + + public String sourceName() { + return ScopeSources.name(source); + } +} diff --git a/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeSources.java b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeSources.java new file mode 100644 index 00000000000..f152c11ac39 --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeSources.java @@ -0,0 +1,21 @@ +package datadog.trace.agent.test.scopediag; + +/** Maps package-private {@code ContinuableScope} source values to readable names. */ +final class ScopeSources { + private ScopeSources() {} + + static String name(byte source) { + switch (source) { + case 0: + return "INSTRUMENTATION"; + case 1: + return "MANUAL"; + case 2: + return "ITERATION"; + case 3: + return "CONTEXT"; + default: + return "UNKNOWN(" + source + ")"; + } + } +} diff --git a/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeStackAdvice.java b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeStackAdvice.java new file mode 100644 index 00000000000..1b6bef31bae --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeStackAdvice.java @@ -0,0 +1,15 @@ +package datadog.trace.agent.test.scopediag; + +import net.bytebuddy.asm.Advice; + +/** Test-only advice for scopes added to the active stack. */ +public final class ScopeStackAdvice { + private ScopeStackAdvice() {} + + public static final class Push { + @Advice.OnMethodEnter(suppress = Throwable.class) + public static void enter(@Advice.Argument(0) Object scope) { + ScopeContinuationProbe.onScopeOpen(scope); + } + } +} diff --git a/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/StackFilter.java b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/StackFilter.java new file mode 100644 index 00000000000..e2e735a850e --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/StackFilter.java @@ -0,0 +1,67 @@ +package datadog.trace.agent.test.scopediag; + +import java.util.ArrayList; +import java.util.List; + +/** Removes diagnostic and runtime plumbing from captured call stacks. */ +final class StackFilter { + private static final String[] DROP_PREFIXES = { + "datadog.trace.agent.test.scopediag.", + "datadog.trace.core.", + "datadog.trace.bootstrap.instrumentation.java.concurrent.", + "datadog.trace.bootstrap.instrumentation.api.", + "datadog.trace.bootstrap.InstrumentationContext", + "java.lang.Thread.getStackTrace", + "java.util.concurrent.ThreadPoolExecutor", + "java.util.concurrent.ScheduledThreadPoolExecutor", + "java.util.concurrent.ForkJoinPool", + "java.util.concurrent.ForkJoinWorkerThread", + "java.util.concurrent.Executors$", + "java.util.concurrent.FutureTask", + "java.util.concurrent.CompletableFuture", + "jdk.internal.reflect.", + "java.lang.reflect.", + "sun.reflect.", + "org.spockframework.mock.", + "org.codehaus.groovy.", + "groovy.lang.", + "net.bytebuddy.", + }; + + private final int maxFrames; + + StackFilter(int maxFrames) { + this.maxFrames = maxFrames; + } + + int maxFrames() { + return maxFrames; + } + + StackTraceElement[] filter(StackTraceElement[] raw) { + if (raw == null) { + return new StackTraceElement[0]; + } + List kept = new ArrayList<>(maxFrames); + for (StackTraceElement frame : raw) { + if (isDropped(frame)) { + continue; + } + kept.add(frame); + if (kept.size() >= maxFrames) { + break; + } + } + return kept.toArray(new StackTraceElement[0]); + } + + private static boolean isDropped(StackTraceElement frame) { + String fqn = frame.getClassName() + "." + frame.getMethodName(); + for (String prefix : DROP_PREFIXES) { + if (fqn.startsWith(prefix) || frame.getClassName().startsWith(prefix)) { + return true; + } + } + return false; + } +} diff --git a/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/TrackScopeContinuations.java b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/TrackScopeContinuations.java new file mode 100644 index 00000000000..dcef5bb15a3 --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/TrackScopeContinuations.java @@ -0,0 +1,19 @@ +package datadog.trace.agent.test.scopediag; + +import java.lang.annotation.ElementType; +import java.lang.annotation.Inherited; +import java.lang.annotation.Retention; +import java.lang.annotation.RetentionPolicy; +import java.lang.annotation.Target; + +/** Configures the default-on scope and continuation diagnostic for a test class or method. */ +@Retention(RetentionPolicy.RUNTIME) +@Target({ElementType.TYPE, ElementType.METHOD}) +@Inherited +public @interface TrackScopeContinuations { + /** Set to {@code false} only for a proven incompatibility with the diagnostic itself. */ + boolean enabled() default true; + + /** Explains why the diagnostic is disabled. Required when {@link #enabled()} is false. */ + String reason() default ""; +} diff --git a/dd-java-agent/instrumentation-testing/src/test/java/datadog/trace/agent/test/scopediag/ScopeContinuationProbeTest.java b/dd-java-agent/instrumentation-testing/src/test/java/datadog/trace/agent/test/scopediag/ScopeContinuationProbeTest.java new file mode 100644 index 00000000000..3752b466af1 --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/test/java/datadog/trace/agent/test/scopediag/ScopeContinuationProbeTest.java @@ -0,0 +1,90 @@ +package datadog.trace.agent.test.scopediag; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertNotNull; +import static org.junit.jupiter.api.Assertions.assertTrue; + +import java.lang.reflect.Field; +import java.lang.reflect.Method; +import org.junit.jupiter.api.Test; + +/** Verifies the tracer internals used by {@link ScopeContinuationProbe}. */ +class ScopeContinuationProbeTest { + + @Test + void cancelledSentinelMatchesProduction() throws Exception { + assertEquals(Integer.MIN_VALUE >> 1, ScopeContinuationProbe.CANCELLED); + + Class scopeContinuation = Class.forName("datadog.trace.core.scopemanager.ScopeContinuation"); + Field cancelled = scopeContinuation.getDeclaredField("CANCELLED"); + cancelled.setAccessible(true); + assertEquals( + cancelled.getInt(null), + ScopeContinuationProbe.CANCELLED, + "ScopeContinuationProbe.CANCELLED is out of sync with ScopeContinuation.CANCELLED"); + } + + @Test + void continuationHooksExist() throws Exception { + Class scopeContinuation = Class.forName("datadog.trace.core.scopemanager.ScopeContinuation"); + assertNotNull(scopeContinuation.getDeclaredMethod("register"), "register() (capture)"); + assertNotNull(scopeContinuation.getDeclaredMethod("resume"), "resume()"); + assertNotNull(scopeContinuation.getDeclaredMethod("release"), "release() (resolve)"); + assertNotNull( + scopeContinuation.getDeclaredMethod("cancelFromContinuedScopeClose"), + "cancelFromContinuedScopeClose() (resolve)"); + assertNotNull(findField(scopeContinuation, "count"), "ScopeContinuation.count"); + assertNotNull(findField(scopeContinuation, "source"), "ScopeContinuation.source"); + } + + @Test + void rootWrittenHookExists() throws Exception { + Class pendingTrace = Class.forName("datadog.trace.core.PendingTrace"); + assertNotNull( + pendingTrace.getDeclaredMethod("write", boolean.class), "PendingTrace.write(boolean)"); + assertNotNull(findField(pendingTrace, "rootSpanWritten"), "PendingTrace.rootSpanWritten"); + assertNotNull(findField(pendingTrace, "traceId"), "PendingTrace.traceId"); + } + + @Test + void scopeLifecycleHooksExist() throws Exception { + Class scope = Class.forName("datadog.trace.core.scopemanager.ContinuableScope"); + assertNotNull(scope.getDeclaredMethod("afterActivated"), "afterActivated() (scope open)"); + assertNotNull(scope.getDeclaredMethod("onProperClose"), "onProperClose() (scope close)"); + assertNotNull(scope.getDeclaredMethod("close"), "close() (wrong-thread check)"); + assertNotNull(findField(scope, "source"), "ContinuableScope.source"); + + Class continuing = Class.forName("datadog.trace.core.scopemanager.ContinuingScope"); + assertNotNull( + continuing.getDeclaredField("continuation"), "ContinuingScope.continuation (scope link)"); + } + + @Test + void wrongThreadCheckChainExists() throws Exception { + Class scope = Class.forName("datadog.trace.core.scopemanager.ContinuableScope"); + assertNotNull(findField(scope, "scopeManager"), "ContinuableScope.scopeManager"); + Class manager = Class.forName("datadog.trace.core.scopemanager.ContinuableScopeManager"); + assertNotNull(manager.getDeclaredMethod("scopeStack"), "ContinuableScopeManager.scopeStack()"); + Class stack = Class.forName("datadog.trace.core.scopemanager.ScopeStack"); + assertTrue(hasMethod(stack, "checkTop", 1), "ScopeStack.checkTop(scope)"); + } + + private static Field findField(Class cls, String name) { + for (Class c = cls; c != null; c = c.getSuperclass()) { + try { + return c.getDeclaredField(name); + } catch (NoSuchFieldException ignored) { + } + } + return null; + } + + private static boolean hasMethod(Class cls, String name, int params) { + for (Method m : cls.getDeclaredMethods()) { + if (m.getName().equals(name) && m.getParameterCount() == params) { + return true; + } + } + return false; + } +} diff --git a/dd-java-agent/instrumentation-testing/src/test/java/datadog/trace/agent/test/scopediag/ScopeDiagnosticsConfigurationTest.java b/dd-java-agent/instrumentation-testing/src/test/java/datadog/trace/agent/test/scopediag/ScopeDiagnosticsConfigurationTest.java new file mode 100644 index 00000000000..2b0ada14e7a --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/test/java/datadog/trace/agent/test/scopediag/ScopeDiagnosticsConfigurationTest.java @@ -0,0 +1,36 @@ +package datadog.trace.agent.test.scopediag; + +import static org.junit.jupiter.api.Assertions.assertFalse; +import static org.junit.jupiter.api.Assertions.assertThrows; +import static org.junit.jupiter.api.Assertions.assertTrue; + +import org.junit.jupiter.api.Test; + +class ScopeDiagnosticsConfigurationTest { + + @TrackScopeContinuations(enabled = false) + private static class UndocumentedOptOut {} + + @TrackScopeContinuations(enabled = false, reason = "incompatible synthetic tracer") + private static class DocumentedOptOut {} + + @Test + void diagnosticsAreEnabledByDefault() { + assertTrue(ScopeDiagnostics.isEnabled(null)); + } + + @Test + void documentedOptOutDisablesDiagnostics() { + assertFalse( + ScopeDiagnostics.isEnabled( + DocumentedOptOut.class.getAnnotation(TrackScopeContinuations.class))); + } + + @Test + void undocumentedOptOutIsRejected() { + TrackScopeContinuations config = + UndocumentedOptOut.class.getAnnotation(TrackScopeContinuations.class); + + assertThrows(IllegalArgumentException.class, () -> ScopeDiagnostics.isEnabled(config)); + } +} diff --git a/dd-java-agent/instrumentation-testing/src/test/java/datadog/trace/agent/test/scopediag/ScopeDiagnosticsIntegrationTest.java b/dd-java-agent/instrumentation-testing/src/test/java/datadog/trace/agent/test/scopediag/ScopeDiagnosticsIntegrationTest.java new file mode 100644 index 00000000000..89a4af142bd --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/test/java/datadog/trace/agent/test/scopediag/ScopeDiagnosticsIntegrationTest.java @@ -0,0 +1,236 @@ +package datadog.trace.agent.test.scopediag; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertFalse; +import static org.junit.jupiter.api.Assertions.assertNotNull; +import static org.junit.jupiter.api.Assertions.assertTrue; + +import datadog.context.Context; +import datadog.context.ContextContinuation; +import datadog.context.ContextScope; +import datadog.trace.bootstrap.instrumentation.api.AgentScope; +import datadog.trace.bootstrap.instrumentation.api.AgentSpan; +import datadog.trace.common.writer.ListWriter; +import datadog.trace.core.CoreTracer; +import java.util.List; +import java.util.concurrent.CountDownLatch; +import java.util.concurrent.TimeUnit; +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.Test; + +/** Exercises diagnostics against continuations created by a real {@link CoreTracer}. */ +class ScopeDiagnosticsIntegrationTest { + + private CoreTracer tracer; + + @AfterEach + void tearDown() { + ScopeDiagnostics.stop(); + ScopeDiagnostics.reset(); + if (tracer != null) { + tracer.close(); + } + } + + @Test + void capturesRealLeakAndResolvedContinuation() { + tracer = CoreTracer.builder().writer(new ListWriter()).strictTraceWrites(false).build(); + + ScopeDiagnostics.startRecording(); + + AgentSpan span = tracer.startSpan("test", "op"); + ContextContinuation leaked = tracer.capture(span); + ContextContinuation resolved = tracer.capture(span); + resolved.release(); + + ScopeDiagnosticsReport report = ScopeDiagnostics.report(); + + assertEquals(2, report.records().size(), "both captures recorded"); + assertEquals(1, report.leakCount(), "exactly the un-resolved continuation leaks"); + assertTrue(report.hasProblems()); + assertFalse(leaked.toString().isEmpty()); + + span.finish(); + } + + @Test + void sameSpanReactivationIsNotFlaggedActivateAfterResolve() { + tracer = CoreTracer.builder().writer(new ListWriter()).strictTraceWrites(false).build(); + + ScopeDiagnostics.startRecording(); + + AgentSpan span = tracer.startSpan("test", "op"); + AgentScope active = tracer.activateSpan(span); + // Same-span reuse resolves the continuation before resume() returns. + ContextContinuation continuation = tracer.capture(span); + ContextScope reused = continuation.resume(); + reused.close(); + active.close(); + span.finish(); + + ScopeDiagnosticsReport report = ScopeDiagnostics.report(); + + assertEquals(1, report.records().size()); + assertEquals( + 0, + report.activateAfterResolveCount(), + "a same-span re-activation resolved during activate() is not activate-after-resolve"); + assertEquals(0, report.leakCount()); + assertFalse(report.hasProblems()); + } + + @Test + void resolvedContinuationDoesNotLeak() { + tracer = CoreTracer.builder().writer(new ListWriter()).strictTraceWrites(false).build(); + + ScopeDiagnostics.startRecording(); + + AgentSpan span = tracer.startSpan("test", "op"); + ContextContinuation continuation = tracer.capture(span); + ContextScope scope = continuation.resume(); + scope.close(); + span.finish(); + + ScopeDiagnosticsReport report = ScopeDiagnostics.report(); + + assertEquals(1, report.records().size()); + assertEquals(0, report.leakCount(), "activated then closed continuation is resolved"); + } + + @Test + void scopeLifetimeRecordedAndLinkedToContinuation() { + tracer = CoreTracer.builder().writer(new ListWriter()).strictTraceWrites(false).build(); + + ScopeDiagnostics.startRecording(); + + AgentSpan span = tracer.startSpan("test", "op"); + ContextContinuation continuation = tracer.capture(span); + ContextScope scope = continuation.resume(); + scope.close(); + span.finish(); + + ScopeDiagnosticsReport report = ScopeDiagnostics.report(); + + ScopeRecord linked = continuationScope(report); + assertNotNull(linked, "the resumed scope was recorded"); + assertNotNull(linked.open(), "scope open observed"); + assertTrue(linked.closed(), "scope close observed"); + assertEquals(0, report.neverClosedScopeCount()); + assertEquals(1, report.records().size()); + assertEquals(Long.valueOf(report.records().get(0).seq), linked.continuationSeq); + } + + @Test + void swappedContextDoesNotCreateCloseOwnedScope() { + tracer = CoreTracer.builder().writer(new ListWriter()).strictTraceWrites(false).build(); + + ScopeDiagnostics.startRecording(); + + AgentSpan span = tracer.startSpan("test", "op"); + Context previous = tracer.swap(span); + previous.swap(); + span.finish(); + + ScopeDiagnosticsReport report = ScopeDiagnostics.report(); + + assertEquals(0, report.neverClosedScopeCount()); + assertTrue(report.scopeRecords().isEmpty(), "stack swaps do not own scope closure"); + } + + @Test + void rootIterationScopeDelegatesCleanup() { + tracer = CoreTracer.builder().writer(new ListWriter()).strictTraceWrites(false).build(); + + ScopeDiagnostics.startRecording(); + + AgentSpan span = tracer.startSpan("test", "iteration"); + tracer.activateNext(span); + + ScopeDiagnosticsReport report = ScopeDiagnostics.report(); + assertEquals(1, report.deferredCleanupScopeCount()); + assertEquals(0, report.neverClosedScopeCount()); + assertFalse(report.hasProblems()); + + tracer.closePrevious(true); + } + + @Test + void waitsForAsynchronousScopeCleanup() throws Exception { + tracer = CoreTracer.builder().writer(new ListWriter()).strictTraceWrites(false).build(); + + ScopeDiagnostics.startRecording(); + + AgentSpan span = tracer.startSpan("test", "op"); + ContextContinuation continuation = tracer.capture(span); + CountDownLatch scopeOpened = new CountDownLatch(1); + CountDownLatch closeScope = new CountDownLatch(1); + Thread worker = + new Thread( + () -> { + try (ContextScope ignored = continuation.resume()) { + scopeOpened.countDown(); + closeScope.await(); + } catch (InterruptedException interrupted) { + Thread.currentThread().interrupt(); + } + }); + worker.start(); + + assertTrue(scopeOpened.await(5, TimeUnit.SECONDS)); + assertTrue(ScopeDiagnostics.report().hasIncompleteLifecycles()); + closeScope.countDown(); + ScopeDiagnostics.awaitQuiescence(); + worker.join(); + + ScopeDiagnosticsReport report = ScopeDiagnostics.report(); + assertFalse(report.hasIncompleteLifecycles()); + assertFalse(report.hasProblems()); + span.finish(); + } + + @Test + void neverClosedScopeIsFlagged() { + tracer = CoreTracer.builder().writer(new ListWriter()).strictTraceWrites(false).build(); + + ScopeDiagnostics.startRecording(); + + AgentSpan span = tracer.startSpan("test", "op"); + ContextContinuation continuation = tracer.capture(span); + ContextScope scope = continuation.resume(); + + ScopeDiagnosticsReport report = ScopeDiagnostics.report(); + + assertEquals(1, report.neverClosedScopeCount(), "the open scope never closed"); + assertEquals(1, report.leakCount(), "and the continuation it backs also leaks"); + assertTrue(report.hasProblems()); + + scope.close(); + span.finish(); + } + + @Test + void eventsAfterStopAreRejected() { + tracer = CoreTracer.builder().writer(new ListWriter()).strictTraceWrites(false).build(); + + ScopeDiagnostics.startRecording(); + AgentSpan span = tracer.startSpan("test", "op"); + ContextContinuation continuation = tracer.capture(span); + + ScopeDiagnostics.stop(); + continuation.release(); + ScopeDiagnosticsReport report = ScopeDiagnostics.report(); + + assertEquals(1, report.leakCount(), "the resolution happened outside the recording window"); + span.finish(); + } + + private static ScopeRecord continuationScope(ScopeDiagnosticsReport report) { + List scopes = report.scopeRecords(); + for (ScopeRecord s : scopes) { + if (s.continuationSeq != null) { + return s; + } + } + return null; + } +} diff --git a/dd-java-agent/instrumentation-testing/src/test/java/datadog/trace/agent/test/scopediag/ScopeDiagnosticsReportTest.java b/dd-java-agent/instrumentation-testing/src/test/java/datadog/trace/agent/test/scopediag/ScopeDiagnosticsReportTest.java new file mode 100644 index 00000000000..5155d563e0b --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/test/java/datadog/trace/agent/test/scopediag/ScopeDiagnosticsReportTest.java @@ -0,0 +1,174 @@ +package datadog.trace.agent.test.scopediag; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertFalse; +import static org.junit.jupiter.api.Assertions.assertTrue; + +import datadog.trace.api.DDTraceId; +import java.util.ArrayList; +import java.util.HashMap; +import java.util.List; +import java.util.Map; +import org.junit.jupiter.api.Test; + +class ScopeDiagnosticsReportTest { + + private static final StackTraceElement[] STACK = { + new StackTraceElement("com.app.Worker", "submit", "Worker.java", 42) + }; + + private static ScopeEvent event(ScopeEvent.Type type, String thread, long nanos) { + return new ScopeEvent(type, thread, nanos, STACK); + } + + private static ContinuationRecord record(long seq, DDTraceId trace) { + return new ContinuationRecord( + seq, trace, 7L, "op", (byte) 0, false, event(ScopeEvent.Type.CAPTURE, "main", 1000)); + } + + @Test + void resolvedContinuationHasNoFailures() { + ContinuationRecord r = record(0, DDTraceId.from(10)); + r.addResume(event(ScopeEvent.Type.ACTIVATE, "pool-1", 2000)); + r.setTerminalOrExtra(event(ScopeEvent.Type.RESOLVE_FINISH, "pool-1", 3000)); + + ScopeDiagnosticsReport report = report(list(r), map()); + + assertEquals(0, report.leakCount()); + assertEquals(0, report.lateCount()); + assertEquals(0, report.doubleCount()); + assertEquals(ContinuationStatus.FINISHED, r.status()); + assertTrue(r.threadHandoff()); + assertFalse(report.hasProblems()); + } + + @Test + void neverResolvedIsFlaggedAsLeak() { + ContinuationRecord r = record(0, DDTraceId.from(11)); + + ScopeDiagnosticsReport report = report(list(r), map()); + + assertEquals(1, report.leakCount()); + assertEquals(ContinuationStatus.LEAKED, r.status()); + assertTrue(report.hasProblems()); + assertTrue(report.renderSummary().contains("LEAKED")); + assertTrue(report.renderSummary().contains("Worker.java:42")); + } + + @Test + void resolutionAfterRootWriteIsFlaggedLate() { + DDTraceId trace = DDTraceId.from(12); + ContinuationRecord r = record(0, trace); + r.addResume(event(ScopeEvent.Type.ACTIVATE, "pool-1", 5000)); + r.setTerminalOrExtra(event(ScopeEvent.Type.RESOLVE_FINISH, "pool-1", 6000)); + + Map rootWritten = map(); + rootWritten.put(trace, 4000L); + + ScopeDiagnosticsReport report = report(list(r), rootWritten); + + assertEquals(1, report.lateCount()); + assertEquals(0, report.leakCount()); + } + + @Test + void lateFinishDoesNotFail() { + DDTraceId trace = DDTraceId.from(120); + ContinuationRecord r = record(0, trace); + r.addResume(event(ScopeEvent.Type.ACTIVATE, "pool-1", 5000)); + r.setTerminalOrExtra(event(ScopeEvent.Type.RESOLVE_FINISH, "pool-1", 6000)); + Map rootWritten = map(); + rootWritten.put(trace, 4000L); + + ScopeDiagnosticsReport report = report(list(r), rootWritten); + + assertEquals(1, report.lateCount()); + assertFalse(report.hasProblems()); + } + + @Test + void multipleResolutionsAreFlaggedDouble() { + ContinuationRecord r = record(0, DDTraceId.from(13)); + r.addResume(event(ScopeEvent.Type.ACTIVATE, "pool-1", 2000)); + r.setTerminalOrExtra(event(ScopeEvent.Type.RESOLVE_FINISH, "pool-1", 3000)); + r.setTerminalOrExtra(event(ScopeEvent.Type.RESOLVE_FINISH, "pool-1", 3500)); + + ScopeDiagnosticsReport report = report(list(r), map()); + + assertEquals(1, report.doubleCount()); + assertTrue(report.hasProblems()); + } + + @Test + void activationAfterResolveIsFailure() { + ContinuationRecord r = record(0, DDTraceId.from(14)); + r.setTerminalOrExtra(event(ScopeEvent.Type.RESOLVE_CANCEL, "pool-1", 2000)); + r.addResume(event(ScopeEvent.Type.ACTIVATE, "pool-2", 3000)); + + ScopeDiagnosticsReport report = report(list(r), map()); + + assertEquals(1, report.activateAfterResolveCount()); + assertEquals(0, report.doubleCount()); + assertTrue(report.hasProblems()); + } + + @Test + void failedActivationIsActivateAfterResolve() { + ContinuationRecord r = record(0, DDTraceId.from(141)); + r.setTerminalOrExtra(event(ScopeEvent.Type.RESOLVE_CANCEL, "pool-1", 2000)); + r.addFailedActivation(event(ScopeEvent.Type.ACTIVATE_FAILED, "pool-2", 3000)); + + ScopeDiagnosticsReport report = report(list(r), map()); + + assertEquals(1, report.activateAfterResolveCount()); + assertTrue(report.hasProblems()); + } + + @Test + void timelineRendersResolvedContinuationEvenWithoutProblems() { + ContinuationRecord r = record(0, DDTraceId.from(30)); + r.addResume(event(ScopeEvent.Type.ACTIVATE, "pool-1", 2000)); + r.setTerminalOrExtra(event(ScopeEvent.Type.RESOLVE_FINISH, "pool-1", 3000)); + + ScopeDiagnosticsReport report = report(list(r), map()); + + assertFalse(report.hasProblems()); + assertTrue(report.renderSummary().contains("(none)")); + + String timeline = report.renderTimeline(); + assertTrue(timeline.contains("#0 FINISHED")); + assertTrue(timeline.contains("capture")); + assertTrue(timeline.contains("resume")); + assertTrue(timeline.contains("finish")); + assertTrue(timeline.contains("Worker.java:42")); + assertTrue(timeline.contains("@ pool-1")); + } + + @Test + void reportIsAnImmutableSnapshot() { + ContinuationRecord record = record(0, DDTraceId.from(31)); + ScopeDiagnosticsReport report = report(list(record), map()); + + record.setTerminalOrExtra(event(ScopeEvent.Type.RESOLVE_FINISH, "pool-1", 3000)); + + assertEquals(1, report.leakCount()); + assertEquals(ContinuationStatus.LEAKED, report.records().get(0).status()); + } + + private static ScopeDiagnosticsReport report( + List records, Map rootWritten) { + return new ScopeDiagnosticsReport(records, new ArrayList<>(), rootWritten); + } + + private static List list(ContinuationRecord... rs) { + List l = new ArrayList<>(); + for (ContinuationRecord r : rs) { + l.add(r); + } + return l; + } + + private static Map map() { + return new HashMap<>(); + } +} diff --git a/dd-java-agent/instrumentation-testing/src/test/java/datadog/trace/agent/test/scopediag/ScopeRecordTest.java b/dd-java-agent/instrumentation-testing/src/test/java/datadog/trace/agent/test/scopediag/ScopeRecordTest.java new file mode 100644 index 00000000000..6af4a059c86 --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/test/java/datadog/trace/agent/test/scopediag/ScopeRecordTest.java @@ -0,0 +1,99 @@ +package datadog.trace.agent.test.scopediag; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertFalse; +import static org.junit.jupiter.api.Assertions.assertTrue; + +import datadog.trace.api.DDTraceId; +import java.util.ArrayList; +import java.util.HashMap; +import java.util.List; +import org.junit.jupiter.api.Test; + +class ScopeRecordTest { + + private static final StackTraceElement[] STACK = { + new StackTraceElement("com.app.Worker", "run", "Worker.java", 7) + }; + + private static ScopeEvent event(ScopeEvent.Type type, String thread, long nanos) { + return new ScopeEvent(type, thread, nanos, STACK); + } + + private static ScopeRecord scope(long seq, Long continuationSeq, String openThread, long nanos) { + return new ScopeRecord( + seq, + DDTraceId.from(1), + 9L, + "op", + (byte) 0, + continuationSeq, + false, + event(ScopeEvent.Type.SCOPE_OPEN, openThread, nanos)); + } + + private static ScopeDiagnosticsReport report(ScopeRecord... scopes) { + List list = new ArrayList<>(); + for (ScopeRecord s : scopes) { + list.add(s); + } + return new ScopeDiagnosticsReport(new ArrayList<>(), list, new HashMap<>()); + } + + @Test + void openAndClosedHasNoFailures() { + ScopeRecord s = scope(0, null, "main", 1000); + s.setClose(event(ScopeEvent.Type.SCOPE_CLOSE, "main", 3000)); + + assertTrue(s.closed()); + assertEquals(0, s.failures().size()); + assertFalse(s.threadHandoff()); + assertEquals(Long.valueOf(2000), s.activeDurationNanos()); + assertFalse(report(s).hasProblems()); + } + + @Test + void openWithoutCloseIsNeverClosed() { + ScopeRecord s = scope(0, null, "main", 1000); + + assertFalse(s.closed()); + assertTrue(s.failures().contains(Failure.NEVER_CLOSED)); + + ScopeDiagnosticsReport report = report(s); + assertEquals(1, report.neverClosedScopeCount()); + assertTrue(report.hasProblems()); + } + + @Test + void deferredCleanupIsNotALeak() { + ScopeRecord s = scope(0, null, "main", 1000); + s.markDeferredCleanup(); + + ScopeDiagnosticsReport report = report(s); + assertFalse(s.failures().contains(Failure.NEVER_CLOSED)); + assertEquals(1, report.deferredCleanupScopeCount()); + assertEquals(0, report.neverClosedScopeCount()); + assertFalse(report.hasProblems()); + } + + @Test + void openAndCloseOnDifferentThreadsIsHandoff() { + ScopeRecord s = scope(0, null, "main", 1000); + s.setClose(event(ScopeEvent.Type.SCOPE_CLOSE, "pool-1", 2000)); + + assertTrue(s.threadHandoff()); + } + + @Test + void wrongThreadCloseIsReportedButDoesNotFail() { + ScopeRecord s = scope(0, null, "main", 1000); + s.setClose(event(ScopeEvent.Type.SCOPE_CLOSE, "main", 2000)); + s.addWrongThreadClose(event(ScopeEvent.Type.SCOPE_CLOSE_WRONG_THREAD, "pool-2", 1500)); + + assertTrue(s.failures().contains(Failure.CLOSE_WRONG_THREAD)); + + ScopeDiagnosticsReport report = report(s); + assertEquals(1, report.closeWrongThreadCount()); + assertFalse(report.hasProblems()); // wrong-thread is report-only + } +} diff --git a/dd-java-agent/instrumentation-testing/src/test/java/datadog/trace/agent/test/scopediag/StackFilterTest.java b/dd-java-agent/instrumentation-testing/src/test/java/datadog/trace/agent/test/scopediag/StackFilterTest.java new file mode 100644 index 00000000000..3853ab274fd --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/test/java/datadog/trace/agent/test/scopediag/StackFilterTest.java @@ -0,0 +1,53 @@ +package datadog.trace.agent.test.scopediag; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertTrue; + +import org.junit.jupiter.api.Test; + +class StackFilterTest { + + private static StackTraceElement frame(String cls, String method) { + return new StackTraceElement(cls, method, "Src.java", 1); + } + + @Test + void dropsPlumbingAndKeepsAppFrames() { + StackTraceElement[] raw = { + frame("java.lang.Thread", "getStackTrace"), + frame("datadog.trace.agent.test.scopediag.ScopeDiagnostics", "event"), + frame("datadog.trace.core.scopemanager.ScopeContinuation", "register"), + frame("java.util.concurrent.ThreadPoolExecutor", "execute"), + frame("com.app.Service", "doWork"), + frame("com.app.Main", "main"), + }; + + StackTraceElement[] filtered = new StackFilter(6).filter(raw); + + assertEquals(2, filtered.length); + assertEquals("com.app.Service", filtered[0].getClassName()); + assertEquals("com.app.Main", filtered[1].getClassName()); + } + + @Test + void respectsMaxFrames() { + StackTraceElement[] raw = { + frame("com.app.A", "a"), frame("com.app.B", "b"), frame("com.app.C", "c"), + }; + + assertEquals(2, new StackFilter(2).filter(raw).length); + } + + @Test + void handlesNullStack() { + assertEquals(0, new StackFilter(6).filter(null).length); + } + + @Test + void keepsScopeManagerFreeStacks() { + StackTraceElement[] raw = {frame("com.app.Only", "here")}; + StackTraceElement[] filtered = new StackFilter(6).filter(raw); + assertEquals(1, filtered.length); + assertTrue(filtered[0].getClassName().startsWith("com.app")); + } +}