From 1eb4d72e18b94379e29ef90a37870037bc9333d3 Mon Sep 17 00:00:00 2001 From: Andrea Marziali Date: Thu, 11 Jun 2026 08:45:32 +0200 Subject: [PATCH 1/4] Introduce systematic continuation leakage diagnostics --- .agents/skills/apm-integrations/SKILL.md | 7 +- .../skills/fix-continuation-leakage/SKILL.md | 56 +++ .../skills/fix-continuation-leakage/SKILL.md | 23 ++ .../test/InstrumentationSpecification.groovy | 78 +++- .../test/AbstractInstrumentationTest.java | 4 +- .../scopediag/ContinuableScopeAdvice.java | 39 ++ .../test/scopediag/ContinuationAdvice.java | 76 ++++ .../test/scopediag/ContinuationRecord.java | 240 +++++++++++ .../test/scopediag/ContinuationStatus.java | 18 + .../trace/agent/test/scopediag/Failure.java | 21 + .../test/scopediag/PendingTraceAdvice.java | 33 ++ .../scopediag/ScopeContinuationProbe.java | 319 +++++++++++++++ .../ScopeContinuationTransformer.java | 65 +++ .../test/scopediag/ScopeDiagnostics.java | 359 +++++++++++++++++ .../scopediag/ScopeDiagnosticsExtension.java | 62 +++ .../scopediag/ScopeDiagnosticsReport.java | 381 ++++++++++++++++++ .../agent/test/scopediag/ScopeEvent.java | 44 ++ .../agent/test/scopediag/ScopeRecord.java | 134 ++++++ .../agent/test/scopediag/ScopeSources.java | 25 ++ .../agent/test/scopediag/StackFilter.java | 75 ++++ .../scopediag/TrackScopeContinuations.java | 25 ++ .../scopediag/ScopeContinuationProbeTest.java | 99 +++++ .../ScopeDiagnosticsConfigurationTest.java | 36 ++ .../ScopeDiagnosticsIntegrationTest.java | 175 ++++++++ .../scopediag/ScopeDiagnosticsReportTest.java | 179 ++++++++ .../agent/test/scopediag/ScopeRecordTest.java | 86 ++++ .../agent/test/scopediag/StackFilterTest.java | 53 +++ 27 files changed, 2696 insertions(+), 16 deletions(-) create mode 100644 .agents/skills/fix-continuation-leakage/SKILL.md create mode 100644 .claude/skills/fix-continuation-leakage/SKILL.md create mode 100644 dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ContinuableScopeAdvice.java create mode 100644 dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ContinuationAdvice.java create mode 100644 dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ContinuationRecord.java create mode 100644 dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ContinuationStatus.java create mode 100644 dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/Failure.java create mode 100644 dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/PendingTraceAdvice.java create mode 100644 dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeContinuationProbe.java create mode 100644 dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeContinuationTransformer.java create mode 100644 dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeDiagnostics.java create mode 100644 dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeDiagnosticsExtension.java create mode 100644 dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeDiagnosticsReport.java create mode 100644 dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeEvent.java create mode 100644 dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeRecord.java create mode 100644 dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeSources.java create mode 100644 dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/StackFilter.java create mode 100644 dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/TrackScopeContinuations.java create mode 100644 dd-java-agent/instrumentation-testing/src/test/java/datadog/trace/agent/test/scopediag/ScopeContinuationProbeTest.java create mode 100644 dd-java-agent/instrumentation-testing/src/test/java/datadog/trace/agent/test/scopediag/ScopeDiagnosticsConfigurationTest.java create mode 100644 dd-java-agent/instrumentation-testing/src/test/java/datadog/trace/agent/test/scopediag/ScopeDiagnosticsIntegrationTest.java create mode 100644 dd-java-agent/instrumentation-testing/src/test/java/datadog/trace/agent/test/scopediag/ScopeDiagnosticsReportTest.java create mode 100644 dd-java-agent/instrumentation-testing/src/test/java/datadog/trace/agent/test/scopediag/ScopeRecordTest.java create mode 100644 dd-java-agent/instrumentation-testing/src/test/java/datadog/trace/agent/test/scopediag/StackFilterTest.java 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..961f3d88eb4 --- /dev/null +++ b/.agents/skills/fix-continuation-leakage/SKILL.md @@ -0,0 +1,56 @@ +--- +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. +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..63f08512204 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,74 @@ 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 } + } + + /** Resolves the {@link TrackScopeContinuations} annotation from the feature method or spec class. */ + 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()) + } + /** Captures the diagnostic failure so the rest of Spock cleanup always runs first. */ + private Throwable reportScopeDiagnostics() { + def config = scopeDiagConfig() + if (!ScopeDiagnostics.isEnabled(config)) { + return null + } try { - if (enabledFinishTimingChecks()) { - doCheckRepeatedFinish() + 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..3dab0453128 --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ContinuableScopeAdvice.java @@ -0,0 +1,39 @@ +package datadog.trace.agent.test.scopediag; + +import net.bytebuddy.asm.Advice; + +/** + * Test-only ByteBuddy advice woven into {@code datadog.trace.core.scopemanager.ContinuableScope} + * (and, by inheritance, {@code ContinuingScope}) to track the scope activation lifecycle. + * + *

The target type is package-private, so {@code this} is typed as {@link Object} and re-cast + * inside {@link ScopeContinuationProbe}. {@code afterActivated} is the open point (first call per + * scope identity), {@code onProperClose} the pop, and {@code close} the wrong-thread check. + */ +public final class ContinuableScopeAdvice { + private ContinuableScopeAdvice() {} + + /** {@code afterActivated()} — the scope became active. */ + public static final class AfterActivated { + @Advice.OnMethodExit(suppress = Throwable.class) + public static void exit(@Advice.This Object scope) { + ScopeContinuationProbe.onScopeOpen(scope); + } + } + + /** {@code onProperClose()} — the scope was popped from its thread's stack. */ + public static final class OnProperClose { + @Advice.OnMethodExit(suppress = Throwable.class) + public static void exit(@Advice.This Object scope) { + ScopeContinuationProbe.onScopeClose(scope); + } + } + + /** {@code close()} — check for an out-of-order / wrong-thread close. */ + 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/ContinuationAdvice.java b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ContinuationAdvice.java new file mode 100644 index 00000000000..8264d3c87da --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ContinuationAdvice.java @@ -0,0 +1,76 @@ +package datadog.trace.agent.test.scopediag; + +import net.bytebuddy.asm.Advice; + +/** + * Test-only ByteBuddy advice woven into {@code datadog.trace.core.scopemanager.ScopeContinuation}. + * + *

The target type is package-private and cannot be named here, so {@code this} is typed as + * {@link Object} and re-cast to the public {@code ContextContinuation} supertype inside {@link + * ScopeContinuationProbe}. {@link Advice.FieldValue} reads the private {@code count} field — legal + * because the advice is inlined into the field's own class. + */ +public final class ContinuationAdvice { + private ContinuationAdvice() {} + + /** {@code register()} — the continuation was captured. */ + public static final class Register { + @Advice.OnMethodExit(suppress = Throwable.class) + public static void exit(@Advice.This Object self) { + ScopeContinuationProbe.onCapture(self); + } + } + + /** + * {@code resume()} — a (possibly noop) activation; the probe filters the rollback branch. + * + *

The activation timestamp is captured at method entry, not exit: the same-span reuse + * optimization ({@code ContinuableScopeManager.continueSpan}) cancels the continuation from + * inside {@code resume()} before it returns, so timestamping the resume at exit would + * order it after that internal resolution and spuriously flag {@code ACTIVATE_AFTER_RESOLVE}. + */ + 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); + } + } + + /** + * Resolution detected via the {@code count} transition. Applied to both {@code release()} and + * {@code cancelFromContinuedScopeClose()} — they need identical before/after observation. The + * originating method name ({@code #m}) distinguishes an explicit cancel from a normal + * finish-on-scope-close. + * + *

The resolve timestamp is captured at method entry (the {@code ddResolveNanos} + * local), not at exit: the body itself may call {@code removeContinuation() -> + * PendingTrace.write()}, which is exactly where the root-written timestamp is taken. Timestamping + * at exit would place the resolution after the root write it triggered, producing a spurious + * late-finish. + */ + 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..d272eb90f83 --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ContinuationRecord.java @@ -0,0 +1,240 @@ +package datadog.trace.agent.test.scopediag; + +import datadog.trace.api.DDTraceId; +import java.util.ArrayList; +import java.util.EnumSet; +import java.util.List; + +/** + * The correlated continuation lifecycle: its capture, every resume (activation), any + * failed activation, and its terminal resolution (finish/cancel). Scope activation lifetimes are + * modelled separately by {@link ScopeRecord}; the scopes a continuation spawned are linked here by + * their seq ids ({@link #scopeRecordSeqs()}). + * + *

Built incrementally as events arrive on different threads, so all mutating access is + * synchronized on the instance. + */ +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; + } + + // ---- mutation ------------------------------------------------------------ + + 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; + } + + // ---- accessors ----------------------------------------------------------- + + 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 isResumed() { + return !resumes.isEmpty(); + } + + public synchronized boolean isResolved() { + return terminal != null; + } + + // ---- derived ------------------------------------------------------------- + + public synchronized ContinuationStatus status() { + if (terminal != null) { + return terminal.type == ScopeEvent.Type.RESOLVE_CANCEL + ? ContinuationStatus.CANCELLED + : ContinuationStatus.FINISHED; + } + return ContinuationStatus.LEAKED; + } + + /** + * Derives the failure set for this continuation. {@code rootWrittenNanos} may be {@code null}. + */ + 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..213a57a62a8 --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ContinuationStatus.java @@ -0,0 +1,18 @@ +package datadog.trace.agent.test.scopediag; + +/** + * Derived lifecycle state of a continuation, for rendering. The authoritative bug signal is the + * {@link Failure} set, not this status. + */ +public enum ContinuationStatus { + /** Captured but not yet resumed or resolved. */ + CAPTURED, + /** Resumed at least once but not yet resolved. */ + RESUMED, + /** 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..6632609584d --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/Failure.java @@ -0,0 +1,21 @@ +package datadog.trace.agent.test.scopediag; + +/** + * A derived failure classification. Shared by {@link ContinuationRecord} (continuation-lifetime + * failures) and {@link ScopeRecord} (scope-lifetime failures). See {@link + * ScopeDiagnosticsReport#hasProblems()} for which of these fail a test versus are report-only. + */ +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..8d583cf0618 --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/PendingTraceAdvice.java @@ -0,0 +1,33 @@ +package datadog.trace.agent.test.scopediag; + +import net.bytebuddy.asm.Advice; + +/** + * Test-only ByteBuddy advice woven into {@code datadog.trace.core.PendingTrace}. Fires the + * root-written signal after {@code write(boolean)} actually changes {@code rootSpanWritten} from + * false to true. Observing the completed transition avoids treating an empty write as a root write. + * The timestamp is conservative: a resolution racing inside {@code write} may be omitted from the + * late category, but it cannot be falsely classified as late. + */ +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..f4240759077 --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeContinuationProbe.java @@ -0,0 +1,319 @@ +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; + +/** + * Recorder hook that the test-only ByteBuddy advice ({@link ContinuationAdvice}, {@link + * PendingTraceAdvice}) funnels scope-continuation lifecycle events into. It replaces the former + * production {@code ContinuationDiagnostics} seam: the advice is woven into {@code + * datadog.trace.core.scopemanager.ScopeContinuation} and {@code datadog.trace.core.PendingTrace} at + * test time only, so production tracer code carries no diagnostic footprint at all. + * + *

Inlined advice runs in the same app classloader as this class at test time, so it can call + * these statics directly. Every entry point first checks the {@link #recording} flag and is fully + * wrapped so a diagnostic failure can never propagate back into the tracer. + */ +public final class ScopeContinuationProbe { + /** + * Mirrors {@code ScopeContinuation.CANCELLED} (see {@code + * dd-trace-core/.../scopemanager/ScopeContinuation.java}). A continuation is resolved exactly + * when its {@code count} field transitions to this sentinel during a cancel call. Kept in sync by + * {@code ScopeContinuationProbeTest}. + */ + static final int CANCELLED = Integer.MIN_VALUE >> 1; + + private static volatile boolean recording = false; + + /** Cached reflective handle to the package-private {@code ScopeContinuation.source} field. */ + private static volatile Field sourceField; + + // cached reflective handles for scope-lifecycle reads (set-once, best-effort) + private static volatile Field scopeSourceField; // ContinuableScope.source + private static volatile Field continuationField; // ContinuingScope.continuation + private static volatile Field scopeManagerField; // ContinuableScope.scopeManager + private static volatile Method scopeStackMethod; // ContinuableScopeManager.scopeStack() + private static volatile Method checkTopMethod; // ScopeStack.checkTop(ContinuableScope) + + private ScopeContinuationProbe() {} + + /** Installs the transformer (once per JVM) and opens the cheap advice-side recording gate. */ + static synchronized void enable() { + ScopeContinuationTransformer.install(); + recording = true; + } + + /** Stops recording. The transformer stays installed (inert while not recording). */ + static void disable() { + recording = false; + } + + // ---- advice entry points (public so inlined advice can reference them) ------------------- + + /** {@code ScopeContinuation.register()} exit: the continuation was captured. */ + 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 disturb the tracer + } + } + + /** + * {@code ScopeContinuation.resume()} exit: a real activation happened. The rollback branch + * returns the {@link NoopScope#INSTANCE noop scope} singleton, so a returned noop scope is + * skipped — this exactly reproduces the original "success branch only" semantics. + */ + public static void onActivate(Object self, Object returnedScope, long activateNanos) { + if (!recording) { + return; + } + try { + ContextContinuation continuation = (ContextContinuation) self; + if (returnedScope == NoopScope.INSTANCE) { + // activate() returned the noop scope: the continuation was already resolved. This is the + // activate-after-resolve signal — the engine records it only if a terminal was seen. + 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) { + } + } + + /** + * {@code ScopeContinuation.release()} / {@code cancelFromContinuedScopeClose()} exit. The + * original production seam fired only from inside the clean resolution branch; here we detect + * that branch by observing the {@code count} field transition to {@link #CANCELLED} during this + * call. A cancel with outstanding activations leaves {@code count} unchanged (not a resolution). + */ + public static void onResolve( + Object self, String method, int countBefore, int countAfter, long resolveNanos) { + if (!recording) { + return; + } + if (countAfter != CANCELLED) { + return; // not a resolution + } + // An explicit cancel() is a discard; cancelFromContinuedScopeClose() is a normal finish once + // the continued scope closes. (Caveat: the rare cancelFromContinuedScopeClose slow path + // delegates to cancel(), so a multi-activation finish is recorded as a cancel.) + boolean cancelled = "release".equals(method); + try { + ContextContinuation continuation = (ContextContinuation) self; + // countBefore == CANCELLED is a genuine second finish/cancel. First transitions are deduped + // by the engine under the same lock as stop/reset/report, including nested advice frames. + ScopeDiagnostics.recordResolve( + continuation, cancelled, resolveNanos, countBefore == CANCELLED); + } catch (Throwable ignored) { + } + } + + /** {@code PendingTrace.write()} root-written site. */ + public static void onRootWritten(Object traceId) { + if (!recording) { + return; + } + try { + ScopeDiagnostics.recordRootWritten((DDTraceId) traceId); + } catch (Throwable ignored) { + } + } + + /** + * {@code ContinuableScope.afterActivated()} exit: a scope became active. Re-activations (parent + * restored after a child closes) reach here too; the engine keeps only the first per scope + * identity. Links to the spawning continuation when the scope is a {@code ContinuingScope}. + */ + 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) { + } + } + + /** + * {@code ContinuableScope.onProperClose()} exit: the scope was popped from its thread's stack. + */ + public static void onScopeClose(Object scope) { + if (!recording) { + return; + } + try { + ScopeDiagnostics.recordScopeClose(scope); + } catch (Throwable ignored) { + } + } + + /** + * {@code ContinuableScope.close()} entry: if the scope is not on top of its thread's stack, this + * is an out-of-order / wrong-thread close. Best-effort — silently does nothing if the internal + * stack check cannot be reached reflectively. + */ + public static void onScopeClosing(Object scope) { + if (!recording) { + return; + } + try { + if (isNotOnTop(scope)) { + ScopeDiagnostics.recordScopeCloseWrongThread(scope); + } + } catch (Throwable ignored) { + } + } + + /** Snapshots the span name as a String (the CharSequence may mutate later), or {@code null}. */ + private static String spanName(AgentSpan span) { + try { + CharSequence name = span.getSpanName(); + return name == null ? null : name.toString(); + } catch (Throwable ignored) { + return null; + } + } + + /** + * Reads the package-private {@code source} byte field, falling back to the {@code -1} sentinel. + */ + 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; + } + } + + /** Reads the {@code source} byte of a scope (declared on {@code ContinuableScope}). */ + 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; + } + } + + /** + * The continuation that spawned a scope, read from {@code ContinuingScope.continuation}; {@code + * null} for a plain (non-continuation) scope. + */ + 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; // not a ContinuingScope + } + Object value = field.get(scope); + return value instanceof ContextContinuation ? (ContextContinuation) value : null; + } catch (Throwable ignored) { + return null; + } + } + + /** Best-effort: {@code true} when the scope is not on top of its thread's scope stack. */ + 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; + } + } + + /** Finds a named field declared on a class or any superclass, made accessible. */ + 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) { + // keep walking up + } + } + return null; + } + + /** Finds a named method with the given parameter count on a class or superclass, accessible. */ + 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..c364729de22 --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeContinuationTransformer.java @@ -0,0 +1,65 @@ +package datadog.trace.agent.test.scopediag; + +import static net.bytebuddy.matcher.ElementMatchers.named; +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 the test-only diagnostic advice into the tracer's own {@code + * datadog.trace.core.scopemanager.ScopeContinuation} and {@code datadog.trace.core.PendingTrace}. + * + *

These classes sit under {@code datadog.trace.core.*}, which the tracer's own {@code + * AgentBuilder} hard-ignores. We therefore install a separate {@link AgentBuilder} on the + * raw {@link Instrumentation} with no global-ignore filter, using retransformation so the + * already-loaded classes are rewoven on install. The advice is schema-preserving, so {@code + * disableClassFormatChanges()} + {@code REDEFINE} keep it retransform-safe. Installed once per JVM. + */ +final class ScopeContinuationTransformer { + private static volatile ResettableClassFileTransformer transformer; + + private ScopeContinuationTransformer() {} + + static synchronized void install() { + if (transformer != null) { + return; + } + 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(named("register"))) + .visit(Advice.to(ContinuationAdvice.Activate.class).on(named("resume"))) + .visit( + Advice.to(ContinuationAdvice.Cancel.class) + .on(named("release").or(named("cancelFromContinuedScopeClose"))))) + .type(named("datadog.trace.core.PendingTrace")) + .transform( + (builder, type, classLoader, module, pd) -> + builder.visit( + Advice.to(PendingTraceAdvice.Write.class) + .on(named("write").and(takesArguments(boolean.class))))) + .type(named("datadog.trace.core.scopemanager.ContinuableScope")) + .transform( + (builder, type, classLoader, module, pd) -> + builder + .visit( + Advice.to(ContinuableScopeAdvice.AfterActivated.class) + .on(named("afterActivated"))) + .visit( + Advice.to(ContinuableScopeAdvice.OnProperClose.class) + .on(named("onProperClose"))) + .visit(Advice.to(ContinuableScopeAdvice.Close.class).on(named("close")))) + .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..d06777fa6ac --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeDiagnostics.java @@ -0,0 +1,359 @@ +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; + +/** + * Test-time engine that records scope/continuation lifecycle events and renders leak reports. + * + *

It models two correlated lifecycles separately: continuations ({@link ContinuationRecord} — + * captured/resumed/finished) and scopes ({@link ScopeRecord} — opened/closed). While recording, + * {@link ScopeContinuationProbe} (test-only bytecode advice) feeds it events, which it correlates + * by identity (an {@link IdentityHashMap}, never {@code equals}/{@code hashCode}) — continuations + * by their {@code ContextContinuation} instance, scopes by their scope instance. It assumes a + * single test runs at a time per JVM (true for instrumentation tests); {@link #reset()} isolates + * one test from the next. + * + *

Usage: + * + * 

+ *   ScopeDiagnostics.startRecording();
+ *   ... exercise code under test ...
+ *   System.out.println(ScopeDiagnostics.report().renderSummary());
+ *   ScopeDiagnostics.assertNoLeaks();   // optional
+ *   ScopeDiagnostics.stop();
+ *
+ */ +public final class ScopeDiagnostics { + private static final int DEFAULT_MAX_FRAMES = 6; + + 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 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() {} + + // ---- public static facade ------------------------------------------------ + + /** 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(); + } + } + + /** Builds an immutable snapshot report of everything recorded so far. */ + public static ScopeDiagnosticsReport report() { + synchronized (INSTANCE.lifecycleLock) { + return new ScopeDiagnosticsReport( + new ArrayList<>(INSTANCE.records.values()), + new ArrayList<>(INSTANCE.scopeRecords.values()), + new HashMap<>(INSTANCE.rootWrittenNanos)); + } + } + + /** + * 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 undocumented opt-outs. */ + 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(); + rootWrittenNanos.clear(); + resolved.clear(); + seq = 0; + scopeSeq = 0; + } + + // ---- listener implementation --------------------------------------------- + + private static final StackTraceElement[] NO_STACK = new StackTraceElement[0]; + + private ScopeEvent event(ScopeEvent.Type type) { + return event(type, System.nanoTime()); + } + + /** Builds an event with an explicit timestamp (thread and stack are still captured now). */ + private ScopeEvent event(ScopeEvent.Type type, long nanos) { + // Capturing a stack per event is the dominant cost and perturbs the very timings we record; + // skip it entirely when callsites are disabled (maxFrames <= 0) rather than walking then + // trimming. + StackFilter filter = stackFilter; + StackTraceElement[] stack = + filter.maxFrames() <= 0 ? NO_STACK : filter.filter(new Throwable().getStackTrace()); + return new ScopeEvent(type, Thread.currentThread().getName(), nanos, stack); + } + + // ---- static forwarders called by ScopeContinuationProbe ------------------ + + 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); + } + } + } + + 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, + 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) { + } + } + + /** 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..54eafd6dccd --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeDiagnosticsExtension.java @@ -0,0 +1,62 @@ +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; + +/** + * JUnit5 extension that enables {@link ScopeDiagnostics} for every test extending {@code + * AbstractInstrumentationTest}. {@link TrackScopeContinuations} can override or disable it. + * + *

Per test: resets and starts recording before; after, logs findings and asserts no leaks. + */ +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.stop(); + ScopeDiagnosticsReport report = ScopeDiagnostics.report(); + if (report.hasFindings()) { + log.info("[{}] {}", context.getDisplayName(), report.renderTimeline()); + } + ScopeDiagnostics.assertNoLeaks(report); + } finally { + ScopeDiagnostics.reset(); + } + } + + /** Method-level annotation wins; otherwise the test class (incl. inherited). */ + 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..b494a68401c --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeDiagnosticsReport.java @@ -0,0 +1,381 @@ +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; + +/** + * An immutable snapshot of the recorded continuation and scope lifecycles plus the derived failure + * findings. Exposes two text renderings: a problem-only summary ({@link #renderSummary()}) for + * quick triage / assertion messages, and a complete timeline ({@link #renderTimeline()}) that dumps + * every continuation and scope with its full event lineage. The harness emits the timeline + * when it contains a finding, giving humans and diagnostic skills enough data to build a graph. + * + *

The two lifecycles are kept separate: {@link ContinuationRecord} (captured → resumed → + * finished) and {@link ScopeRecord} (opened → closed). A scope spawned by resuming a continuation + * is linked to it ({@link ContinuationRecord#scopeRecordSeqs()} / {@link + * ScopeRecord#continuationSeq}) and rendered nested under it in the timeline. + */ +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; + } + + // ---- accessors ----------------------------------------------------------- + + 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); + } + + private static int countWith(Map> findings, Failure failure) { + int n = 0; + for (EnumSet f : findings.values()) { + if (f.contains(failure)) { + n++; + } + } + return n; + } + + /** + * True when there is a genuine bug to fail on: a never-resolved leak, a double finish, an + * activation after resolve, or a scope that was never closed. {@link Failure#LATE_FINISH} and + * {@link Failure#CLOSE_WRONG_THREAD} are reported but do not fail (frequently legitimate async or + * teardown ordering). + */ + 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(); + } + + // ---- rendering: text summary --------------------------------------------- + + 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(closeWrongThreadCount()) + .append(" wrong-thread)\n"); + } + + /** Problem-only summary: just the flagged continuations and scopes with their callsites. */ + 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(); + } + + // ---- rendering: complete timeline ---------------------------------------- + + private static final int TIMELINE_FRAMES = 3; + + /** + * Complete cross-thread timeline: one block per continuation (capture → resume(s) → terminal), + * with the scopes it spawned nested under it, followed by any non-continuation scopes. Unlike + * {@link #renderSummary()} this lists all records, not just the flagged ones, so a graph + * (Gantt/DAG) or report can be reconstructed from it whether or not anything leaked. Each event + * carries its relative time ({@code +Δms} from the first recorded event), thread, and callsite. + */ + 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 (!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..4ad15cbbd9b --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeEvent.java @@ -0,0 +1,44 @@ +package datadog.trace.agent.test.scopediag; + +/** + * A single observed point in a continuation's lifecycle. Time, thread, and stack are captured by + * the recorder on the event's own thread (notifications are synchronous), so they reflect the + * thread that actually captured/activated/resolved the continuation. + */ +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, + /** A scope became active (first activation). */ + SCOPE_OPEN, + /** A scope was popped from its thread's stack. */ + 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..8bd5bca1153 --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeRecord.java @@ -0,0 +1,134 @@ +package datadog.trace.agent.test.scopediag; + +import datadog.trace.api.DDTraceId; +import java.util.ArrayList; +import java.util.EnumSet; +import java.util.List; + +/** + * The scope activation lifecycle: a scope opened (first activation) → closed (popped from + * its thread's stack). Distinct from the continuation lifecycle ({@link ContinuationRecord}); when + * a scope was spawned by resuming a continuation, {@link #continuationSeq} links back to that + * continuation's {@link ContinuationRecord#seq}. + */ +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 seq of 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 final List wrongThreadCloses = new ArrayList<>(0); + + ScopeRecord( + long seq, + DDTraceId traceId, + long spanId, + String spanName, + byte source, + Long continuationSeq, + ScopeEvent open) { + this.seq = seq; + this.traceId = traceId; + this.spanId = spanId; + this.spanName = spanName; + this.source = source; + this.continuationSeq = continuationSeq; + this.open = open; + } + + // ---- mutation ------------------------------------------------------------ + + 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, + open == null ? null : open.snapshot()); + copy.close = close == null ? null : close.snapshot(); + for (ScopeEvent event : wrongThreadCloses) { + copy.wrongThreadCloses.add(event.snapshot()); + } + return copy; + } + + // ---- accessors ----------------------------------------------------------- + + 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; + } + + // ---- derived ------------------------------------------------------------- + + /** {@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) { + 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..7bf7a81fa3b --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeSources.java @@ -0,0 +1,25 @@ +package datadog.trace.agent.test.scopediag; + +/** + * Maps the {@code byte} scope source used by the tracer to a readable name. Mirrors the constants + * in {@code datadog.trace.core.scopemanager.ContinuableScope} (which are package-private and not + * visible from here). + */ +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/StackFilter.java b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/StackFilter.java new file mode 100644 index 00000000000..8b360d38fa0 --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/StackFilter.java @@ -0,0 +1,75 @@ +package datadog.trace.agent.test.scopediag; + +import java.util.ArrayList; +import java.util.List; + +/** + * Trims a raw stack trace down to the frames that point at where a continuation was + * captured/activated/resolved: it drops the diagnostic plumbing, the scope-manager internals, and + * the executor/reflection scaffolding, keeping the top {@code maxFrames} meaningful frames. + */ +final class StackFilter { + private static final String[] DROP_PREFIXES = { + // diagnostic harness itself + "datadog.trace.agent.test.scopediag.", + // tracer scope/continuation machinery and the capture/activate plumbing it sits behind + "datadog.trace.core.", + "datadog.trace.bootstrap.instrumentation.java.concurrent.", + "datadog.trace.bootstrap.instrumentation.api.", + "datadog.trace.bootstrap.InstrumentationContext", + // JDK executor/reflection scaffolding between the caller and the capture + "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.", + // Spock/Groovy/ByteBuddy mock & dynamic-dispatch scaffolding (test harness, not a callsite) + "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..69b0d8556f6 --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/TrackScopeContinuations.java @@ -0,0 +1,25 @@ +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; + +/** + * Overrides the scope-continuation diagnostic defaults for an instrumentation test class or method. + * Diagnostics run for every instrumentation test unless explicitly disabled. + * + *

Honored by both the JUnit5 {@link ScopeDiagnosticsExtension} and the Groovy/Spock {@code + * InstrumentationSpecification}. + */ +@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; + + /** Required when disabling diagnostics. Explain the incompatibility, preferably with an issue. */ + 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..1cfc29256db --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/test/java/datadog/trace/agent/test/scopediag/ScopeContinuationProbeTest.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.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; + +/** + * Guards the production names/constants that {@link ScopeContinuationProbe} relies on reflectively + * or mirrors. If any of these are renamed/changed in the tracer, these assertions fail loudly + * instead of the diagnostic silently going dark. + */ +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"); + // methods woven by ScopeContinuationTransformer (matched by name) + assertNotNull(scopeContinuation.getDeclaredMethod("register"), "register() (capture)"); + assertNotNull(scopeContinuation.getDeclaredMethod("resume"), "resume()"); + assertNotNull(scopeContinuation.getDeclaredMethod("release"), "release() (resolve)"); + assertNotNull( + scopeContinuation.getDeclaredMethod("cancelFromContinuedScopeClose"), + "cancelFromContinuedScopeClose() (resolve)"); + // fields read by the Cancel advice (@Advice.FieldValue) and the probe (reflection) + 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"); + // PendingTraceAdvice matches write(boolean) and reads these fields via @Advice.FieldValue + 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)"); + // source byte read reflectively in the probe + 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) { + // keep walking + } + } + 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..4c4f1478a75 --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/test/java/datadog/trace/agent/test/scopediag/ScopeDiagnosticsIntegrationTest.java @@ -0,0 +1,175 @@ +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.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 org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.Test; + +/** + * Exercises the full path: a real {@link CoreTracer} capturing continuations via {@code + * captureSpan} drives {@code ScopeContinuation} -> {@code ScopeContinuationProbe} -> {@link + * ScopeDiagnostics}, and the derived report classifies the leak correctly. + */ +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); // captured, never resolved + 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()); + // keep a reference so the leak isn't reclaimed before the assertion + 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); // span becomes the active top scope + // Capturing then immediately activating the already-active span hits the continueSpan reuse + // optimization: it cancels the continuation from inside activate() before activate() returns. + // The resume must be timestamped at activate() entry (not exit) so it does not appear to occur + // after that internal resolution and spuriously trip ACTIVATE_AFTER_RESOLVE. + 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()); + // the scope links back to its continuation record + assertEquals(1, report.records().size()); + assertEquals(Long.valueOf(report.records().get(0).seq), linked.continuationSeq); + } + + @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(); // opened, never closed + + 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()); + + // clean up so the open scope does not pollute this thread's scope stack for later tests + 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..a2462b294ae --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/test/java/datadog/trace/agent/test/scopediag/ScopeDiagnosticsReportTest.java @@ -0,0 +1,179 @@ +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()); // captured on main, resolved on pool-1 + 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")); + // the capture callsite is surfaced in the problem summary + 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); // root written before the activation/resolution + + ScopeDiagnosticsReport report = report(list(r), rootWritten); + + assertEquals(1, report.lateCount()); + assertEquals(0, report.leakCount()); // it is resolved, just late + } + + @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()); // late-finish is report-only + } + + @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)); // resume after cancel + + 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()); + + // a clean run: the summary reports no problems ... + assertFalse(report.hasProblems()); + assertTrue(report.renderSummary().contains("(none)")); + + // ... but the timeline still dumps the full lineage so a graph/report can be built + 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")); // callsite preserved + assertTrue(timeline.contains("@ pool-1")); // resume/finish thread preserved + } + + @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()); + } + + // ---- helpers ------------------------------------------------------------- + + 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..7ad0112a432 --- /dev/null +++ b/dd-java-agent/instrumentation-testing/src/test/java/datadog/trace/agent/test/scopediag/ScopeRecordTest.java @@ -0,0 +1,86 @@ +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, + 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()); // never-closed is a genuine bug + } + + @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")); + } +} From 44c5646a36258ad77dd308fe2dbb9568bef7ece8 Mon Sep 17 00:00:00 2001 From: Andrea Marziali Date: Fri, 11 Sep 2026 10:28:23 +0200 Subject: [PATCH 2/4] code hygiene --- .../test/InstrumentationSpecification.groovy | 2 - .../scopediag/ContinuableScopeAdvice.java | 12 +-- .../test/scopediag/ContinuationAdvice.java | 32 +------ .../test/scopediag/ContinuationRecord.java | 24 +---- .../test/scopediag/ContinuationStatus.java | 9 +- .../trace/agent/test/scopediag/Failure.java | 6 +- .../test/scopediag/PendingTraceAdvice.java | 6 +- .../scopediag/ScopeContinuationProbe.java | 93 ++++--------------- .../ScopeContinuationTransformer.java | 65 ++++++++++--- .../test/scopediag/ScopeDiagnostics.java | 38 +------- .../scopediag/ScopeDiagnosticsExtension.java | 9 +- .../scopediag/ScopeDiagnosticsReport.java | 36 +------ .../agent/test/scopediag/ScopeEvent.java | 8 +- .../agent/test/scopediag/ScopeRecord.java | 17 +--- .../agent/test/scopediag/ScopeSources.java | 6 +- .../agent/test/scopediag/StackFilter.java | 10 +- .../scopediag/TrackScopeContinuations.java | 10 +- .../scopediag/ScopeContinuationProbeTest.java | 11 +-- .../ScopeDiagnosticsIntegrationTest.java | 20 +--- .../scopediag/ScopeDiagnosticsReportTest.java | 19 ++-- .../agent/test/scopediag/ScopeRecordTest.java | 2 +- 21 files changed, 109 insertions(+), 326 deletions(-) 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 63f08512204..27c9e726363 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 @@ -540,7 +540,6 @@ abstract class InstrumentationSpecification extends DDSpecification implements A } } - /** Resolves the {@link TrackScopeContinuations} annotation from the feature method or spec class. */ private TrackScopeContinuations scopeDiagConfig() { def method = specificationContext?.currentFeature?.featureMethod?.reflection def ann = method?.getAnnotation(TrackScopeContinuations) @@ -554,7 +553,6 @@ abstract class InstrumentationSpecification extends DDSpecification implements A return ScopeDiagnostics.isEnabled(scopeDiagConfig()) } - /** Captures the diagnostic failure so the rest of Spock cleanup always runs first. */ private Throwable reportScopeDiagnostics() { def config = scopeDiagConfig() if (!ScopeDiagnostics.isEnabled(config)) { 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 index 3dab0453128..1bbac24d23a 100644 --- 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 @@ -2,18 +2,10 @@ import net.bytebuddy.asm.Advice; -/** - * Test-only ByteBuddy advice woven into {@code datadog.trace.core.scopemanager.ContinuableScope} - * (and, by inheritance, {@code ContinuingScope}) to track the scope activation lifecycle. - * - *

The target type is package-private, so {@code this} is typed as {@link Object} and re-cast - * inside {@link ScopeContinuationProbe}. {@code afterActivated} is the open point (first call per - * scope identity), {@code onProperClose} the pop, and {@code close} the wrong-thread check. - */ +/** Test-only advice for {@code ContinuableScope}. */ public final class ContinuableScopeAdvice { private ContinuableScopeAdvice() {} - /** {@code afterActivated()} — the scope became active. */ public static final class AfterActivated { @Advice.OnMethodExit(suppress = Throwable.class) public static void exit(@Advice.This Object scope) { @@ -21,7 +13,6 @@ public static void exit(@Advice.This Object scope) { } } - /** {@code onProperClose()} — the scope was popped from its thread's stack. */ public static final class OnProperClose { @Advice.OnMethodExit(suppress = Throwable.class) public static void exit(@Advice.This Object scope) { @@ -29,7 +20,6 @@ public static void exit(@Advice.This Object scope) { } } - /** {@code close()} — check for an out-of-order / wrong-thread close. */ public static final class Close { @Advice.OnMethodEnter(suppress = Throwable.class) public static void enter(@Advice.This Object 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 index 8264d3c87da..cf430b5ed22 100644 --- 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 @@ -2,18 +2,10 @@ import net.bytebuddy.asm.Advice; -/** - * Test-only ByteBuddy advice woven into {@code datadog.trace.core.scopemanager.ScopeContinuation}. - * - *

The target type is package-private and cannot be named here, so {@code this} is typed as - * {@link Object} and re-cast to the public {@code ContextContinuation} supertype inside {@link - * ScopeContinuationProbe}. {@link Advice.FieldValue} reads the private {@code count} field — legal - * because the advice is inlined into the field's own class. - */ +/** Test-only advice for {@code ScopeContinuation}. */ public final class ContinuationAdvice { private ContinuationAdvice() {} - /** {@code register()} — the continuation was captured. */ public static final class Register { @Advice.OnMethodExit(suppress = Throwable.class) public static void exit(@Advice.This Object self) { @@ -21,14 +13,7 @@ public static void exit(@Advice.This Object self) { } } - /** - * {@code resume()} — a (possibly noop) activation; the probe filters the rollback branch. - * - *

The activation timestamp is captured at method entry, not exit: the same-span reuse - * optimization ({@code ContinuableScopeManager.continueSpan}) cancels the continuation from - * inside {@code resume()} before it returns, so timestamping the resume at exit would - * order it after that internal resolution and spuriously flag {@code ACTIVATE_AFTER_RESOLVE}. - */ + /** Timestamps entry because {@code resume()} may resolve the continuation before returning. */ public static final class Activate { @Advice.OnMethodEnter public static long enter() { @@ -42,18 +27,7 @@ public static void exit( } } - /** - * Resolution detected via the {@code count} transition. Applied to both {@code release()} and - * {@code cancelFromContinuedScopeClose()} — they need identical before/after observation. The - * originating method name ({@code #m}) distinguishes an explicit cancel from a normal - * finish-on-scope-close. - * - *

The resolve timestamp is captured at method entry (the {@code ddResolveNanos} - * local), not at exit: the body itself may call {@code removeContinuation() -> - * PendingTrace.write()}, which is exactly where the root-written timestamp is taken. Timestamping - * at exit would place the resolution after the root write it triggered, producing a spurious - * late-finish. - */ + /** Timestamps entry because resolution may write the trace before the method returns. */ public static final class Cancel { @Advice.OnMethodEnter public static int enter( 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 index d272eb90f83..845218efa2f 100644 --- 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 @@ -5,15 +5,7 @@ import java.util.EnumSet; import java.util.List; -/** - * The correlated continuation lifecycle: its capture, every resume (activation), any - * failed activation, and its terminal resolution (finish/cancel). Scope activation lifetimes are - * modelled separately by {@link ScopeRecord}; the scopes a continuation spawned are linked here by - * their seq ids ({@link #scopeRecordSeqs()}). - * - *

Built incrementally as events arrive on different threads, so all mutating access is - * synchronized on the instance. - */ +/** Records a continuation's capture, activations, scopes, and resolution. */ public final class ContinuationRecord { public final long seq; public final DDTraceId traceId; @@ -48,8 +40,6 @@ public final class ContinuationRecord { this.capture = capture; } - // ---- mutation ------------------------------------------------------------ - synchronized void addResume(ScopeEvent event) { resumes.add(event); } @@ -95,8 +85,6 @@ synchronized ContinuationRecord snapshot() { return copy; } - // ---- accessors ----------------------------------------------------------- - public synchronized ScopeEvent capture() { return capture; } @@ -121,16 +109,10 @@ public synchronized List scopeRecordSeqs() { return new ArrayList<>(scopeRecordSeqs); } - public synchronized boolean isResumed() { - return !resumes.isEmpty(); - } - public synchronized boolean isResolved() { return terminal != null; } - // ---- derived ------------------------------------------------------------- - public synchronized ContinuationStatus status() { if (terminal != null) { return terminal.type == ScopeEvent.Type.RESOLVE_CANCEL @@ -140,9 +122,7 @@ public synchronized ContinuationStatus status() { return ContinuationStatus.LEAKED; } - /** - * Derives the failure set for this continuation. {@code rootWrittenNanos} may be {@code null}. - */ + /** Derives failures, including events after {@code rootWrittenNanos} when provided. */ public synchronized EnumSet failures(Long rootWrittenNanos) { EnumSet failures = EnumSet.noneOf(Failure.class); if (terminal == null) { 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 index 213a57a62a8..e26bf691fa4 100644 --- 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 @@ -1,14 +1,7 @@ package datadog.trace.agent.test.scopediag; -/** - * Derived lifecycle state of a continuation, for rendering. The authoritative bug signal is the - * {@link Failure} set, not this status. - */ +/** Derived continuation state used when rendering a timeline. */ public enum ContinuationStatus { - /** Captured but not yet resumed or resolved. */ - CAPTURED, - /** Resumed at least once but not yet resolved. */ - RESUMED, /** Resolved normally (all activations closed or a clean cancel with no outstanding work). */ FINISHED, /** Resolved via the cancel-with-outstanding-work path. */ 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 index 6632609584d..64a596bf473 100644 --- 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 @@ -1,10 +1,6 @@ package datadog.trace.agent.test.scopediag; -/** - * A derived failure classification. Shared by {@link ContinuationRecord} (continuation-lifetime - * failures) and {@link ScopeRecord} (scope-lifetime failures). See {@link - * ScopeDiagnosticsReport#hasProblems()} for which of these fail a test versus are report-only. - */ +/** A derived scope or continuation lifecycle finding. */ public enum Failure { /** Continuation captured but never resolved within the window. */ LEAKED, 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 index 8d583cf0618..a93b2936b7c 100644 --- 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 @@ -3,11 +3,7 @@ import net.bytebuddy.asm.Advice; /** - * Test-only ByteBuddy advice woven into {@code datadog.trace.core.PendingTrace}. Fires the - * root-written signal after {@code write(boolean)} actually changes {@code rootSpanWritten} from - * false to true. Observing the completed transition avoids treating an empty write as a root write. - * The timestamp is conservative: a resolution racing inside {@code write} may be omitted from the - * late category, but it cannot be falsely classified as late. + * Records a root write only after {@code PendingTrace.write(boolean)} sets {@code rootSpanWritten}. */ public final class PendingTraceAdvice { private PendingTraceAdvice() {} 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 index f4240759077..18ffe219f28 100644 --- 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 @@ -8,54 +8,37 @@ import java.lang.reflect.Field; import java.lang.reflect.Method; -/** - * Recorder hook that the test-only ByteBuddy advice ({@link ContinuationAdvice}, {@link - * PendingTraceAdvice}) funnels scope-continuation lifecycle events into. It replaces the former - * production {@code ContinuationDiagnostics} seam: the advice is woven into {@code - * datadog.trace.core.scopemanager.ScopeContinuation} and {@code datadog.trace.core.PendingTrace} at - * test time only, so production tracer code carries no diagnostic footprint at all. - * - *

Inlined advice runs in the same app classloader as this class at test time, so it can call - * these statics directly. Every entry point first checks the {@link #recording} flag and is fully - * wrapped so a diagnostic failure can never propagate back into the tracer. - */ +/** Forwards test-only Byte Buddy advice events to {@link ScopeDiagnostics}. */ public final class ScopeContinuationProbe { /** - * Mirrors {@code ScopeContinuation.CANCELLED} (see {@code - * dd-trace-core/.../scopemanager/ScopeContinuation.java}). A continuation is resolved exactly - * when its {@code count} field transitions to this sentinel during a cancel call. Kept in sync by - * {@code ScopeContinuationProbeTest}. + * 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; - /** Cached reflective handle to the package-private {@code ScopeContinuation.source} field. */ private static volatile Field sourceField; - // cached reflective handles for scope-lifecycle reads (set-once, best-effort) - private static volatile Field scopeSourceField; // ContinuableScope.source - private static volatile Field continuationField; // ContinuingScope.continuation - private static volatile Field scopeManagerField; // ContinuableScope.scopeManager - private static volatile Method scopeStackMethod; // ContinuableScopeManager.scopeStack() - private static volatile Method checkTopMethod; // ScopeStack.checkTop(ContinuableScope) + 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 per JVM) and opens the cheap advice-side recording gate. */ + /** Installs the transformer once and starts recording. */ static synchronized void enable() { ScopeContinuationTransformer.install(); recording = true; } - /** Stops recording. The transformer stays installed (inert while not recording). */ + /** Stops recording without uninstalling the transformer. */ static void disable() { recording = false; } - // ---- advice entry points (public so inlined advice can reference them) ------------------- - - /** {@code ScopeContinuation.register()} exit: the continuation was captured. */ public static void onCapture(Object self) { if (!recording) { return; @@ -68,15 +51,10 @@ public static void onCapture(Object self) { continuation, span.getTraceId(), span.getSpanId(), spanName(span), sourceOf(self)); } } catch (Throwable ignored) { - // diagnostics must never disturb the tracer + // Diagnostics must never affect the tracer. } } - /** - * {@code ScopeContinuation.resume()} exit: a real activation happened. The rollback branch - * returns the {@link NoopScope#INSTANCE noop scope} singleton, so a returned noop scope is - * skipped — this exactly reproduces the original "success branch only" semantics. - */ public static void onActivate(Object self, Object returnedScope, long activateNanos) { if (!recording) { return; @@ -84,8 +62,7 @@ public static void onActivate(Object self, Object returnedScope, long activateNa try { ContextContinuation continuation = (ContextContinuation) self; if (returnedScope == NoopScope.INSTANCE) { - // activate() returned the noop scope: the continuation was already resolved. This is the - // activate-after-resolve signal — the engine records it only if a terminal was seen. + // A noop result may indicate activation after resolution. ScopeDiagnostics.recordActivateFailed(continuation); return; } @@ -103,35 +80,25 @@ public static void onActivate(Object self, Object returnedScope, long activateNa } } - /** - * {@code ScopeContinuation.release()} / {@code cancelFromContinuedScopeClose()} exit. The - * original production seam fired only from inside the clean resolution branch; here we detect - * that branch by observing the {@code count} field transition to {@link #CANCELLED} during this - * call. A cancel with outstanding activations leaves {@code count} unchanged (not a resolution). - */ public static void onResolve( Object self, String method, int countBefore, int countAfter, long resolveNanos) { if (!recording) { return; } if (countAfter != CANCELLED) { - return; // not a resolution + return; } - // An explicit cancel() is a discard; cancelFromContinuedScopeClose() is a normal finish once - // the continued scope closes. (Caveat: the rare cancelFromContinuedScopeClose slow path - // delegates to cancel(), so a multi-activation finish is recorded as a cancel.) + // 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; - // countBefore == CANCELLED is a genuine second finish/cancel. First transitions are deduped - // by the engine under the same lock as stop/reset/report, including nested advice frames. ScopeDiagnostics.recordResolve( continuation, cancelled, resolveNanos, countBefore == CANCELLED); } catch (Throwable ignored) { } } - /** {@code PendingTrace.write()} root-written site. */ public static void onRootWritten(Object traceId) { if (!recording) { return; @@ -142,11 +109,6 @@ public static void onRootWritten(Object traceId) { } } - /** - * {@code ContinuableScope.afterActivated()} exit: a scope became active. Re-activations (parent - * restored after a child closes) reach here too; the engine keeps only the first per scope - * identity. Links to the spawning continuation when the scope is a {@code ContinuingScope}. - */ public static void onScopeOpen(Object scope) { if (!recording) { return; @@ -162,9 +124,6 @@ public static void onScopeOpen(Object scope) { } } - /** - * {@code ContinuableScope.onProperClose()} exit: the scope was popped from its thread's stack. - */ public static void onScopeClose(Object scope) { if (!recording) { return; @@ -175,11 +134,7 @@ public static void onScopeClose(Object scope) { } } - /** - * {@code ContinuableScope.close()} entry: if the scope is not on top of its thread's stack, this - * is an out-of-order / wrong-thread close. Best-effort — silently does nothing if the internal - * stack check cannot be reached reflectively. - */ + /** Records an out-of-order close when the internal stack can be inspected. */ public static void onScopeClosing(Object scope) { if (!recording) { return; @@ -192,7 +147,7 @@ public static void onScopeClosing(Object scope) { } } - /** Snapshots the span name as a String (the CharSequence may mutate later), or {@code null}. */ + /** Copies the possibly mutable span name. */ private static String spanName(AgentSpan span) { try { CharSequence name = span.getSpanName(); @@ -202,9 +157,6 @@ private static String spanName(AgentSpan span) { } } - /** - * Reads the package-private {@code source} byte field, falling back to the {@code -1} sentinel. - */ private static byte sourceOf(Object self) { try { Field field = sourceField; @@ -219,7 +171,6 @@ private static byte sourceOf(Object self) { } } - /** Reads the {@code source} byte of a scope (declared on {@code ContinuableScope}). */ private static byte scopeSourceOf(Object scope) { try { Field field = scopeSourceField; @@ -233,10 +184,6 @@ private static byte scopeSourceOf(Object scope) { } } - /** - * The continuation that spawned a scope, read from {@code ContinuingScope.continuation}; {@code - * null} for a plain (non-continuation) scope. - */ private static ContextContinuation continuationOf(Object scope) { try { Field field = continuationField; @@ -245,7 +192,7 @@ private static ContextContinuation continuationOf(Object scope) { continuationField = field; } if (field == null || !field.getDeclaringClass().isInstance(scope)) { - return null; // not a ContinuingScope + return null; } Object value = field.get(scope); return value instanceof ContextContinuation ? (ContextContinuation) value : null; @@ -254,7 +201,6 @@ private static ContextContinuation continuationOf(Object scope) { } } - /** Best-effort: {@code true} when the scope is not on top of its thread's scope stack. */ private static boolean isNotOnTop(Object scope) { try { Field managerField = scopeManagerField; @@ -290,7 +236,6 @@ private static boolean isNotOnTop(Object scope) { } } - /** Finds a named field declared on a class or any superclass, made accessible. */ private static Field findField(Class cls, String name) { for (Class c = cls; c != null; c = c.getSuperclass()) { try { @@ -298,13 +243,11 @@ private static Field findField(Class cls, String name) { f.setAccessible(true); return f; } catch (NoSuchFieldException ignored) { - // keep walking up } } return null; } - /** Finds a named method with the given parameter count on a class or superclass, accessible. */ private static Method findMethod(Class cls, String name, int paramCount) { for (Class c = cls; c != null; c = c.getSuperclass()) { for (Method m : c.getDeclaredMethods()) { 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 index c364729de22..3bb99277a6a 100644 --- 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 @@ -1,6 +1,8 @@ package datadog.trace.agent.test.scopediag; +import static net.bytebuddy.matcher.ElementMatchers.isMethod; import static net.bytebuddy.matcher.ElementMatchers.named; +import static net.bytebuddy.matcher.ElementMatchers.returns; import static net.bytebuddy.matcher.ElementMatchers.takesArguments; import java.lang.instrument.Instrumentation; @@ -10,14 +12,8 @@ import net.bytebuddy.asm.Advice; /** - * Installs the test-only diagnostic advice into the tracer's own {@code - * datadog.trace.core.scopemanager.ScopeContinuation} and {@code datadog.trace.core.PendingTrace}. - * - *

These classes sit under {@code datadog.trace.core.*}, which the tracer's own {@code - * AgentBuilder} hard-ignores. We therefore install a separate {@link AgentBuilder} on the - * raw {@link Instrumentation} with no global-ignore filter, using retransformation so the - * already-loaded classes are rewoven on install. The advice is schema-preserving, so {@code - * disableClassFormatChanges()} + {@code REDEFINE} keep it retransform-safe. Installed once per JVM. + * 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; @@ -38,28 +34,67 @@ static synchronized void install() { .transform( (builder, type, classLoader, module, pd) -> builder - .visit(Advice.to(ContinuationAdvice.Register.class).on(named("register"))) - .visit(Advice.to(ContinuationAdvice.Activate.class).on(named("resume"))) + .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(named("release").or(named("cancelFromContinuedScopeClose"))))) + .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(named("write").and(takesArguments(boolean.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.AfterActivated.class) - .on(named("afterActivated"))) + .on( + isMethod() + .and(named("afterActivated")) + .and(takesArguments(0)) + .and(returns(void.class)))) .visit( Advice.to(ContinuableScopeAdvice.OnProperClose.class) - .on(named("onProperClose"))) - .visit(Advice.to(ContinuableScopeAdvice.Close.class).on(named("close")))) + .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))))) .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 index d06777fa6ac..3c135721c22 100644 --- 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 @@ -9,27 +9,7 @@ import java.util.Map; import java.util.Set; -/** - * Test-time engine that records scope/continuation lifecycle events and renders leak reports. - * - *

It models two correlated lifecycles separately: continuations ({@link ContinuationRecord} — - * captured/resumed/finished) and scopes ({@link ScopeRecord} — opened/closed). While recording, - * {@link ScopeContinuationProbe} (test-only bytecode advice) feeds it events, which it correlates - * by identity (an {@link IdentityHashMap}, never {@code equals}/{@code hashCode}) — continuations - * by their {@code ContextContinuation} instance, scopes by their scope instance. It assumes a - * single test runs at a time per JVM (true for instrumentation tests); {@link #reset()} isolates - * one test from the next. - * - *

Usage: - * - * 

- *   ScopeDiagnostics.startRecording();
- *   ... exercise code under test ...
- *   System.out.println(ScopeDiagnostics.report().renderSummary());
- *   ScopeDiagnostics.assertNoLeaks();   // optional
- *   ScopeDiagnostics.stop();
- *
- */ +/** Records test-time scope and continuation lifecycles and reports leaks. */ public final class ScopeDiagnostics { private static final int DEFAULT_MAX_FRAMES = 6; @@ -52,8 +32,6 @@ public final class ScopeDiagnostics { private ScopeDiagnostics() {} - // ---- public static facade ------------------------------------------------ - /** Clears any prior data and starts recording with the default stack depth. */ public static void startRecording() { startRecording(DEFAULT_MAX_FRAMES); @@ -90,7 +68,7 @@ public static void reset() { } } - /** Builds an immutable snapshot report of everything recorded so far. */ + /** Returns an immutable snapshot of the events recorded so far. */ public static ScopeDiagnosticsReport report() { synchronized (INSTANCE.lifecycleLock) { return new ScopeDiagnosticsReport( @@ -116,7 +94,7 @@ public static void assertNoLeaks(ScopeDiagnosticsReport report) { } } - /** Resolves the default-on policy and rejects undocumented opt-outs. */ + /** 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; @@ -137,27 +115,21 @@ private void clear() { scopeSeq = 0; } - // ---- listener implementation --------------------------------------------- - private static final StackTraceElement[] NO_STACK = new StackTraceElement[0]; private ScopeEvent event(ScopeEvent.Type type) { return event(type, System.nanoTime()); } - /** Builds an event with an explicit timestamp (thread and stack are still captured now). */ + /** Uses the supplied event time while capturing the thread and stack at the call site. */ private ScopeEvent event(ScopeEvent.Type type, long nanos) { - // Capturing a stack per event is the dominant cost and perturbs the very timings we record; - // skip it entirely when callsites are disabled (maxFrames <= 0) rather than walking then - // trimming. + // 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()); return new ScopeEvent(type, Thread.currentThread().getName(), nanos, stack); } - // ---- static forwarders called by ScopeContinuationProbe ------------------ - static void recordCapture( ContextContinuation id, DDTraceId traceId, long spanId, String spanName, byte source) { synchronized (INSTANCE.lifecycleLock) { 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 index 54eafd6dccd..ef82829a6c0 100644 --- 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 @@ -9,12 +9,7 @@ import org.slf4j.Logger; import org.slf4j.LoggerFactory; -/** - * JUnit5 extension that enables {@link ScopeDiagnostics} for every test extending {@code - * AbstractInstrumentationTest}. {@link TrackScopeContinuations} can override or disable it. - * - *

Per test: resets and starts recording before; after, logs findings and asserts no leaks. - */ +/** Runs {@link ScopeDiagnostics} around each JUnit instrumentation test. */ public final class ScopeDiagnosticsExtension implements BeforeEachCallback, AfterEachCallback { private static final Logger log = LoggerFactory.getLogger(ScopeDiagnosticsExtension.class); @@ -44,7 +39,7 @@ public void afterEach(ExtensionContext context) { } } - /** Method-level annotation wins; otherwise the test class (incl. inherited). */ + /** Resolves method configuration before inherited class configuration. */ private static TrackScopeContinuations resolve(ExtensionContext context) { Optional element = context.getElement(); if (element.isPresent()) { 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 index b494a68401c..a9d83583bcf 100644 --- 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 @@ -7,18 +7,7 @@ import java.util.List; import java.util.Map; -/** - * An immutable snapshot of the recorded continuation and scope lifecycles plus the derived failure - * findings. Exposes two text renderings: a problem-only summary ({@link #renderSummary()}) for - * quick triage / assertion messages, and a complete timeline ({@link #renderTimeline()}) that dumps - * every continuation and scope with its full event lineage. The harness emits the timeline - * when it contains a finding, giving humans and diagnostic skills enough data to build a graph. - * - *

The two lifecycles are kept separate: {@link ContinuationRecord} (captured → resumed → - * finished) and {@link ScopeRecord} (opened → closed). A scope spawned by resuming a continuation - * is linked to it ({@link ContinuationRecord#scopeRecordSeqs()} / {@link - * ScopeRecord#continuationSeq}) and rendered nested under it in the timeline. - */ +/** Immutable scope and continuation lifecycle snapshot with derived failures. */ public final class ScopeDiagnosticsReport { private final List continuations; private final List scopes; @@ -84,8 +73,6 @@ private static Map> classifyScopes(List records() { return new ArrayList<>(continuations); } @@ -136,12 +123,7 @@ private static int countWith(Map> findings, Failure fail return n; } - /** - * True when there is a genuine bug to fail on: a never-resolved leak, a double finish, an - * activation after resolve, or a scope that was never closed. {@link Failure#LATE_FINISH} and - * {@link Failure#CLOSE_WRONG_THREAD} are reported but do not fail (frequently legitimate async or - * teardown ordering). - */ + /** Returns whether the report contains a failure that should fail the test. */ public boolean hasProblems() { return leakCount() > 0 || doubleCount() > 0 @@ -154,8 +136,6 @@ public boolean hasFindings() { return !continuationFailures.isEmpty() || !scopeFailures.isEmpty(); } - // ---- rendering: text summary --------------------------------------------- - private void appendHeader(StringBuilder sb, String title) { sb.append(title) .append(" (") @@ -177,7 +157,7 @@ private void appendHeader(StringBuilder sb, String title) { .append(" wrong-thread)\n"); } - /** Problem-only summary: just the flagged continuations and scopes with their callsites. */ + /** Renders flagged continuations and scopes with their call sites. */ public String renderSummary() { StringBuilder sb = new StringBuilder(); appendHeader(sb, "Scope/continuation problems"); @@ -218,17 +198,9 @@ public String renderSummary() { return sb.toString(); } - // ---- rendering: complete timeline ---------------------------------------- - private static final int TIMELINE_FRAMES = 3; - /** - * Complete cross-thread timeline: one block per continuation (capture → resume(s) → terminal), - * with the scopes it spawned nested under it, followed by any non-continuation scopes. Unlike - * {@link #renderSummary()} this lists all records, not just the flagged ones, so a graph - * (Gantt/DAG) or report can be reconstructed from it whether or not anything leaked. Each event - * carries its relative time ({@code +Δms} from the first recorded event), thread, and callsite. - */ + /** Renders all events with relative times, threads, call sites, and linked scopes. */ public String renderTimeline() { StringBuilder sb = new StringBuilder(); appendHeader(sb, "Scope/continuation timeline"); 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 index 4ad15cbbd9b..c1b77c461e5 100644 --- 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 @@ -1,10 +1,6 @@ package datadog.trace.agent.test.scopediag; -/** - * A single observed point in a continuation's lifecycle. Time, thread, and stack are captured by - * the recorder on the event's own thread (notifications are synchronous), so they reflect the - * thread that actually captured/activated/resolved the continuation. - */ +/** A timestamped scope or continuation lifecycle event with its thread and call site. */ public final class ScopeEvent { public enum Type { CAPTURE, @@ -13,9 +9,7 @@ public enum Type { ACTIVATE_FAILED, RESOLVE_FINISH, RESOLVE_CANCEL, - /** A scope became active (first activation). */ SCOPE_OPEN, - /** A scope was popped from its thread's stack. */ SCOPE_CLOSE, /** A scope was closed while not on top of its thread's stack. */ SCOPE_CLOSE_WRONG_THREAD 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 index 8bd5bca1153..825a3444274 100644 --- 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 @@ -5,12 +5,7 @@ import java.util.EnumSet; import java.util.List; -/** - * The scope activation lifecycle: a scope opened (first activation) → closed (popped from - * its thread's stack). Distinct from the continuation lifecycle ({@link ContinuationRecord}); when - * a scope was spawned by resuming a continuation, {@link #continuationSeq} links back to that - * continuation's {@link ContinuationRecord#seq}. - */ +/** Records a scope's activation and close events. */ public final class ScopeRecord { public final long seq; public final DDTraceId traceId; @@ -18,9 +13,7 @@ public final class ScopeRecord { public final String spanName; public final byte source; - /** - * The seq of the continuation that spawned this scope, or {@code null} for a plain activation. - */ + /** The continuation that spawned this scope, or {@code null} for a plain activation. */ public final Long continuationSeq; private final ScopeEvent open; @@ -44,8 +37,6 @@ public final class ScopeRecord { this.open = open; } - // ---- mutation ------------------------------------------------------------ - synchronized void setClose(ScopeEvent event) { if (close == null) { close = event; @@ -73,8 +64,6 @@ synchronized ScopeRecord snapshot() { return copy; } - // ---- accessors ----------------------------------------------------------- - public synchronized ScopeEvent open() { return open; } @@ -91,8 +80,6 @@ public synchronized boolean closed() { return close != null; } - // ---- derived ------------------------------------------------------------- - /** {@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); 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 index 7bf7a81fa3b..f152c11ac39 100644 --- 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 @@ -1,10 +1,6 @@ package datadog.trace.agent.test.scopediag; -/** - * Maps the {@code byte} scope source used by the tracer to a readable name. Mirrors the constants - * in {@code datadog.trace.core.scopemanager.ContinuableScope} (which are package-private and not - * visible from here). - */ +/** Maps package-private {@code ContinuableScope} source values to readable names. */ final class ScopeSources { private ScopeSources() {} 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 index 8b360d38fa0..e2e735a850e 100644 --- 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 @@ -3,21 +3,14 @@ import java.util.ArrayList; import java.util.List; -/** - * Trims a raw stack trace down to the frames that point at where a continuation was - * captured/activated/resolved: it drops the diagnostic plumbing, the scope-manager internals, and - * the executor/reflection scaffolding, keeping the top {@code maxFrames} meaningful frames. - */ +/** Removes diagnostic and runtime plumbing from captured call stacks. */ final class StackFilter { private static final String[] DROP_PREFIXES = { - // diagnostic harness itself "datadog.trace.agent.test.scopediag.", - // tracer scope/continuation machinery and the capture/activate plumbing it sits behind "datadog.trace.core.", "datadog.trace.bootstrap.instrumentation.java.concurrent.", "datadog.trace.bootstrap.instrumentation.api.", "datadog.trace.bootstrap.InstrumentationContext", - // JDK executor/reflection scaffolding between the caller and the capture "java.lang.Thread.getStackTrace", "java.util.concurrent.ThreadPoolExecutor", "java.util.concurrent.ScheduledThreadPoolExecutor", @@ -29,7 +22,6 @@ final class StackFilter { "jdk.internal.reflect.", "java.lang.reflect.", "sun.reflect.", - // Spock/Groovy/ByteBuddy mock & dynamic-dispatch scaffolding (test harness, not a callsite) "org.spockframework.mock.", "org.codehaus.groovy.", "groovy.lang.", 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 index 69b0d8556f6..dcef5bb15a3 100644 --- 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 @@ -6,13 +6,7 @@ import java.lang.annotation.RetentionPolicy; import java.lang.annotation.Target; -/** - * Overrides the scope-continuation diagnostic defaults for an instrumentation test class or method. - * Diagnostics run for every instrumentation test unless explicitly disabled. - * - *

Honored by both the JUnit5 {@link ScopeDiagnosticsExtension} and the Groovy/Spock {@code - * InstrumentationSpecification}. - */ +/** Configures the default-on scope and continuation diagnostic for a test class or method. */ @Retention(RetentionPolicy.RUNTIME) @Target({ElementType.TYPE, ElementType.METHOD}) @Inherited @@ -20,6 +14,6 @@ /** Set to {@code false} only for a proven incompatibility with the diagnostic itself. */ boolean enabled() default true; - /** Required when disabling diagnostics. Explain the incompatibility, preferably with an issue. */ + /** 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 index 1cfc29256db..3752b466af1 100644 --- 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 @@ -8,11 +8,7 @@ import java.lang.reflect.Method; import org.junit.jupiter.api.Test; -/** - * Guards the production names/constants that {@link ScopeContinuationProbe} relies on reflectively - * or mirrors. If any of these are renamed/changed in the tracer, these assertions fail loudly - * instead of the diagnostic silently going dark. - */ +/** Verifies the tracer internals used by {@link ScopeContinuationProbe}. */ class ScopeContinuationProbeTest { @Test @@ -31,14 +27,12 @@ void cancelledSentinelMatchesProduction() throws Exception { @Test void continuationHooksExist() throws Exception { Class scopeContinuation = Class.forName("datadog.trace.core.scopemanager.ScopeContinuation"); - // methods woven by ScopeContinuationTransformer (matched by name) assertNotNull(scopeContinuation.getDeclaredMethod("register"), "register() (capture)"); assertNotNull(scopeContinuation.getDeclaredMethod("resume"), "resume()"); assertNotNull(scopeContinuation.getDeclaredMethod("release"), "release() (resolve)"); assertNotNull( scopeContinuation.getDeclaredMethod("cancelFromContinuedScopeClose"), "cancelFromContinuedScopeClose() (resolve)"); - // fields read by the Cancel advice (@Advice.FieldValue) and the probe (reflection) assertNotNull(findField(scopeContinuation, "count"), "ScopeContinuation.count"); assertNotNull(findField(scopeContinuation, "source"), "ScopeContinuation.source"); } @@ -46,7 +40,6 @@ void continuationHooksExist() throws Exception { @Test void rootWrittenHookExists() throws Exception { Class pendingTrace = Class.forName("datadog.trace.core.PendingTrace"); - // PendingTraceAdvice matches write(boolean) and reads these fields via @Advice.FieldValue assertNotNull( pendingTrace.getDeclaredMethod("write", boolean.class), "PendingTrace.write(boolean)"); assertNotNull(findField(pendingTrace, "rootSpanWritten"), "PendingTrace.rootSpanWritten"); @@ -59,7 +52,6 @@ void scopeLifecycleHooksExist() throws Exception { assertNotNull(scope.getDeclaredMethod("afterActivated"), "afterActivated() (scope open)"); assertNotNull(scope.getDeclaredMethod("onProperClose"), "onProperClose() (scope close)"); assertNotNull(scope.getDeclaredMethod("close"), "close() (wrong-thread check)"); - // source byte read reflectively in the probe assertNotNull(findField(scope, "source"), "ContinuableScope.source"); Class continuing = Class.forName("datadog.trace.core.scopemanager.ContinuingScope"); @@ -82,7 +74,6 @@ private static Field findField(Class cls, String name) { try { return c.getDeclaredField(name); } catch (NoSuchFieldException ignored) { - // keep walking } } return null; 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 index 4c4f1478a75..33b050542d6 100644 --- 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 @@ -15,11 +15,7 @@ import org.junit.jupiter.api.AfterEach; import org.junit.jupiter.api.Test; -/** - * Exercises the full path: a real {@link CoreTracer} capturing continuations via {@code - * captureSpan} drives {@code ScopeContinuation} -> {@code ScopeContinuationProbe} -> {@link - * ScopeDiagnostics}, and the derived report classifies the leak correctly. - */ +/** Exercises diagnostics against continuations created by a real {@link CoreTracer}. */ class ScopeDiagnosticsIntegrationTest { private CoreTracer tracer; @@ -40,7 +36,7 @@ void capturesRealLeakAndResolvedContinuation() { ScopeDiagnostics.startRecording(); AgentSpan span = tracer.startSpan("test", "op"); - ContextContinuation leaked = tracer.capture(span); // captured, never resolved + ContextContinuation leaked = tracer.capture(span); ContextContinuation resolved = tracer.capture(span); resolved.release(); @@ -49,7 +45,6 @@ void capturesRealLeakAndResolvedContinuation() { assertEquals(2, report.records().size(), "both captures recorded"); assertEquals(1, report.leakCount(), "exactly the un-resolved continuation leaks"); assertTrue(report.hasProblems()); - // keep a reference so the leak isn't reclaimed before the assertion assertFalse(leaked.toString().isEmpty()); span.finish(); @@ -62,11 +57,8 @@ void sameSpanReactivationIsNotFlaggedActivateAfterResolve() { ScopeDiagnostics.startRecording(); AgentSpan span = tracer.startSpan("test", "op"); - AgentScope active = tracer.activateSpan(span); // span becomes the active top scope - // Capturing then immediately activating the already-active span hits the continueSpan reuse - // optimization: it cancels the continuation from inside activate() before activate() returns. - // The resume must be timestamped at activate() entry (not exit) so it does not appear to occur - // after that internal resolution and spuriously trip ACTIVATE_AFTER_RESOLVE. + 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(); @@ -121,7 +113,6 @@ void scopeLifetimeRecordedAndLinkedToContinuation() { assertNotNull(linked.open(), "scope open observed"); assertTrue(linked.closed(), "scope close observed"); assertEquals(0, report.neverClosedScopeCount()); - // the scope links back to its continuation record assertEquals(1, report.records().size()); assertEquals(Long.valueOf(report.records().get(0).seq), linked.continuationSeq); } @@ -134,7 +125,7 @@ void neverClosedScopeIsFlagged() { AgentSpan span = tracer.startSpan("test", "op"); ContextContinuation continuation = tracer.capture(span); - ContextScope scope = continuation.resume(); // opened, never closed + ContextScope scope = continuation.resume(); ScopeDiagnosticsReport report = ScopeDiagnostics.report(); @@ -142,7 +133,6 @@ void neverClosedScopeIsFlagged() { assertEquals(1, report.leakCount(), "and the continuation it backs also leaks"); assertTrue(report.hasProblems()); - // clean up so the open scope does not pollute this thread's scope stack for later tests scope.close(); span.finish(); } 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 index a2462b294ae..5155d563e0b 100644 --- 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 @@ -38,7 +38,7 @@ void resolvedContinuationHasNoFailures() { assertEquals(0, report.lateCount()); assertEquals(0, report.doubleCount()); assertEquals(ContinuationStatus.FINISHED, r.status()); - assertTrue(r.threadHandoff()); // captured on main, resolved on pool-1 + assertTrue(r.threadHandoff()); assertFalse(report.hasProblems()); } @@ -52,7 +52,6 @@ void neverResolvedIsFlaggedAsLeak() { assertEquals(ContinuationStatus.LEAKED, r.status()); assertTrue(report.hasProblems()); assertTrue(report.renderSummary().contains("LEAKED")); - // the capture callsite is surfaced in the problem summary assertTrue(report.renderSummary().contains("Worker.java:42")); } @@ -64,12 +63,12 @@ void resolutionAfterRootWriteIsFlaggedLate() { r.setTerminalOrExtra(event(ScopeEvent.Type.RESOLVE_FINISH, "pool-1", 6000)); Map rootWritten = map(); - rootWritten.put(trace, 4000L); // root written before the activation/resolution + rootWritten.put(trace, 4000L); ScopeDiagnosticsReport report = report(list(r), rootWritten); assertEquals(1, report.lateCount()); - assertEquals(0, report.leakCount()); // it is resolved, just late + assertEquals(0, report.leakCount()); } @Test @@ -84,7 +83,7 @@ void lateFinishDoesNotFail() { ScopeDiagnosticsReport report = report(list(r), rootWritten); assertEquals(1, report.lateCount()); - assertFalse(report.hasProblems()); // late-finish is report-only + assertFalse(report.hasProblems()); } @Test @@ -104,7 +103,7 @@ void multipleResolutionsAreFlaggedDouble() { 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)); // resume after cancel + r.addResume(event(ScopeEvent.Type.ACTIVATE, "pool-2", 3000)); ScopeDiagnosticsReport report = report(list(r), map()); @@ -133,18 +132,16 @@ void timelineRendersResolvedContinuationEvenWithoutProblems() { ScopeDiagnosticsReport report = report(list(r), map()); - // a clean run: the summary reports no problems ... assertFalse(report.hasProblems()); assertTrue(report.renderSummary().contains("(none)")); - // ... but the timeline still dumps the full lineage so a graph/report can be built 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")); // callsite preserved - assertTrue(timeline.contains("@ pool-1")); // resume/finish thread preserved + assertTrue(timeline.contains("Worker.java:42")); + assertTrue(timeline.contains("@ pool-1")); } @Test @@ -158,8 +155,6 @@ void reportIsAnImmutableSnapshot() { assertEquals(ContinuationStatus.LEAKED, report.records().get(0).status()); } - // ---- helpers ------------------------------------------------------------- - private static ScopeDiagnosticsReport report( List records, Map rootWritten) { return new ScopeDiagnosticsReport(records, new ArrayList<>(), rootWritten); 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 index 7ad0112a432..b3f1b0b4140 100644 --- 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 @@ -60,7 +60,7 @@ void openWithoutCloseIsNeverClosed() { ScopeDiagnosticsReport report = report(s); assertEquals(1, report.neverClosedScopeCount()); - assertTrue(report.hasProblems()); // never-closed is a genuine bug + assertTrue(report.hasProblems()); } @Test From 9222d0b82bd9b574e426c1db3e3522d7aa85c006 Mon Sep 17 00:00:00 2001 From: Andrea Marziali Date: Fri, 11 Sep 2026 11:13:17 +0200 Subject: [PATCH 3/4] use the right named --- .../agent/test/scopediag/ScopeContinuationTransformer.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) 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 index 3bb99277a6a..7862eb79d6f 100644 --- 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 @@ -1,7 +1,7 @@ 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.named; import static net.bytebuddy.matcher.ElementMatchers.returns; import static net.bytebuddy.matcher.ElementMatchers.takesArguments; From aa0b232f4df90b3415060445f15546f3ee1ebd8e Mon Sep 17 00:00:00 2001 From: Andrea Marziali Date: Fri, 11 Sep 2026 14:19:56 +0200 Subject: [PATCH 4/4] Add deferred cleanup use case --- .../skills/fix-continuation-leakage/SKILL.md | 3 + .../test/InstrumentationSpecification.groovy | 1 + .../scopediag/ContinuableScopeAdvice.java | 7 -- .../ContinuableScopeManagerAdvice.java | 15 ++++ .../scopediag/ScopeContinuationProbe.java | 10 +++ .../ScopeContinuationTransformer.java | 51 +++++++++++-- .../test/scopediag/ScopeDiagnostics.java | 62 ++++++++++++++-- .../scopediag/ScopeDiagnosticsExtension.java | 1 + .../scopediag/ScopeDiagnosticsReport.java | 19 +++++ .../agent/test/scopediag/ScopeRecord.java | 14 +++- .../test/scopediag/ScopeStackAdvice.java | 15 ++++ .../ScopeDiagnosticsIntegrationTest.java | 71 +++++++++++++++++++ .../agent/test/scopediag/ScopeRecordTest.java | 13 ++++ 13 files changed, 262 insertions(+), 20 deletions(-) create mode 100644 dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ContinuableScopeManagerAdvice.java create mode 100644 dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeStackAdvice.java diff --git a/.agents/skills/fix-continuation-leakage/SKILL.md b/.agents/skills/fix-continuation-leakage/SKILL.md index 961f3d88eb4..d87a570cca6 100644 --- a/.agents/skills/fix-continuation-leakage/SKILL.md +++ b/.agents/skills/fix-continuation-leakage/SKILL.md @@ -38,6 +38,9 @@ resolution, scope, thread, timing, and callsite data needed to find the missing - `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. 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 27c9e726363..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 @@ -559,6 +559,7 @@ abstract class InstrumentationSpecification extends DDSpecification implements A return null } try { + ScopeDiagnostics.awaitQuiescence() ScopeDiagnostics.stop() def report = ScopeDiagnostics.report() if (report.hasFindings()) { 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 index 1bbac24d23a..59b2a3c23b1 100644 --- 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 @@ -6,13 +6,6 @@ public final class ContinuableScopeAdvice { private ContinuableScopeAdvice() {} - public static final class AfterActivated { - @Advice.OnMethodExit(suppress = Throwable.class) - public static void exit(@Advice.This Object scope) { - ScopeContinuationProbe.onScopeOpen(scope); - } - } - public static final class OnProperClose { @Advice.OnMethodExit(suppress = Throwable.class) public static void exit(@Advice.This Object 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/ScopeContinuationProbe.java b/dd-java-agent/instrumentation-testing/src/main/java/datadog/trace/agent/test/scopediag/ScopeContinuationProbe.java index 18ffe219f28..4cd5ef08003 100644 --- 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 @@ -134,6 +134,16 @@ public static void onScopeClose(Object scope) { } } + 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) { 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 index 7862eb79d6f..f00a942eb2f 100644 --- 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 @@ -3,6 +3,7 @@ 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; @@ -24,6 +25,16 @@ 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() @@ -74,13 +85,6 @@ static synchronized void install() { .transform( (builder, type, classLoader, module, pd) -> builder - .visit( - Advice.to(ContinuableScopeAdvice.AfterActivated.class) - .on( - isMethod() - .and(named("afterActivated")) - .and(takesArguments(0)) - .and(returns(void.class)))) .visit( Advice.to(ContinuableScopeAdvice.OnProperClose.class) .on( @@ -95,6 +99,39 @@ static synchronized void install() { .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 index 3c135721c22..c95582b545f 100644 --- 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 @@ -12,6 +12,7 @@ /** 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(); @@ -20,6 +21,8 @@ public final class ScopeDiagnostics { 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()); @@ -71,10 +74,28 @@ public static void reset() { /** Returns an immutable snapshot of the events recorded so far. */ public static ScopeDiagnosticsReport report() { synchronized (INSTANCE.lifecycleLock) { - return new ScopeDiagnosticsReport( - new ArrayList<>(INSTANCE.records.values()), - new ArrayList<>(INSTANCE.scopeRecords.values()), - new HashMap<>(INSTANCE.rootWrittenNanos)); + 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; + } + } } } @@ -109,12 +130,20 @@ public static boolean isEnabled(TrackScopeContinuations config) { 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) { @@ -127,7 +156,9 @@ private ScopeEvent event(ScopeEvent.Type type, long nanos) { StackFilter filter = stackFilter; StackTraceElement[] stack = filter.maxFrames() <= 0 ? NO_STACK : filter.filter(new Throwable().getStackTrace()); - return new ScopeEvent(type, Thread.currentThread().getName(), nanos, stack); + ScopeEvent event = new ScopeEvent(type, Thread.currentThread().getName(), nanos, stack); + lifecycleLock.notifyAll(); + return event; } static void recordCapture( @@ -208,6 +239,14 @@ static void recordScopeCloseWrongThread(Object 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) { @@ -287,6 +326,7 @@ void onScopeOpen( spanName, source, continuationSeq, + deferredCleanupScopes.remove(scope), event(ScopeEvent.Type.SCOPE_OPEN))); if (owner != null) { owner.linkScope(s); @@ -315,6 +355,18 @@ void onScopeCloseWrongThread(Object scope) { } } + 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) { 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 index ef82829a6c0..7ba889284d0 100644 --- 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 @@ -28,6 +28,7 @@ public void afterEach(ExtensionContext context) { return; } try { + ScopeDiagnostics.awaitQuiescence(); ScopeDiagnostics.stop(); ScopeDiagnosticsReport report = ScopeDiagnostics.report(); if (report.hasFindings()) { 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 index a9d83583bcf..d7e3c56595a 100644 --- 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 @@ -113,6 +113,20 @@ 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()) { @@ -153,6 +167,8 @@ private void appendHeader(StringBuilder sb, String title) { .append(" activate-after-resolve | scopes: ") .append(neverClosedScopeCount()) .append(" never-closed, ") + .append(deferredCleanupScopeCount()) + .append(" deferred, ") .append(closeWrongThreadCount()) .append(" wrong-thread)\n"); } @@ -315,6 +331,9 @@ private void appendScopeLine(StringBuilder sb, String indent, ScopeRecord scope) if (scope.threadHandoff()) { sb.append(" [handoff]"); } + if (scope.deferredCleanup() && !scope.closed()) { + sb.append(" [deferred-cleanup]"); + } if (!failures.isEmpty()) { sb.append(' ').append(failures); } 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 index 825a3444274..6d1e1d66116 100644 --- 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 @@ -18,6 +18,7 @@ public final class ScopeRecord { private final ScopeEvent open; private ScopeEvent close; + private boolean deferredCleanup; private final List wrongThreadCloses = new ArrayList<>(0); ScopeRecord( @@ -27,6 +28,7 @@ public final class ScopeRecord { String spanName, byte source, Long continuationSeq, + boolean deferredCleanup, ScopeEvent open) { this.seq = seq; this.traceId = traceId; @@ -34,6 +36,7 @@ public final class ScopeRecord { this.spanName = spanName; this.source = source; this.continuationSeq = continuationSeq; + this.deferredCleanup = deferredCleanup; this.open = open; } @@ -56,6 +59,7 @@ synchronized ScopeRecord snapshot() { spanName, source, continuationSeq, + deferredCleanup, open == null ? null : open.snapshot()); copy.close = close == null ? null : close.snapshot(); for (ScopeEvent event : wrongThreadCloses) { @@ -80,6 +84,14 @@ 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); @@ -95,7 +107,7 @@ public synchronized Long activeDurationNanos() { public synchronized EnumSet failures() { EnumSet failures = EnumSet.noneOf(Failure.class); - if (open != null && close == null) { + if (open != null && close == null && !deferredCleanup) { failures.add(Failure.NEVER_CLOSED); } if (!wrongThreadCloses.isEmpty()) { 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/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 index 33b050542d6..89a4af142bd 100644 --- 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 @@ -5,6 +5,7 @@ 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; @@ -12,6 +13,8 @@ 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; @@ -117,6 +120,74 @@ void scopeLifetimeRecordedAndLinkedToContinuation() { 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(); 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 index b3f1b0b4140..6af4a059c86 100644 --- 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 @@ -28,6 +28,7 @@ private static ScopeRecord scope(long seq, Long continuationSeq, String openThre "op", (byte) 0, continuationSeq, + false, event(ScopeEvent.Type.SCOPE_OPEN, openThread, nanos)); } @@ -63,6 +64,18 @@ void openWithoutCloseIsNeverClosed() { 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);