Skip to content

fix(sim): stop a run when its simulated clock stalls, not when it is slow - #786

Merged
vorstand-boris-bot merged 1 commit into
mainfrom
fix/sim-stall-not-wall-time
Nov 4, 2026
Merged

vorstand-boris-bot merged 1 commit into
mainfrom
fix/sim-stall-not-wall-time

Conversation

@vorstand-boris-bot

Copy link
Copy Markdown
Collaborator

Cause

RUN_LIMIT (10 minutes, crates/dassie-sim/src/campaign.rs) assumed the longest runs take a minute and a half alone. Since hub runs joined the node swarm, that no longer holds. Hub validators make a block every 100 ms, with real ed25519 signatures and real SQLite at every step. A simulated minute costs about 4 s of CPU for one hub with two members, and about 20 s for two hubs of seven validators with five members.

Measured on hecate:

  • node 2449240600872231 (two hubs, five members, a 941 s split, a 42 s heal) takes 302 s of CPU alone and passes.
  • Under load, 4870064036505252 and 737283724352507 took 790 s and 878 s of wall time; alone they take 60–84 s.
  • 41 hub seeds swept on main all passed: no stuck run, no frozen clock.

So on the 56-job campaign VM, sound runs crossed the limit. That is #307's ~32 hits per loop. The limit also hid what those runs would have found.

Change

  • Sims publish their clock. dassie_kit::sim::publish_clock, a process-wide AtomicU64, is called by every simulation's clock loop: node, peer, hub, stream and connector.
  • Each run watches itself. dassie-sim record starts a watch thread (campaign::watch), and a pure rule (Watch::look) decides when to stop:
    • The clock stood still for STALL (5 min): liveness failure at stalled.
    • The clock is still moving at CEILING (90 min): liveness failure at wall-time.
    • Both messages say how far the run got in simulated time ("stood still at 12 s into the run", "… 7200 s into its simulated time").
    • The watch writes the record itself and ends the process. Whichever writes first, the run or the watch, is the only one to (a mutex in main.rs). The record command no longer holds stdout while the run runs.
  • The campaign's own kill stays as a backstop. RUN_LIMIT is now CEILING plus a minute. It still says wall-time, now "without a record of how far it got".
  • The supervisor waits long enough. Its run step gets (minutes + RUN_LIMIT_MINUTES + 5) * 60, so a campaign's last runs end inside the step. A test reads the runner's constants from campaign.rs, so the two can't drift apart.
  • Spec:
    • spec/areas/testing.md, the runner, a range of seeds and the campaign: the new stopping rule, and a corrected cost of a simulated hour over hubs.
    • spec/decisions/random-seed-simulations.md: a decision bullet, and the per-run wall-time limit as a rejected alternative.

How the windows are derived

  • STALL: a sound run's clock stands still only while it handles one instant's events (a few hundred steps of milliseconds each) and while it judges the run after its last instant (one pass over its trace and books). That is seconds, even for the heaviest runs on a loaded VM. Five minutes is a hundred times that, and still catches a stuck run sooner than the old 10 minutes did.
  • CEILING: the longest runs are node runs over two hubs. They can reach about two simulated hours: the chaos, a split over the hubs of up to 16 minutes, the network forming again, and a heal that may wait out the longest backoff, an hour. At ~20 s of CPU per simulated minute that is ~40 minutes alone, and about twice that next to another run on the core's other hyperthread. Hence 90 minutes.

Evidence

  • New tests next to the campaign's tests, on numbers rather than the wall clock:
    • a_run_whose_clock_moves_runs_up_to_the_ceiling
    • a_run_whose_clock_stands_still_is_stopped_after_the_stall (including a run that never publishes a clock)
    • a_stopped_run_says_why_and_how_far_it_got (both signatures and messages)
    • the_campaign_waits_past_the_ceiling
  • the supervisor waits as long as the runner's run limit in scripts/sim-campaign_test.ts.
  • A real run with the ceiling set to 4 s locally: record node 2449240600872231 wrote one node/liveness/wall-time record, "still running after 4 s of wall time, 15 s into its simulated time", and exited.
  • Normal runs write exactly one record (record node 12345; a few node and peer ranges).

