Skip to content

test(agent): reject when no matching trace arrives before the timeout#9177

Merged
tlhunter merged 7 commits into
masterfrom
BridgeAR/2026-07-01-fix-expectsomespan-zero-span-hang
Jul 14, 2026
Merged

test(agent): reject when no matching trace arrives before the timeout#9177
tlhunter merged 7 commits into
masterfrom
BridgeAR/2026-07-01-fix-expectsomespan-zero-span-hang

Conversation

@BridgeAR

@BridgeAR BridgeAR commented Jul 1, 2026

Copy link
Copy Markdown
Member

Summary

An assertSomeTraces / expectSomeSpan expectation whose span never arrives left the returned promise unsettled. The rejection timeout only fired when errors had accumulated (if (errors.length)), so with zero payloads the callback did nothing and the spec hung until Mocha's 5s per-test timeout killed it with a generic Timeout of 5000ms exceeded — instead of failing at the intended 1s window with the real cause.

The rejection timeout now always settles the promise: the accumulated first/aggregate error when a payload matched but assertions failed, and otherwise a fresh error naming the timeout window so a missing span reports No matching trace received within <timeoutMs>ms. The success and rejectFirst paths still clearTimeout before settling, so a cleared timer cannot reject an already-resolved promise.

Regression test in agent.spec.js loads the mock agent, calls assertSomeTraces with a 200ms timeout and no payload, and asserts it rejects with the new message well under 1s. On master the same test hangs the full 5s and fails with the generic Mocha timeout.

@dd-octo-sts

dd-octo-sts Bot commented Jul 1, 2026

Copy link
Copy Markdown
Contributor

Overall package size

Self size: 6.66 MB
Deduped: 7.32 MB
No deduping: 7.32 MB

Dependency sizes | name | version | self size | total size | |------|---------|-----------|------------| | import-in-the-middle | 3.3.1 | 122.62 kB | 437.94 kB | | opentracing | 0.14.7 | 194.81 kB | 194.81 kB | | dc-polyfill | 0.1.11 | 25.74 kB | 25.74 kB |

🤖 This report was automatically generated by heaviest-objects-in-the-universe

@datadog-official

datadog-official Bot commented Jul 1, 2026

Copy link
Copy Markdown

Tests

🎉 All green!

🧪 All tests passed
❄️ No new flaky tests detected

🎯 Code Coverage (details)
Patch Coverage: 100.00%
Overall Coverage: 96.50% (-0.00%)

This comment will be updated automatically if new data arrives.
🔗 Commit SHA: 1228f05 | Docs | Datadog PR Page | Give us feedback!

@pr-commenter

pr-commenter Bot commented Jul 1, 2026

Copy link
Copy Markdown

Benchmarks

Benchmark execution time: 2026-07-08 18:46:36

Comparing candidate commit 1228f05 in PR branch BridgeAR/2026-07-01-fix-expectsomespan-zero-span-hang with baseline commit a619775 in branch master.

📊 Benchmarking dashboard

Found 0 performance improvements and 0 performance regressions! Performance is the same for 2310 metrics, 48 unstable metrics.

Explanation

This is an A/B test comparing a candidate commit's performance against that of a baseline commit. Performance changes are noted in the tables below as:

  • 🟩 = significantly better candidate vs. baseline
  • 🟥 = significantly worse candidate vs. baseline

We compute a confidence interval (CI) over the relative difference of means between metrics from the candidate and baseline commits, considering the baseline as the reference.

If the CI is entirely outside the configured SIGNIFICANT_IMPACT_THRESHOLD (or the deprecated UNCONFIDENCE_THRESHOLD), the change is considered significant.

Feel free to reach out to #apm-benchmarking-platform on Slack if you have any questions.

More details about the CI and significant changes

You can imagine this CI as a range of values that is likely to contain the true difference of means between the candidate and baseline commits.

CIs of the difference of means are often centered around 0%, because often changes are not that big:

---------------------------------(------|---^--------)-------------------------------->
                              -0.6%    0%  0.3%     +1.2%
                                 |          |        |
         lower bound of the CI --'          |        |
sample mean (center of the CI) -------------'        |
         upper bound of the CI ----------------------'

As described above, a change is considered significant if the CI is entirely outside the configured SIGNIFICANT_IMPACT_THRESHOLD (or the deprecated UNCONFIDENCE_THRESHOLD).

For instance, for an execution time metric, this confidence interval indicates a significantly worse performance:

