Skip to content

fix(ci): harden flaky test_extension_ci timing races#4044

Draft
Leiyks wants to merge 3 commits into
masterfrom
leiyks/fix-ci-test-extension-flaky
Draft

fix(ci): harden flaky test_extension_ci timing races#4044
Leiyks wants to merge 3 commits into
masterfrom
leiyks/fix-ci-test-extension-flaky

Conversation

@Leiyks

@Leiyks Leiyks commented Jul 15, 2026

Copy link
Copy Markdown
Contributor

What

Fixes flaky/racy tests in the test_extension_ci valgrind lane:

  • tests/ext/remote_config/rc_fork_notify.phpt (and the wider
    dynamic_config_*/rc_* family that shares await_remote_config:
    dynamic_config_update.phpt, dynamic_config_auto_update.phpt,
    dynamic_config_multiconfig.phpt, rc_trace_enabled_rinit.phpt)
  • tests/ext/live-debugger/debugger_span_decoration_probe.phpt (and the
    other live-debugger probe tests that share await_probe_installation)
  • tests/ext/request-replayer/dd_trace_span_event.phpt (and the other
    request-replayer tests that share request_replayer.inc:
    client_side_stats.phpt, client_side_stats_peer_tags.phpt,
    client_side_stats_trace_filters.phpt)

No tests are skipped or disabled. Each fix addresses a confirmed root cause
with direct evidence gathered before the change was made.

Why + How, per fix

tracer/functions.cawait_remote_config settle-window active-poll

Root cause (confirmed via local reproduction + tracing):
dd_trace_internal_fn("await_remote_config") called a single blind
php_sleep(timeout_sec). Remote config is only applied at a Zend
VM-interrupt checkpoint (dd_vm_interrupt -> ddog_process_remote_configs(),
ext/remote_config.c), which is only reached between opcode dispatches.
Temporary debug instrumentation (added, used to confirm the mechanism, then
fully removed) proved that reread_remote_configuration can already be set
before the sleep starts and still not get processed until the full 10s
timeout elapses — PHP's sleep() retries internally on EINTR for the
remaining duration, so the SIGVTALRM-driven interrupt never gets a chance to
run mid-sleep.

