perf: slot-driver stall watchdog + chain.onBlock substep histogram (P0 of #863)

[ch4r10t33r]

What this PR does

Adds two diagnostic tools to help us figure out where time is going inside zeam when the slot driver stalls (the multi-second freezes seen on the devnet-4 aggregator in #863).

Nothing in this PR fixes the stalls themselves. It just makes them visible and attributable, so the next perf PRs can target the actual cost.

1. A watchdog thread that flags stalls

A small background thread wakes up every second and checks how long it's been since the main loop last ticked the clock. If the gap is more than 5 seconds, it:

• logs an error: slot-driver stall detected: last tick 604.389s ago (threshold=5000ms). See #863.
• bumps a Prometheus counter: zeam_slot_driver_stall_fired_total
• records the stall length in a histogram: zeam_slot_driver_stall_seconds (1, 2, 5, 10, 30, 60, 120, 300, 600 second buckets)

If the freeze lasts 600 seconds, the watchdog only logs once. It re-arms only after the slot driver ticks again, otherwise we'd get one log per second for the whole freeze.

The watchdog runs on its own OS thread, so it keeps working even if the main loop or libp2p thread is completely stuck.

(Per-thread stack dumps would be nice — but Zig 0.16's signal-handler API is unstable. Easy to add later if the metric tells us we need it.)

2. A per-step timing breakdown for chain.onBlock

chain.onBlock is a multi-stage process: hash the block, clone parent state, verify signatures, run the state transition, update fork choice, persist to DB, etc. Today we only see the total time. With this PR each stage gets its own histogram entry under the label step:

step label	what it measures
block_root_compute	hashing the block (when the caller didn't pre-compute the root)
parent_state_clone	snapshot + clone of the parent state
verify_signatures	XMSS signature verification
state_transition	the actual STF (process_slots + process_block)
ssz_serialize_fallback	re-serialising the block when no precomputed bytes were supplied
forkchoice_onblock	adding the block to fork choice
block_attestations	processing attestations carried by the block
db_persist	writing the block + state to RocksDB / LMDB

Buckets match the existing zeam_chain_onblock_duration_seconds so dashboards can stack the per-step series next to the total.

Why this PR first

#863 shows the aggregator (zeam_0) had:

• 5 onBlock calls > 1s, 2 > 5s, 1 > 10s
• 12 xev drains > 10s, 3 > 60s
• one window where the process froze for 604 seconds

Peers on the same host stayed healthy, so this isn't host pressure — it's per-process. Without per-step timing we can't tell whether the time goes into signature verify, STF, DB writes, or somewhere else. And without the watchdog those long freezes are hard to spot in noisy logs.

The next perf PRs (lock-free pubkey cache, etc.) need this attribution to actually claim wins.

Validation

• zig build clean (Debug + ReleaseFast)
• zig build test -Dprover=dummy --summary all passes
• zig fmt clean
• Hot path overhead: a few monotonicTimestampNs calls and one HistogramVec observe per step. Negligible.

Out of scope

• Per-thread stack dump on stall (waiting on stable Zig signal API).
• The actual perf fixes — those come in P1 and beyond.

Refs #863.

[zclawz]

Adversarial review finding for #883:

High — pkgs/node/src/slot_driver_watchdog.zig:112-117 / pkgs/node/src/clock.zig:19,70-75 — watchdog introduces an unsynchronised cross-thread read of Clock.last_tick_time_ms

The watchdog thread reads self.clock.last_tick_time_ms while the libxev clock thread writes it in tickInterval(). The PR comment says torn reads are acceptable because the worst case is a spurious stall log, but this is a plain shared mutable Zig field, not an atomic. That makes the program data-racy once the watchdog is enabled. Also, because the field is ?isize, the representation may include a tag/discriminant rather than a single naturally atomic word, so a torn read can be worse than just an old timestamp.

This is especially risky because the watchdog is enabled by default for every node in Node.run(), so the diagnostic path can introduce undefined behaviour into the production slot driver.

Suggested fix: make the timestamp explicitly atomic. For example, replace the nullable field with an std.atomic.Value(i64)/isize using a sentinel such as -1 for “no tick yet”, then use release/store in tickInterval() and acquire/load in the watchdog. Alternatively add a tiny accessor on Clock that hides the atomic/sentinel details.

Non-blocking notes:

• sleepMs() ignores interrupted nanosleep; harmless for diagnostics, but it can shorten probe intervals under signals.
• I like the onBlock substep histogram direction; I did not find a consensus-path mutation there beyond metric observations.

Validation/evidence: inspected the PR diff and surrounding Clock.tickInterval() / Node.run() lifecycle. A full zig build test -Dprover=dummy --summary all is still running locally through the long XMSS/forkchoice tests; no compile failure had appeared at the time of this review comment.

[ch4r10t33r]

Fixed in 82825fb:

Data race (High) — addressed.

Clock.last_tick_time_ms is now std.atomic.Value(i64) using std.math.minInt(i64) as the "never ticked" sentinel. The libxev thread writes via .release store in tickInterval(); the watchdog reads via a new public accessor Clock.lastTickMs() ?i64 that does an .acquire load and translates the sentinel. No struct field is poked directly from outside the Clock.

The libxev thread itself reads back the same atomic via .monotonic (it's the single writer, so it doesn't need to synchronise with itself). Behaviour change on the hot path is limited to one .release atomic store per tick, replacing a plain field write.

EINTR (Note) — addressed.

SlotDriverWatchdog.sleepMs now loops on EINTR, continuing with the remaining duration from nanosleep's rem slot. That way a stray signal (e.g. a future SIGUSR1-based stack-dump probe) cannot shorten the probe interval. Aborts immediately when stop_flag is set so shutdown isn't blocked by a long in-flight sleep.

zig build test -Dprover=dummy --summary all passes locally.

[ch4r10t33r]

@zclawz can you verify and approve this PR?

[zclawz]

PR #883 Review: slot-driver stall watchdog + onBlock substep histogram

Summary: Adds two diagnostic layers to attribute the multi-second slot-driver stalls from #863: a background watchdog thread that fires when the libxev tick clock falls behind wall-clock by >5s, and per-substep lap timing inside onBlock exported as a labeled Prometheus histogram.

---

Correctness / Logic ✅

The SUPPRESS_REFIRE hysteresis in runLoop is correct: firing_for_current_stall resets when last_tick changes (i.e. the driver ticked again), so each distinct stall event fires exactly once rather than once per probe interval. The ordering — reset check, then last_observed_tick_ms update, then threshold compare, then refire guard — is the right sequence.

OnblockStepWatch.lap() silently swallows metric write errors (catch {}), so instrumentation failures never bubble into block processing. Correct and intentional.

Minor label note: the "block_attestations" lap point is placed after forkChoice.updateHead() (step 5), so it actually measures the attestation loop plus updateHead. Consider renaming to "block_attestations_and_head_update" or splitting the lap — otherwise dashboard consumers may undercount updateHead time. Not a bug, but a readability issue.

The "ssz_serialize_fallback" lap only fires on the fallback code path (when no precomputed SSZ bytes were supplied). Worth noting in the metric help text that this observation is absent on the fast path.

---

Concurrency / Memory ordering ✅

last_tick_time_ms_atomic uses .release on writes and .acquire on reads — correct for producer-consumer visibility. The sentinel NEVER_TICKED_MS = std.math.minInt(i64) is unambiguous since real unix-epoch ms are positive and large.

stop_flag uses .release on store and .acquire on loads — correct for a thread-exit signal. sleepMs re-issues nanosleep on EINTR so stop-flag checks are responsive.

---

Resource management ✅

Node.deinit calls wd.stop() (which joins the watchdog thread) before stopping the API server — correct ordering. Watchdog spawn failure is non-fatal and handled cleanly with a warn log.

---

Nits

• "block_attestations" label mismatch noted above — worth fixing before merge so dashboards are accurate.
• The metric help comment mentions a "total_excluding_io_wait" label but I don't see a corresponding lap call in the diff — intended for a follow-up PR?

---

Verdict: LGTM ✅ — the label naming nit on "block_attestations" is worth fixing for dashboard accuracy, but not a blocker.