----------------------------------------|---------|---(---------^---------)---------->
                                       0%        1%  1.3%      2.2%      3.1%
                                                  |   |         |         |
       significant impact threshold --------------'   |         |         |
                      lower bound of CI --------------'         |         |
       sample mean (center of the CI) --------------------------'         |
                      upper bound of CI ----------------------------------'

Unstable benchmarks

These benchmarks have a confidence interval too wide to call a change; treat them as noise rather than signal.

scenario:appsec-appsec-enabled-24

  • unstable execution_time [-203.851ms; +209.194ms] or [-7.688%; +7.889%]

scenario:appsec-appsec-enabled-26

  • unstable execution_time [-231.007ms; +169.880ms] or [-9.182%; +6.752%]

scenario:appsec-appsec-enabled-with-attacks-26

  • unstable execution_time [-184.224ms; +196.048ms] or [-6.246%; +6.647%]

scenario:appsec-control-20

  • unstable execution_time [-121.489ms; +116.723ms] or [-7.388%; +7.098%]

scenario:appsec-control-24

  • unstable execution_time [-113.654ms; +120.409ms] or [-9.152%; +9.696%]

scenario:appsec-control-26

  • unstable execution_time [-124.039ms; +127.582ms] or [-10.010%; +10.296%]

scenario:appsec-iast-no-vulnerability-control-20

  • unstable execution_time [-13634.866µs; +14966.866µs] or [-5.296%; +5.813%]

scenario:appsec-iast-with-vulnerability-control-20

  • unstable execution_time [-30.989ms; +34.454ms] or [-5.560%; +6.182%]

scenario:child_process-file-args-24

  • unstable cpu_usage_percentage [-5.371%; +5.211%]
  • unstable execution_time [-30.758ms; +37.441ms] or [-6.498%; +7.910%]
  • unstable throughput [-123637.037op/s; +107797.265op/s] or [-5.609%; +4.891%]

scenario:debugger-line-probe-with-snapshot-default-24

  • unstable cpu_user_time [-1499.015ms; +500.863ms] or [-17.636%; +5.893%]
  • unstable execution_time [-1546.450ms; +501.827ms] or [-16.797%; +5.451%]
  • unstable instructions [-12.9G instructions; +4.3G instructions] or [-18.622%; +6.225%]
  • unstable throughput [-162.501op/s; +466.281op/s] or [-4.578%; +13.135%]

scenario:debugger-line-probe-with-snapshot-default-26

  • unstable cpu_user_time [-2005.924ms; +648.451ms] or [-21.262%; +6.873%]
  • unstable execution_time [-2040.590ms; +617.158ms] or [-20.109%; +6.082%]
  • unstable instructions [-17.9G instructions; +5.8G instructions] or [-22.676%; +7.405%]
  • unstable throughput [-198.057op/s; +408.917op/s] or [-6.155%; +12.709%]

scenario:debugger-line-probe-with-snapshot-minimal-24

  • unstable cpu_user_time [-1532.743ms; +398.756ms] or [-17.656%; +4.593%]
  • unstable execution_time [-1586.200ms; +439.117ms] or [-16.864%; +4.669%]
  • unstable instructions [-13.1G instructions; +3.3G instructions] or [-18.499%; +4.694%]
  • unstable throughput [-139.305op/s; +483.813op/s] or [-4.016%; +13.947%]

scenario:debugger-line-probe-with-snapshot-minimal-26

  • unstable cpu_user_time [-1842.413ms; +594.955ms] or [-19.676%; +6.354%]
  • unstable execution_time [-1839.259ms; +595.934ms] or [-18.249%; +5.913%]
  • unstable instructions [-18.0G instructions; +5.8G instructions] or [-22.857%; +7.422%]
  • unstable throughput [-131.033op/s; +401.740op/s] or [-4.023%; +12.335%]

scenario:debugger-line-probe-without-snapshot-24

  • unstable cpu_user_time [-2515.577ms; +2703.471ms] or [-27.971%; +30.060%]
  • unstable execution_time [-2534.953ms; +2704.073ms] or [-26.089%; +27.830%]
  • unstable instructions [-21431.6M instructions; +23126.9M instructions] or [-28.982%; +31.275%]
  • unstable max_rss_usage [-11589.105KB; +11422.705KB] or [-7.263%; +7.159%]
  • unstable throughput [-739.257op/s; +661.497op/s] or [-21.459%; +19.202%]