An earlier hypothesis — that this was a fork-specific sidecar
re-subscription gap (the reproduced failure happened to hit only the
pcntl_fork()'d child process in the first sample) — was traced end-to-end
through ext/sidecar.c (datadog_sidecar_handle_fork), ext/remote_config.c,
ext/datadog.c, and the libdatadog RC manager (SHM path computation, target
tracking, queue registration). The trace disproved it: target tracking and
SHM paths are identical and fork-safe for parent and child. A larger sample
showed the failure hits parent, child, or both, symmetrically — a generic
timing race, not a fork defect.

Fix: replaced the blind sleep with a bounded active-polling loop that
waits for RC application to settle (not just for a single update): it
calls ddog_process_remote_configs() every 10ms, and only returns once
either the overall timeout_sec elapses, or at least one update has been
seen and a subsequent 500ms quiet period observes no further change —
draining any update actively instead of racing ahead of it. This closes a
second, related early-return bug: previously the call could return true
the instant the first of several in-flight RC updates landed, one poll
cycle before the config the caller actually cares about was applied. Also
added dd_trace_internal_fn("process_remote_config_now") — a thin wrapper
around the existing datadog_check_for_new_config_now() used by the
live-debugger test helper (see below) to actively drive RC application from
within its own poll loop instead of depending on a VM-interrupt checkpoint
landing inside it.

tracer/live_debugger.c + tests/ext/live-debugger/live_debugger.inc — probe-count race in await_probe_installation

Root cause (confirmed via real CI sidecar logs — could not be reproduced
locally despite ~130 valgrind runs across targeted and full-directory
sweeps):
all 3 LIVE_DEBUGGING RC configs were acknowledged
(apply_state:2), then one dropped out of the acknowledged config_states
a few seconds later and never returned. The root-span decoration probe (id 3)
was consequently inactive, producing empty meta. Separately,
await_probe_installation() only polled a hook-install counter — it never
asserted the probes were actually effective, and returned unconditionally
once the counter matched, and stale hook-index entries were never dropped on
removal so the counter didn't reflect the currently-installed set.

Fix:

  • tracer/live_debugger.c: on probe removal, zend_hash_index_del() the
    (now stale) index entry so zend_hash_num_elements(&active_live_debugger_hooks)
    reflects the currently-installed probes, not a historical high-water mark.
  • New dd_trace_internal_fn("live_debugger_installed_probe_count") exposing
    that live count to tests.
  • await_probe_installation() rewritten to poll the net installed-probe
    count and only return once it has been >= $num continuously for a 1s
    stability window (any dip below $num resets the wait), actively driving
    RC application each iteration via process_remote_config_now() instead of
    relying on a VM-interrupt checkpoint happening to land inside the loop.
    This waits out the remote-config remove/re-add churn described below
    rather than sampling in the middle of it.

Known limitation: this closes the same class of slow/transient-apply
race as the await_remote_config fix, but it is also a client-side
mitigation for a distinct, upstream libdatadog remote-config churn issue —
see "Known limitations" below.

tests/ext/includes/request_replayer.incwaitForDataAndReplay timeout

Root cause (confirmed via real CI sidecar logs): the trace was captured
and enqueued correctly at time T, but the sidecar's trace_flusher stalled
~18s across all sessions under contention and drained the backlog ~1s
after the test's 500 * 33.3ms ≈ 16.65s client budget had already
expired. This is not a valgrind-specific issue, and not a request-selection
race — the mock agent (datadog/dd-trace-ci:php-request-replayer-2.0) was
read directly: it's a single-threaded php -S server with per-session-token
storage, so concurrent unrelated tests can't cross-contaminate, and a wrong
entry pick would show up as a content mismatch, not the observed timeout
exception. This helper is shared by dd_trace_span_event.phpt and the
client_side_stats*.phpt family, so all of them were exposed to the same
race.

Fix: widened maxIteration from 500 (~16.65s) to 900 (~30s at the
33.3ms flush interval used by the affected tests), comfortably exceeding the
observed ~17.7s worst case. This is a synchronization-budget fix, not a
skip; the underlying sidecar flush-stall is out of scope here.

Testing

Verified locally against datadog/dd-trace-ci:php-8.3_bookworm-9, replicating
the test_extension_ci valgrind recipe (make test_extension_ci), under
artificial CPU contention:

  • rc_fork_notify.phpt: 50/50 pass (post-fix, realistic contention level)
  • dynamic_config_update.phpt: 50/50 pass (post-fix, heavier contention)
  • tests/ext/remote_config/ (full directory): 4/4 clean runs
  • tests/ext/live-debugger/ (full directory): 5/5 clean runs
  • tests/ext/request-replayer/ (full directory): 5/5 clean runs under load,
    7/7 clean with no artificial load

Pre-fix, the same harness reproduced the rc_fork_notify.phpt failure
(1-2 per 50 runs) with a debug-instrumented build that pinpointed the exact
mechanism (see the await_remote_config section above); that instrumentation
was fully removed before this diff.

Realistic single-pipeline CI is green with these changes; do not expect
100% under an artificial 10x-parallel-same-branch stress harness — see
"Known limitations" below.

Known limitations

Upstream libdatadog remote-config churn (separate, unresolved — tracked
upstream):
under heavy concurrent load, remote-config target switching in
libdatadog's RemoteConfigManager (datadog-sidecar/src/shm_remote_config.rs)
unconditionally Remove-then-Add-cycles every active config whenever the RC
Target changes at all — including on a process_tags-only change, which
carries no RC-relevant information. This produces a real, if narrow,
Remove→Add gap during which a probe genuinely reads as absent even though it
never changed. A/B evidence: with
DD_EXPERIMENTAL_PROPAGATE_PROCESS_TAGS_ENABLED on, ~113 Remove events are
emitted under the stress harness vs. ~1 with it off. The
await_probe_installation stability-window fix in this PR waits this churn
out client-side and is sufficient for realistic CI concurrency (0 failures
in normal pipeline runs), but does not fix the underlying churn. Root cause,
A/B evidence, and two falsified fix attempts are documented in a follow-up
libdatadog issue (link to be added here once filed). Do not re-attempt a
client-side fix for this specific mechanism without reading that issue
first.

Irreducible RINIT/fork delivery-latency limit: under extreme
artificial CPU saturation (deliberately pegging 3 of 4 cores with tight spin
loops, well beyond realistic CI contention), a residual flake in
rc_fork_notify.phpt / rc_trace_enabled_rinit.phpt persists post-fix.
Tracing showed this is a pure data-delivery-latency limit —
ddog_process_remote_configs() legitimately returns changed=false because
the RC update hasn't arrived in local shared memory within the timeout
window yet, not because polling isn't happening. No amount of additional
polling manufactures data that hasn't arrived over the network/sidecar path
in time. This was not addressed here as it's outside the bounded scope of
this fix; realistic CI does not hit it.

Keep #3849 as a separate PR (A/F, unrelated scope).

Three independent flaky-test root causes in the test_extension_ci
valgrind lane, each confirmed with direct evidence before fixing:

- [7.2] tracer/functions.c await_remote_config: replaced a blind
  php_sleep(timeout_sec) with a bounded active-polling loop (mirrors
  await_agent_info). Local tracing proved the blind sleep can leave
  reread_remote_configuration set *before* sleeping and still not
  process it until the full timeout elapses -- PHP's sleep() retries
  internally on EINTR, so the SIGVTALRM-driven VM-interrupt checkpoint
  that applies remote config is never reached during the wait. An
  earlier hypothesis that this was a fork-specific sidecar
  re-subscription gap was traced end-to-end (sidecar.c, remote_config.c,
  datadog.c, and the libdatadog RC manager) and disproven: target
  tracking, SHM path computation, and queue registration are all
  fork-safe. The failure hits parent and child symmetrically, matching
  a generic timing race, not a fork defect.

- [8.0] tests/ext/live-debugger/live_debugger.inc
  await_probe_installation: hardened to verify the RC-applied probe
  count (via get_loaded_remote_configs) rather than trusting the
  hook-install counter alone, and to actively drive RC processing
  each poll iteration via a new process_remote_config_now() test
  primitive. Confirmed via real CI sidecar logs: all 3 LIVE_DEBUGGING
  configs were acknowledged, then one dropped out of the acknowledged
  set and never returned, leaving the root-span decoration probe
  inactive. This hardening closes the same class of slow/transient
  apply race as the 7.2 fix; it cannot recover from a probe that is
  genuinely dropped server-side after being applied.

- [8.3] tests/ext/includes/request_replayer.inc
  waitForDataAndReplay: widened maxIteration from 500 (~16.65s) to
  900 (~30s at the 33.3ms flush interval). Confirmed via real CI
  sidecar logs: the trace was enqueued correctly, but the sidecar's
  trace_flusher stalled ~18s across all sessions under contention and
  drained ~1s after the old budget expired. Data provably arrives,
  just later than the old budget under load -- not a valgrind issue,
  not a selection race in the mock agent (single-threaded, per-token
  storage, ruled out by reading its source).

No tests skipped or disabled. Verified locally under test_extension_ci
valgrind: rc_fork_notify.phpt and dynamic_config_update.phpt 50/50 pass
each; full remote_config/, live-debugger/, and request-replayer/ test
directories pass with no regressions.
@datadog-prod-us1-5

datadog-prod-us1-5 Bot commented Jul 15, 2026

Copy link
Copy Markdown

Pipelines  Tests

Fix all issues with BitsAI

⚠️ Warnings

🚦 4 Pipeline jobs failed

DataDog/apm-reliability/dd-trace-php | test_extension_ci: [7.0]   View in Datadog   GitLab

DataDog/apm-reliability/dd-trace-php | merge-gate   View in Datadog   GitLab

DataDog/apm-reliability/dd-trace-php | publish docker image for system tests   View in Datadog   GitLab

View all 4 failed jobs.

ℹ️ Info

No other issues found (see more)

🧪 All tests passed
❄️ No new flaky tests detected

🎯 Code Coverage (details)
Patch Coverage: 100.00%
Overall Coverage: 54.12% (+0.00%)

Useful? React with 👍 / 👎

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

Leiyks added 2 commits July 16, 2026 09:47
The active-poll rewrite of await_remote_config/process_remote_config_now
addressed the timing-checkpoint race in test_extension_ci, but
await_probe_installation still counted hook-install events, which can
return mid-churn when remote config removes and re-adds probes
("churn") during delivery -- observed as an empty span-decoration
capture when the last (targetSpan=ROOT) probe hadn't been re-installed
yet when the test body ran.

Root-cause fix, folded in from the span-decoration-capture branch:

- tracer/live_debugger.c: drop the stale active_live_debugger_hooks
  index entry when a probe is removed, so its element count reflects
  only currently-installed probes.
- tracer/functions.c: add live_debugger_installed_probe_count, a net
  installed-probe counter derived from that hash table.
- tests/ext/live-debugger/live_debugger.inc: rewrite
  await_probe_installation to poll the net installed-probe count via
  live_debugger_installed_probe_count and require it to stay >= $num
  continuously for a 1s stability window, so a churn dip resets the
  wait instead of returning early. Still actively drives RC
  application each iteration via process_remote_config_now.
…ension_ci]

Return only after an RC update has been applied AND a 500ms settle
window observes no further change (or the overall timeout elapses),
instead of returning on the first observed update. A per-request
reader against a warm/shared sidecar can otherwise race ahead of the
config the caller just published, applying it one poll-cycle late.
@pr-commenter

pr-commenter Bot commented Jul 16, 2026

Copy link
Copy Markdown

Benchmarks [ tracer ]

Benchmark execution time: 2026-07-16 13:49:36

Comparing candidate commit bac7c25 in PR branch leiyks/fix-ci-test-extension-flaky with baseline commit 024fe4a in branch master.

Found 3 performance improvements and 0 performance regressions! Performance is the same for 191 metrics, 0 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 ----------------------------------'

scenario:ComposerTelemetryBench/benchTelemetryParsing-opcache

  • 🟩 execution_time [-1.945µs; -0.455µs] or [-11.242%; -2.631%]

scenario:MessagePackSerializationBench/benchMessagePackSerialization

  • 🟩 execution_time [-4.577µs; -2.543µs] or [-4.211%; -2.341%]

scenario:TraceFlushBench/benchFlushTrace-opcache

  • 🟩 execution_time [-83.294µs; -50.206µs] or [-3.356%; -2.023%]

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant