Skip to content

test(daemon): age the stuck-probe sample from the sampler's time - #11

Merged
novelKR merged 1 commit into
mainfrom
codex/stuck-probe-sample-time
Sep 27, 2026
Merged

novelKR merged 1 commit into
mainfrom
codex/stuck-probe-sample-time

Conversation

@novelKR

@novelKR novelKR commented Sep 27, 2026 •

Copy link
Copy Markdown
Owner

Summary

Test-only fix for a false failure of server::tests::native::a_stuck_probe_does_not_hold_the_authority_and_its_delay_closes_admission (DG1-C03). No product code changes.

Failure

  • Run 36303237592 (pull_request, head aff986cc83623d0a1c0521771964da1346e6c094), job contracts (macos-14), step "Native host evidence functional checks", stage service-sampling: assertion failed: last_open - last_read <= 6_000 at crates/daemon/src/server.rs:2854.
  • The push run 36303235570 of the same head passed. Since the assertion was added in defde38, this step ran on 33 macOS attempts and failed only this once.

Cause

  • The test measured from last_read, which the scripted probe records inside read() before returning.
  • The controller ages a sample from sample.at, which Sampler::sample takes after the read returns ("so its age is never understated"), and stores as its last sample (PressureController::observe). Admission closes when now - sample.at > 6_000.
  • So sample.at >= last_read, and the upper-bound assertion assumed they were equal. Whenever they differed by a millisecond or more and a 20 ms poll fell between last_read + 6_000 and sample.at + 6_000, a correct controller was reported as late. The lower-bound assertion cannot fail this way.

Change

  • The scripted probe blocks its third read by count (baseline, first sample, stuck read) and records when that read began, replacing "block whichever read follows a store" plus a fixed 2300 ms sleep. This makes the first sample the last completed one.
  • The reference time is that sample's sample.at, read from its pressure receipt, which carries the same value the controller stores.
  • Both bounds (<= 6_000 open, > 6_000 closed), the lock check, the "closed before the stuck read returned" check and the slow-read and recovery checks are unchanged. The two bound assertions now print their values.
  • The "never closed" guard now counts its 12 s from when the blocked read began instead of from when the delay was armed, about one 2 s sampling interval earlier, so a controller that never closes fails about 2 s later than before. That guard and the 4 s wait for the blocked read to begin only turn a hang into a failure; the six-second admission policy is asserted by the two bounds above.

Verification

Rust 1.95.0, one Cargo job, one test thread (CARGO_BUILD_JOBS=1, RUST_TEST_THREADS=1), macOS arm64.

  • Reproduction with uncommitted instrumentation (a pause between the probe's timestamp and the sampler's, and an overridable freshness limit):
    • old test, no pause: 3/3 pass; old test, 40 ms pause: 3/3 fail at this assertion
    • new test, no pause: 3/3 pass; new test, 40 ms pause: the preserved run summary records 3/3 passes, but the raw logs do not independently prove that the pause was active in those runs
    • new test, limit 5900 ms (closes early): 3/3 fail; limit 6100 ms (closes late): 3/3 fail
    • Evidence limits: the preserved command script keeps the run helper but not each case's invocation, so each case's environment is known from its name only. The early- and late-close failures print 5,915 ms and 6,094 ms, matching the intended limits. By construction the new reference is the controller's own sample time, which such a pause cannot move.
  • New test: 30/30 runs pass.
  • cargo test -p devguard-daemon --lib --locked: 41 passed.
  • python3 scripts/qualify.py dg1-probes: passed (service-sampling 2/2).
  • cargo fmt --all -- --check, cargo clippy -p devguard-daemon --all-targets --locked -- -D warnings, git diff --check: clean.
  • CI for this head: push run 36311129096 and pull_request run 36311154406 passed on ubuntu-24.04 and macos-14.

Not run locally

  • scripts/validate.py and workspace-wide Clippy (host memory was tight); both run in this PR's CI on macOS and Ubuntu.
  • The hosted macOS 14 runner was not reproduced locally; the reproduction widens the gap on purpose. It shows the mechanism, not the gap or the failure probability of run 36303237592.

Rollback

Revert this commit; it touches one test module only.

Handoff (session of 2026-09-27)

…-C03)

The pull_request run of aff986c failed once on the hosted macOS 14
runner, in the native host evidence step; the push run of the same head
passed. The stuck-probe test asserted that admission stayed open no
more than 6000 ms after last_read, the time its scripted probe records
just before a read returns. The controller ages a sample from sample.at
instead, which the sampler takes after the read has returned so that an
age is never understated. sample.at is therefore never earlier than
last_read, and a 20 ms poll that fell between the two thresholds saw a
correct controller still open and failed the assertion.

Take the reference from the first sample's pressure receipt, which
carries the same sample.at the controller stores. So that this sample is
the last one completed, the scripted probe now blocks its third read by
count (baseline, first sample, then the stuck read) instead of blocking
whichever read follows a store, and the test waits for that read to
begin rather than sleeping 2300 ms. Both bounds and the other checks are
unchanged; the two bound assertions now print their values.

With a 40 ms pause inserted between the probe's timestamp and the
sampler's, the old test failed 3 of 3 at this assertion and the new test
passed 3 of 3. With the freshness limit changed to 5900 or 6100 ms, the
new test failed 3 of 3 each; that instrumentation is not committed. The
test then passed 30 of 30 runs, devguard-daemon's 41 library tests and
scripts/qualify.py dg1-probes once, with rustfmt and Clippy for the crate
clean, on Rust 1.95.0 with one Cargo job and one test thread.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
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