scenario:debugger-line-probe-without-snapshot-26

  • unstable cpu_user_time [-2.743s; +5.205s] or [-23.824%; +45.213%]
  • unstable execution_time [-2.850s; +5.330s] or [-23.240%; +43.457%]
  • unstable instructions [-24.3G instructions; +46.0G instructions] or [-24.926%; +47.266%]
  • unstable max_rss_usage [-8.883MB; +16.222MB] or [-5.364%; +9.796%]
  • unstable throughput [-1100.756op/s; +576.053op/s] or [-39.048%; +20.435%]

scenario:dogstatsd-with-tags-20

  • unstable cpu_user_time [-405.718ms; +237.298ms] or [-8.460%; +4.948%]
  • unstable execution_time [-401.243ms; +235.296ms] or [-8.234%; +4.828%]
  • unstable throughput [-81444.065op/s; +137299.680op/s] or [-4.731%; +7.976%]

scenario:iast-sink-check-26

  • unstable execution_time [-176.700ms; +215.525ms] or [-4.794%; +5.848%]

scenario:plugin-graphql-long-with-depth-off-20

  • unstable max_rss_usage [-9.023MB; +4.138MB] or [-6.899%; +3.164%]

scenario:plugin-graphql-long-with-depth-on-max-20

  • unstable cpu_user_time [-706.420ms; +718.464ms] or [-5.528%; +5.622%]
  • unstable execution_time [-715.671ms; +718.451ms] or [-5.479%; +5.500%]
  • unstable throughput [-3.334op/s; +3.322op/s] or [-5.412%; +5.391%]

scenario:plugin-mongodb-core-plain-find-26

  • unstable execution_time [-116.357ms; +162.573ms] or [-5.574%; +7.788%]
  • unstable throughput [-244855.219op/s; +187473.770op/s] or [-6.184%; +4.735%]

scenario:test-optimization-large-suite-20

  • unstable max_rss_usage [-6.377MB; +2.945MB] or [-7.931%; +3.663%]

@codecov

codecov Bot commented Jul 1, 2026

Copy link
Copy Markdown

Codecov Report

✅ All modified and coverable lines are covered by tests.
✅ Project coverage is 96.54%. Comparing base (a619775) to head (1228f05).
⚠️ Report is 6 commits behind head on master.

Additional details and impacted files
@@            Coverage Diff             @@
##           master    #9177      +/-   ##
==========================================
- Coverage   96.54%   96.54%   -0.01%     
==========================================
  Files         915      915              
  Lines      121018   121034      +16     
  Branches    20693    20600      -93     
