feat(event-loop): log block stream gap closures from alloy-internal reconnects (COW-1086) - #65
Closed
brunota20 wants to merge 1 commit into
Closed
Conversation
…econnects (COW-1086)
Adds a positive-recovery Info log when the block subscription
resumes after a silence ≥ 60 s, covering the observability gap
identified in the 2026-06-23 Sepolia soak.
## Background
The 2026-06-23 soak surfaced this sequence:
09:05:43 ERROR WS connection error: WebSocket protocol error:
Connection reset without closing handshake
target=alloy_transport_ws::native
(no further WS-related lines for ~1 h)
10:02:24 INFO indexed watch:... ← twap-monitor activity resumes
10:05:24 INFO ethflow observed ... ← ethflow-watcher activity resumes
`docker ps` showed 0 restarts and the container stayed healthy
throughout — alloy's transport layer reconnected internally without
the engine's `reconnecting_block_task` ever observing
`inner.next().await -> None`. So the engine never entered its
"stream ended → backoff → subscription reopened" path, and the
existing `block subscription reopened` Info log (COW-1071) never
fired. The transport-layer ERROR followed by silence is
indistinguishable from a hung engine on a soak dashboard.
## What changes
In `reconnecting_block_task`, on every yielded item compare
`now.duration_since(last_event)` against `BLOCK_GAP_LOG_THRESHOLD`
(60 s, 5× Sepolia block time). When the gap meets or exceeds the
threshold, emit:
INFO chain_id=... gap_s=... kind="block"
"stream gap closed - first event after silence
(likely an alloy-internal transport reconnect)"
The gap-detection logic is factored into a small synchronous helper
`block_stream_gap_to_log(now, last_event, threshold) -> Option<Duration>`
so it can be unit-tested without spinning up an async runtime or a
real provider.
## Why blocks only (not logs)
Block subscriptions have predictable cadence — Sepolia produces a
new block every ~12 s, mainnet every ~12 s. A 60 s silence is
therefore anomalous and worth surfacing. Log subscriptions, by
contrast, are inherently sparse (driven by on-chain user activity),
so the same threshold would fire false positives on quiet windows.
The existing `log subscription reopened` log already handles the
engine-detectable reconnect for log streams.
## Tests
4 new unit tests on the gap-detection helper:
* `block_stream_gap_to_log_returns_none_when_no_prior_event`
* `block_stream_gap_to_log_returns_none_when_under_threshold`
* `block_stream_gap_to_log_returns_some_at_threshold_boundary`
* `block_stream_gap_to_log_returns_some_when_well_over_threshold`
All 90 nexum-engine tests pass (86 existing + 4 new). Clippy strict
clean, fmt clean. Wasm build untouched.
## Out of scope
* End-to-end test of `reconnecting_block_task` against a mock
provider — no existing scaffolding for that path, and the gap
helper covers the decision logic deterministically.
* Suppressing or downgrading the `alloy_transport_ws::native` ERROR
itself — it is a legitimate transport-layer event, just one whose
recovery wasn't previously observable. The new Info line closes
that loop without losing the original signal.
## Live validation
The next time alloy auto-reconnects internally on the soak VM, the
new line will surface as a structured JSON event with
`gap_s=<seconds>` so the soak dashboard can correlate it with the
preceding transport ERROR.
This was referenced Jun 23, 2026
Author
Live validation note (2026-06-23 14:00 UTC)Combined with the rest of the redesign + fix bundle on Companion PRs (same redesign / soak deploy bundle)
Each is single-concern; the deploy branch is the cumulative integration point and will fold into |
Author
|
Superseded by deploy branch commit |
This was referenced Jun 24, 2026
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
What this PR does
Adds a positive-recovery Info log when the block subscription resumes after a silence ≥ 60 s. Closes the observability gap surfaced in the 2026-06-23 Sepolia soak: an
alloy_transport_ws::nativeERROR followed by silence looked identical to a hung engine on the dashboard, because alloy's internal reconnect path bypasses the engine's ownreconnecting_block_taskand never emits the existingblock subscription reopenedlog line (COW-1071).Live evidence (2026-06-23 soak)
docker psshows 0 restarts and the container stayed healthy throughout. Grep on the engine's own reconnect markers returns zero hits:So alloy's transport layer reconnected internally without
inner.next().awaitever returningNone— the engine never entered thestream ended → backoff → subscription reopenedarm and the existing positive-recovery log never fired.Change
In
reconnecting_block_task, on every yielded item, comparenow.duration_since(last_event)againstBLOCK_GAP_LOG_THRESHOLD(60 s, 5× Sepolia block time). When the gap meets or exceeds the threshold, emit:The decision logic is factored into a small synchronous helper:
so it can be unit-tested without an async runtime or a real provider.
Why blocks only
Block subscriptions have predictable cadence (Sepolia and mainnet both produce ~12 s blocks). A 60 s silence is anomalous and worth surfacing. Log subscriptions are inherently sparse (driven by on-chain user activity), so the same threshold would fire false positives during quiet windows — the engine-detectable reconnect path already covers them via the existing
log subscription reopenedline.Tests (90 total, all green)
4 new unit tests on the helper:
block_stream_gap_to_log_returns_none_when_no_prior_eventblock_stream_gap_to_log_returns_none_when_under_thresholdblock_stream_gap_to_log_returns_some_at_threshold_boundary(60 s = 60 s counts as a gap)block_stream_gap_to_log_returns_some_when_well_over_threshold(pinned at the 3600 s of the actual soak gap)cargo clippy -p nexum-engine --all-targets -- -D warningsclean.cargo fmt --checkclean.Out of scope
reconnecting_block_taskagainst a mock provider — no existing scaffolding for that path. The gap helper covers the decision logic deterministically.alloy_transport_ws::nativeERROR itself — it is a legitimate transport-layer event, just one whose recovery wasn't previously observable. The new Info line closes that loop without losing the original signal.Live validation plan
Deploy to the soak VM after review. Next time alloy auto-reconnects internally, the new line surfaces as a structured JSON event with
gap_s=<seconds>so the soak dashboard can correlate it with the preceding transport ERROR.Linear
Resolves COW-1086.
AI assistance disclosure: drafted by Claude (Opus 4.7, 1M context) following the 2026-06-23 soak inspection.