Skip to content

The cloud probe budget test stops counting machine stalls against the probe (#5600) - #5601

Closed
erikdarlingdata wants to merge 1 commit into
devfrom
fix/5600-probe-budget-flake
Closed

erikdarlingdata wants to merge 1 commit into
devfrom
fix/5600-probe-budget-flake

Conversation

@erikdarlingdata

Copy link
Copy Markdown
Owner

Fixes #5600.

SECTION: None

Why

The cloud probe budget test failed in the whole-suite guards job: "ProbeAsync returned 1083 ms after the handler's request ended, not within 1000 ms", on a pull request that touches no probe code. The probe cancels its request on its own 200 ms budget and returns inline, so a gap of over a second is time the machine took, not time the probe spent.

What changes

Test only, in Darling/Darling.Tests/DarlingCloudIdentityProbeTests.cs. The probe is unchanged.

  • The return time is now stamped by a synchronous continuation on the probe task itself. Before, it was read in the test after await ... WaitAsync(...), so it also counted the hop from the probe task's completion back to the test method (WaitAsync's own completion, then the test's continuation). That hop can wait on a busy process.
  • A StallWatcher runs on a dedicated thread (never a pool thread) and records every 10 ms tick that came 25 ms or more late. A stop-the-world pause or a descheduled process delays all threads at once. The two timed steps (call to first request, and request end to return) get the stall time that fell inside their window as extra allowance. A probe that really waits leaves the watcher ticking on time and gets no allowance.
  • The failure message now also says how much of the gap was a machine stall and when the test method resumed, so the next failure shows which of the two it was.
  • Every guard stays: the HangGuard, the first-request start bar, "the request must end by the budget's cancel, not early", and the post-cancel bar.

I could not reproduce the load on this laptop (no CPU load allowed), so the cause above is from reading the code and the earlier #4741 notes, not a measured repro. The failure message change exists so CI will tell us if a stall or the resume hop was it.

RED-plant

A temporary plant in the probe (an untokened 3 s Task.Delay in the catch after the budget cancels), then the test:

  • at this head: fails, "ProbeAsync returned 3006 ms after the handler's request ended ... 151 ms of that was a machine stall".
  • at origin/dev's version of the test, same plant: fails, "returned 3004 ms after the handler's request ended".
    The plant is not committed.

Test plan

  • Build: 0 warnings, 0 errors.
  • *DarlingCloudIdentityProbe*: Total 20, Failed 0 (three runs in a row also 20/0).
  • *Census*: Total 485, Failed 0, Skipped 1.
  • *Ratchet*: Total 15, Failed 0.
  • -trait Stage=Guard -failSkips: Total 1432, Failed 0.
  • Whole-suite shape on a GitHub runner: the guards job runs the whole Darling suite in one process when the build job's filters skip Darling.Tests. This PR's CI shape decides which one ran; check the job.

…wn resume hop against the probe (#5600)

The post-cancel bar now reads the probe task's own completion through a synchronous continuation, and a dedicated stall watcher thread grants machine stalls as allowance. An unbounded wait after the cancel still fails.
@erikdarlingdata

Copy link
Copy Markdown
Owner Author

Superseded by #5604. That PR keeps this one's change to how the test stamps the probe's return time, and runs the test in a timing collection that runs on its own. It drops the stall allowance. The branch stays on the remote. Claude posting for Erik Darling.

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