==========================================
+ Hits       116837   116849      +12     
- Misses       4181     4185       +4     
Flag Coverage Δ
aiguard 53.56% <ø> (-0.06%) ⬇️
aiguard-integration 57.00% <ø> (-0.01%) ⬇️
apm-bucket-0 53.79% <ø> (-0.06%) ⬇️
apm-bucket-1 58.09% <ø> (-0.06%) ⬇️
apm-bucket-2 56.11% <ø> (-0.06%) ⬇️
apm-capabilities-tracing 60.34% <ø> (+0.04%) ⬆️
apm-integrations-aerospike 52.94% <ø> (-0.06%) ⬇️
apm-integrations-confluentinc-kafka-javascript 57.00% <ø> (-0.06%) ⬇️
apm-integrations-couchbase 53.26% <ø> (-0.06%) ⬇️
apm-integrations-http 57.98% <ø> (-0.05%) ⬇️
apm-integrations-kafkajs 57.72% <ø> (-0.08%) ⬇️
apm-integrations-next 54.24% <ø> (-0.06%) ⬇️
apm-integrations-prisma 54.18% <ø> (-0.06%) ⬇️
apm-integrations-tedious 53.04% <ø> (-0.06%) ⬇️
appsec 69.02% <ø> (-0.11%) ⬇️
appsec-express_fastify_graphql 65.69% <ø> (-0.05%) ⬇️
appsec-integration 45.50% <ø> (-0.01%) ⬇️
appsec-kafka_ldapjs_lodash 59.12% <ø> (-0.05%) ⬇️
appsec-mongodb-core_mongoose_mysql 62.28% <ø> (-0.05%) ⬇️
appsec-next 52.86% <ø> (-0.05%) ⬇️
appsec-node-serialize_passport_postgres 61.92% <ø> (-0.05%) ⬇️
appsec-sourcing_stripe_template 60.27% <ø> (-0.05%) ⬇️
debugger 65.69% <ø> (-0.03%) ⬇️
instrumentations-bucket-0 48.75% <ø> (-0.06%) ⬇️
instrumentations-bucket-1 54.97% <ø> (-0.06%) ⬇️
instrumentations-bucket-10 56.64% <ø> (-0.06%) ⬇️
instrumentations-bucket-11 48.74% <ø> (-0.06%) ⬇️
instrumentations-bucket-12 48.84% <ø> (-0.06%) ⬇️
instrumentations-bucket-13 48.67% <ø> (-0.06%) ⬇️
instrumentations-bucket-2 49.73% <ø> (-0.06%) ⬇️
instrumentations-bucket-3 53.83% <ø> (-0.06%) ⬇️
instrumentations-bucket-4 49.16% <ø> (-0.06%) ⬇️
instrumentations-bucket-5 53.01% <ø> (-0.05%) ⬇️
instrumentations-bucket-6 55.62% <ø> (-0.06%) ⬇️
instrumentations-bucket-7 53.60% <ø> (-0.06%) ⬇️
instrumentations-bucket-8 54.64% <ø> (-0.06%) ⬇️
instrumentations-bucket-9 56.10% <ø> (-0.05%) ⬇️
instrumentations-instrumentation-couchbase 48.17% <ø> (-0.06%) ⬇️
instrumentations-integration-esbuild 33.90% <ø> (-0.01%) ⬇️
llmobs-ai_anthropic_bedrock 57.75% <ø> (-0.05%) ⬇️
llmobs-bucket-1 56.81% <ø> (-0.05%) ⬇️
llmobs-openai 57.58% <ø> (-0.05%) ⬇️
llmobs-sdk 59.98% <ø> (-0.06%) ⬇️
llmobs-vertex-ai 54.22% <ø> (-0.06%) ⬇️
master-coverage 96.54% <ø> (?)
openfeature 54.61% <ø> (-0.01%) ⬇️
openfeature-unit 49.82% <ø> (-0.06%) ⬇️
platform-core_esbuild_instrumentations-misc 38.40% <ø> (-0.02%) ⬇️
platform-integration 62.18% <ø> (-0.01%) ⬇️
platform-shimmer_unit-guardrails_webpack 37.19% <ø> (-0.03%) ⬇️
plugins-bucket-0 53.18% <ø> (-0.05%) ⬇️
plugins-bucket-1 55.07% <ø> (-0.02%) ⬇️
plugins-bucket-11 56.73% <ø> (-0.06%) ⬇️
plugins-bucket-17 56.75% <ø> (-0.06%) ⬇️
plugins-bucket-18 57.60% <ø> (-0.06%) ⬇️
plugins-bucket-19 57.13% <ø> (-0.06%) ⬇️
plugins-bucket-20 59.38% <ø> (-0.06%) ⬇️
plugins-bucket-4 53.85% <ø> (-0.06%) ⬇️
plugins-bullmq_cassandra_cookie 57.40% <ø> (-0.06%) ⬇️
plugins-cookie-parser_crypto_dd-trace-api 52.32% <ø> (-0.06%) ⬇️
plugins-fetch_fs_generic-pool 54.54% <ø> (-0.06%) ⬇️
plugins-google-cloud-pubsub_grpc_handlebars 59.88% <ø> (-0.06%) ⬇️
plugins-hapi_hono_ioredis 55.87% <ø> (-0.06%) ⬇️
plugins-jest_knex_langgraph 51.66% <ø> (-0.06%) ⬇️
plugins-ldapjs_light-my-request_limitd-client 53.44% <ø> (-0.04%) ⬇️
plugins-lodash_mariadb_memcached 54.21% <ø> (-0.06%) ⬇️
plugins-mongodb_mongodb-core_mongoose 55.46% <ø> (-0.06%) ⬇️
plugins-multer_mysql_mysql2 54.37% <ø> (-0.06%) ⬇️
plugins-nats_node-serialize_opensearch 56.07% <ø> (-0.06%) ⬇️
plugins-passport-http_pino_postgres 54.75% <ø> (-0.06%) ⬇️
plugins-process_pug_redis 53.87% <ø> (-0.07%) ⬇️
plugins-undici_url_valkey 54.30% <ø> (-0.14%) ⬇️
plugins-vm_winston_ws 55.27% <ø> (-0.06%) ⬇️
profiling 58.21% <ø> (-0.06%) ⬇️
serverless-aws-sdk-aws-sdk 50.67% <ø> (-0.04%) ⬇️
serverless-aws-sdk-bedrockruntime 50.68% <ø> (-0.05%) ⬇️
serverless-aws-sdk-client 51.95% <ø> (-0.06%) ⬇️
serverless-aws-sdk-dynamodb 51.86% <ø> (+0.05%) ⬆️
serverless-aws-sdk-eventbridge 46.22% <ø> (-0.05%) ⬇️
serverless-aws-sdk-kinesis 54.70% <ø> (-0.06%) ⬇️
serverless-aws-sdk-lambda 52.78% <ø> (-0.05%) ⬇️
serverless-aws-sdk-s3 51.52% <ø> (-0.05%) ⬇️
serverless-aws-sdk-serverless-peer-service 54.76% <ø> (-0.02%) ⬇️
serverless-aws-sdk-sns 55.48% <ø> (-0.06%) ⬇️
serverless-aws-sdk-sqs 55.91% <ø> (-0.06%) ⬇️
serverless-aws-sdk-stepfunctions 51.25% <ø> (-0.05%) ⬇️
serverless-aws-sdk-util 48.45% <ø> (-0.06%) ⬇️
serverless-bucket-0 55.24% <ø> (-0.02%) ⬇️
serverless-bucket-1 56.02% <ø> (-0.06%) ⬇️
test-optimization-cucumber 72.97% <ø> (-0.01%) ⬇️
test-optimization-cypress 66.45% <ø> (+0.06%) ⬆️
test-optimization-jest 73.89% <ø> (-0.06%) ⬇️
test-optimization-mocha 74.31% <ø> (+0.03%) ⬆️
test-optimization-playwright-playwright-atr 61.60% <ø> (+<0.01%) ⬆️
test-optimization-playwright-playwright-efd 61.79% <ø> (+0.01%) ⬆️
test-optimization-playwright-playwright-final-status 61.74% <ø> (+<0.01%) ⬆️
test-optimization-playwright-playwright-impacted-tests 61.47% <ø> (+0.17%) ⬆️
test-optimization-playwright-playwright-reporting 61.37% <ø> (-0.19%) ⬇️
test-optimization-playwright-playwright-test-management 62.28% <ø> (-0.11%) ⬇️
test-optimization-playwright-playwright-test-span 61.50% <ø> (-0.06%) ⬇️
test-optimization-selenium 60.69% <ø> (-0.18%) ⬇️
test-optimization-testopt 59.16% <ø> (+0.09%) ⬆️
test-optimization-vitest 72.75% <ø> (+0.02%) ⬆️

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Harness.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.
  • 📦 JS Bundle Analysis: Save yourself from yourself by tracking and limiting bundle sizes in JS merges.