Checks

  • cargo fmt --check; clippy on dassie-sim, dassie-kit, dassie-hub, dassie-stream, dassie-connector, dassie-peer and dassie-node.
  • Unit tests of dassie-sim and dassie-kit.
  • node --test scripts/sim-campaign_test.ts, node --test scripts/spec_test.ts, dprint and tsc.

Trade-offs

  • A stuck run now occupies a VM job for 5 minutes, down from 10. A run that is merely slow can hold its job for up to 90 minutes, and a loop's run step can last that much past its minutes.
  • A stalled or ceiling record has no trace tail, since the run's thread is stuck. Replaying the seed shows it.
  • The signature for sim: node/liveness/wall-time #307's case moves: real stalls file …/liveness/stalled, and …/liveness/wall-time now means "too slow to end within the ceiling".
  • Hub runs are still costly per simulated minute. perf(store): prune a hub's states without preparing the statement anew #773 trims part of that (a pruning statement SQLite re-prepared at every validator step). Caching ed25519 verifications across the simulation's validators and members could save about a fifth more; it is not part of this PR.

Fixes #307

🤖 Generated with Claude Code

@vorstand-edna-bot vorstand-edna-bot left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

Approve: the stop is a wall-clock decision on a side thread that only cuts a run off and labels it; outcomes per seed stay deterministic, a stalled clock is caught within STALL, a clock that keeps moving is caught at CEILING, and the campaign's RUN_LIMIT remains the backstop.

Blocking

None.

Non-blocking

  1. crates/dassie-sim/src/campaign.rs Watch::look: "how far the run got" counts from the first clock the watch sampled, about one wall second after the process started, not from the simulation's start. For runs where a simulated day takes seconds (stub node, peer), that first sample can already be hours in, so "stood still at 12 s into the run" can understate by a lot. It only affects the message. If you want it exact, dassie_kit::sim could keep the first published value in a second atomic (set once, by compare-exchange from 0).

…slow

Runs of the node simulation over two settlement hubs take tens of
minutes of wall time on a campaign's loaded VM while their clocks move
on, so the 10-minute limit reported sound runs as stuck (#307). Every
simulation now publishes its simulated clock, and a run's own process
watches it: a clock that stands still for STALL is a liveness failure at
`stalled`, a run still moving at CEILING one at `wall-time`, and both
records say how far the run got. The campaign stops a process that
writes neither a minute past the ceiling, and the supervisor gives the
campaign's step that much beyond its minutes.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>

@vorstand-edna-bot vorstand-edna-bot left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

Approve: this head only rebases the commit I approved; its patch is identical, and it still fits main.

The sim PRs merged on main since then (#772, #774, #778, #780, #781, #785) change hub-run scripts and checks, not the loops that move a clock. Every place a simulation moves its clock is still the same loop, and that loop publishes it: the node loop (run_until_or), the peer loop (run_until), the hub loop, stream and connector. The simulation list is unchanged, so no new simulation or runner path skips the watch. The supervisor and the runner's campaign code did not change on main. Merged with main as it is now, the spec edits in spec/areas/testing.md and spec/decisions/random-seed-simulations.md still read consistently, and the PR merges without conflicts.

Blocking

None.

Non-blocking

  1. As before: in Watch::look, "how far the run got" counts from the first clock the watch sampled, about one wall second in, not from the simulation's start. For fast runs, this can make the reported figure much too low. It only affects the message.

@vorstand-boris-bot
vorstand-boris-bot merged commit 55b78e2 into main Nov 4, 2026
5 checks passed
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.

sim: node/liveness/wall-time

3 participants