@BridgeAR
BridgeAR marked this pull request as ready for review July 1, 2026 23:57
@BridgeAR
BridgeAR requested review from a team as code owners July 1, 2026 23:57
@BridgeAR
BridgeAR requested review from bojbrook and removed request for a team July 1, 2026 23:57

@chatgpt-codex-connector chatgpt-codex-connector Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

💡 Codex Review

Here are some automated review suggestions for this pull request.

Reviewed commit: 34e4dc98f0

ℹ️ About Codex in GitHub

Codex has been enabled to automatically review pull requests in this repo. Reviews are triggered when you

  • Open a pull request for review
  • Mark a draft as ready
  • Comment "@codex review".

If Codex has suggestions, it will comment; otherwise it will react with 👍.

When you sign up for Codex through ChatGPT, Codex can also answer questions or update the PR, like "@codex address that feedback".

Comment thread packages/dd-trace/test/plugins/agent.js
juan-fernandez
juan-fernandez previously approved these changes Jul 2, 2026
BridgeAR added 2 commits July 4, 2026 00:11
An `assertSomeTraces` / `expectSomeSpan` expectation whose span never
arrives left the returned promise unsettled: the rejection timeout only
fired when errors had accumulated, so with zero payloads the callback did
nothing and the spec hung until Mocha's 5s per-test timeout killed it with
a generic "Timeout of 5000ms exceeded" instead of failing at the intended
1s window with the real cause.

The rejection timeout now always settles the promise: the accumulated
first/aggregate error when a payload matched but assertions failed, and
otherwise a fresh error naming the timeout window so a missing span points
the reader at "no matching trace received within <timeoutMs>ms".
…t reject

Rejecting the assertSomeTraces promise at its timeout broke tests that relied on
the previous never-settling behaviour:

1. "Should not be traced" cases registered an expectation that must never match,
   left the promise unawaited, and passed via a separate setTimeout(done). The
   reject now fires into that path, calling done() twice or surfacing a stray
   "No matching trace". A new assertNoTraces resolves when nothing matches before
   the timeout and rejects only when a forbidden trace arrives; the negative
   sites move to it.
2. Positive tests whose span legitimately lands after 1s (restify <5 uncaught
   exceptions ~5s, the openai/anthropic dead-baseURL retry backoff, kafka
   consumer delivery, aws-sdk cold connect, the http Node-20 timeout cases) now
   set an explicit timeoutMs. openai/anthropic instead drop retries with
   maxRetries: 0 since the endpoint is dead on purpose. The LLMObs harness gets a
   longer window because every call is a real VCR round-trip.
3. mongodb-core's BigInt test returns done() early on the version that throws
   synchronously; the assertion now registers only once the command starts, so
   no expectation is left to reject afterwards.
@BridgeAR
BridgeAR force-pushed the BridgeAR/2026-07-01-fix-expectsomespan-zero-span-hang branch from 34e4dc9 to 15230c5 Compare July 3, 2026 22:13
@BridgeAR
BridgeAR requested a review from a team as a code owner July 3, 2026 22:13
An assertSomeTraces expectation that is armed but never consumed can keep its rejection timer running after the test ends. The timer then rejects a promise nobody awaits a whole timeout window later, surfacing as an unhandled rejection on an unrelated test.

1. Each expectation promise carries a cancel() that disarms its timer and drops the handler; the consumer that armed it cancels it in its own teardown.
2. The framework reset() disarms every still-armed expectation, then throws to fail the just-finished test by name. Bare subscribe() handlers have no timer and are never counted.
3. The invalid-type SDK test no longer races getEvents() against a timeout, which abandoned a poll loop that kept draining span requests and starving later tests.
@BridgeAR
BridgeAR force-pushed the BridgeAR/2026-07-01-fix-expectsomespan-zero-span-hang branch from 15230c5 to ce22372 Compare July 3, 2026 22:19
This PR's teardown leak guard counts any handler left in the set as armed, but
runCallbackAgainstTraces kept its handler on the timeout and rejectFirst settle
paths, so the guard rejected expectations it had already settled. Drop the
handler on every settle path.

With the guard trustworthy, three specs leaked real expectations:

1. aws-sdk sqs: timeoutMs sat on `.catch()` rather than assertSomeTraces, so the
   suppressed-consumer expectation ran on the 1000ms default and stayed armed past
   the 250ms done().
2. google-cloud-pubsub dsm and index: the DSM checkpoint expectations were never
   awaited. Register before publishing, then await, and read the expected pathway
   hash little-endian to match DataStreamsProcessor's readBigUInt64LE decode.
@BridgeAR
BridgeAR requested a review from a team as a code owner July 7, 2026 21:33
BridgeAR and others added 3 commits July 8, 2026 10:52
`should allow disabling a specific service` and its sqs consumer-span-kind sibling
paired two fire-and-forget assertSomeTraces expectations on a 100ms window with a
fixed setTimeout(done, 250) asserting a match counter. On a cold localstack the
enabled request's span lands after the 100ms window, so its expectation times out,
the counter stays 0, and the guard asserts 0 !== 1.

Assert the disabled request's absence with assertNoTraces and await the enabled
request's assertSomeTraces, which is what assertNoTraces documents in place of a
bare assertSomeTraces plus a separate setTimeout(done, …).
…e timeout

This PR makes assertSomeTraces reject at its timeout instead of waiting out the
mocha deadline. The full-agentic-call test registers the expectation, then spawns
the claude subprocess and runs several steps before the trace flushes, which takes
longer than the 1000ms default, so the expectation rejected before the trace ever
arrived. Opt into a 10s timeoutMs and raise the block's mocha timeout to 15s.
@tlhunter
tlhunter merged commit 1abef82 into master Jul 14, 2026
687 of 689 checks passed
@tlhunter
tlhunter deleted the BridgeAR/2026-07-01-fix-expectsomespan-zero-span-hang branch July 14, 2026 19:46
This was referenced Jul 15, 2026
juan-fernandez pushed a commit that referenced this pull request Jul 16, 2026
…#9177)

* test(agent): reject when no matching trace arrives before the timeout

An `assertSomeTraces` / `expectSomeSpan` expectation whose span never
arrives left the returned promise unsettled: the rejection timeout only
fired when errors had accumulated, so with zero payloads the callback did
nothing and the spec hung until Mocha's 5s per-test timeout killed it with
a generic "Timeout of 5000ms exceeded" instead of failing at the intended
1s window with the real cause.

The rejection timeout now always settles the promise: the accumulated
first/aggregate error when a payload matched but assertions failed, and
otherwise a fresh error naming the timeout window so a missing span points
the reader at "no matching trace received within <timeoutMs>ms".

* test(agent): add assertNoTraces and give slow spans room after timeout reject

Rejecting the assertSomeTraces promise at its timeout broke tests that relied on
the previous never-settling behaviour:

1. "Should not be traced" cases registered an expectation that must never match,
   left the promise unawaited, and passed via a separate setTimeout(done). The
   reject now fires into that path, calling done() twice or surfacing a stray
   "No matching trace". A new assertNoTraces resolves when nothing matches before
   the timeout and rejects only when a forbidden trace arrives; the negative
   sites move to it.
2. Positive tests whose span legitimately lands after 1s (restify <5 uncaught
   exceptions ~5s, the openai/anthropic dead-baseURL retry backoff, kafka
   consumer delivery, aws-sdk cold connect, the http Node-20 timeout cases) now
   set an explicit timeoutMs. openai/anthropic instead drop retries with
   maxRetries: 0 since the endpoint is dead on purpose. The LLMObs harness gets a
   longer window because every call is a real VCR round-trip.
3. mongodb-core's BigInt test returns done() early on the version that throws
   synchronously; the assertion now registers only once the command starts, so
   no expectation is left to reject afterwards.

* test(agent): fail loudly on leaked trace expectations

An assertSomeTraces expectation that is armed but never consumed can keep its rejection timer running after the test ends. The timer then rejects a promise nobody awaits a whole timeout window later, surfacing as an unhandled rejection on an unrelated test.

1. Each expectation promise carries a cancel() that disarms its timer and drops the handler; the consumer that armed it cancels it in its own teardown.
2. The framework reset() disarms every still-armed expectation, then throws to fail the just-finished test by name. Bare subscribe() handlers have no timer and are never counted.
3. The invalid-type SDK test no longer races getEvents() against a timeout, which abandoned a poll loop that kept draining span requests and starving later tests.

* test(agent): drop settled handlers and fix the leaks the guard exposed

This PR's teardown leak guard counts any handler left in the set as armed, but
runCallbackAgainstTraces kept its handler on the timeout and rejectFirst settle
paths, so the guard rejected expectations it had already settled. Drop the
handler on every settle path.

With the guard trustworthy, three specs leaked real expectations:

1. aws-sdk sqs: timeoutMs sat on `.catch()` rather than assertSomeTraces, so the
   suppressed-consumer expectation ran on the 1000ms default and stayed armed past
   the 250ms done().
2. google-cloud-pubsub dsm and index: the DSM checkpoint expectations were never
   awaited. Register before publishing, then await, and read the expected pathway
   hash little-endian to match DataStreamsProcessor's readBigUInt64LE decode.

* test(aws-sdk): make the disabling tests deterministic

`should allow disabling a specific service` and its sqs consumer-span-kind sibling
paired two fire-and-forget assertSomeTraces expectations on a 100ms window with a
fixed setTimeout(done, 250) asserting a match counter. On a cold localstack the
enabled request's span lands after the 100ms window, so its expectation times out,
the counter stays 0, and the guard asserts 0 !== 1.

Assert the disabled request's absence with assertNoTraces and await the enabled
request's assertSomeTraces, which is what assertNoTraces documents in place of a
bare assertSomeTraces plus a separate setTimeout(done, …).

* test(claude-agent-sdk): give the agentic-call assertion room under the timeout

This PR makes assertSomeTraces reject at its timeout instead of waiting out the
mocha deadline. The full-agentic-call test registers the expectation, then spawns
the claude subprocess and runs several steps before the trace flushes, which takes
longer than the 1000ms default, so the expectation rejected before the trace ever
arrived. Opt into a 10s timeoutMs and raise the block's mocha timeout to 15s.
juan-fernandez pushed a commit that referenced this pull request Jul 16, 2026
…#9177)

* test(agent): reject when no matching trace arrives before the timeout

An `assertSomeTraces` / `expectSomeSpan` expectation whose span never
arrives left the returned promise unsettled: the rejection timeout only
fired when errors had accumulated, so with zero payloads the callback did
nothing and the spec hung until Mocha's 5s per-test timeout killed it with
a generic "Timeout of 5000ms exceeded" instead of failing at the intended
1s window with the real cause.

The rejection timeout now always settles the promise: the accumulated
first/aggregate error when a payload matched but assertions failed, and
otherwise a fresh error naming the timeout window so a missing span points
the reader at "no matching trace received within <timeoutMs>ms".

* test(agent): add assertNoTraces and give slow spans room after timeout reject

Rejecting the assertSomeTraces promise at its timeout broke tests that relied on
the previous never-settling behaviour:

1. "Should not be traced" cases registered an expectation that must never match,
   left the promise unawaited, and passed via a separate setTimeout(done). The
   reject now fires into that path, calling done() twice or surfacing a stray
   "No matching trace". A new assertNoTraces resolves when nothing matches before
   the timeout and rejects only when a forbidden trace arrives; the negative
   sites move to it.
2. Positive tests whose span legitimately lands after 1s (restify <5 uncaught
   exceptions ~5s, the openai/anthropic dead-baseURL retry backoff, kafka
   consumer delivery, aws-sdk cold connect, the http Node-20 timeout cases) now
   set an explicit timeoutMs. openai/anthropic instead drop retries with
   maxRetries: 0 since the endpoint is dead on purpose. The LLMObs harness gets a
   longer window because every call is a real VCR round-trip.
3. mongodb-core's BigInt test returns done() early on the version that throws
   synchronously; the assertion now registers only once the command starts, so
   no expectation is left to reject afterwards.

* test(agent): fail loudly on leaked trace expectations

An assertSomeTraces expectation that is armed but never consumed can keep its rejection timer running after the test ends. The timer then rejects a promise nobody awaits a whole timeout window later, surfacing as an unhandled rejection on an unrelated test.

1. Each expectation promise carries a cancel() that disarms its timer and drops the handler; the consumer that armed it cancels it in its own teardown.
2. The framework reset() disarms every still-armed expectation, then throws to fail the just-finished test by name. Bare subscribe() handlers have no timer and are never counted.
3. The invalid-type SDK test no longer races getEvents() against a timeout, which abandoned a poll loop that kept draining span requests and starving later tests.

* test(agent): drop settled handlers and fix the leaks the guard exposed

This PR's teardown leak guard counts any handler left in the set as armed, but
runCallbackAgainstTraces kept its handler on the timeout and rejectFirst settle
paths, so the guard rejected expectations it had already settled. Drop the
handler on every settle path.

With the guard trustworthy, three specs leaked real expectations:

1. aws-sdk sqs: timeoutMs sat on `.catch()` rather than assertSomeTraces, so the
   suppressed-consumer expectation ran on the 1000ms default and stayed armed past
   the 250ms done().
2. google-cloud-pubsub dsm and index: the DSM checkpoint expectations were never
   awaited. Register before publishing, then await, and read the expected pathway
   hash little-endian to match DataStreamsProcessor's readBigUInt64LE decode.

* test(aws-sdk): make the disabling tests deterministic

`should allow disabling a specific service` and its sqs consumer-span-kind sibling
paired two fire-and-forget assertSomeTraces expectations on a 100ms window with a
fixed setTimeout(done, 250) asserting a match counter. On a cold localstack the
enabled request's span lands after the 100ms window, so its expectation times out,
the counter stays 0, and the guard asserts 0 !== 1.

Assert the disabled request's absence with assertNoTraces and await the enabled
request's assertSomeTraces, which is what assertNoTraces documents in place of a
bare assertSomeTraces plus a separate setTimeout(done, …).

* test(claude-agent-sdk): give the agentic-call assertion room under the timeout

This PR makes assertSomeTraces reject at its timeout instead of waiting out the
mocha deadline. The full-agentic-call test registers the expectation, then spawns
the claude subprocess and runs several steps before the trace flushes, which takes
longer than the 1000ms default, so the expectation rejected before the trace ever
arrived. Opt into a 10s timeoutMs and raise the block's mocha timeout to 15s.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants