fix(spurctld): stop logging replayed WAL operations as new events - #772
Closed
pre wants to merge 1 commit into
Closed
fix(spurctld): stop logging replayed WAL operations as new events#772pre wants to merge 1 commit into
pre wants to merge 1 commit into
Conversation
Every start of spurctld re-applies the whole Raft log, and each apply logged again at INFO. One node removal was thus printed once per controller process, on every node, with the timestamp of the restart. A reader who greps the journal finds a removal that did not happen, and looks for a fault in the wrong place. The store now records the highest log index that was on disk at startup. Every entry up to it is a replay, and is applied inside a `wal_replay` span. The subscriber drops INFO and below inside that span. WARN and ERROR pass, because a bad transition during a replay is a real defect. The state is applied exactly as before: only the log output changes. Measured on a three-node cluster: before the change, a restart printed the old "node removed from cluster" line again on every node. After it, a restart that replays 46 entries prints none, sinfo still shows every node, and a live shutdown still logs.
pre
requested review from
biluriuday,
sajmera-pensando,
sgopinath1,
shiv-tyagi and
yansun1996
as code owners
August 31, 2026 13:27
Author
|
Verification so far, since the workflow runs need maintainer approval: Local, on this branch alone (rebased on 360d44c):
On a three-node cluster, with this change alone and nothing else:
The E2E suite has not run yet. Could a maintainer approve the workflow runs? |
Author
|
Superseded by #785 |
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.
Symptom
Every start of
spurctldre-applies the whole Raft log, and each apply logged again atINFO. One node removal is therefore printed once per controller process, on every node, carrying the timestamp of the restart rather than of the event:One removal happened. The node was in
sinfothe whole time. A reader who greps the journal after a restart finds a removal that did not happen and looks for a fault in the wrong place. This cost real time while diagnosing an unrelated defect, because the replayed line looked like a live event.The same applies to every other
INFOinapply_operation: partitions created, reservations updated, and so on.Change
SpurStorerecords the highest log index that was on disk when the process started (replay_upto). Every entry up to it is history, andapply_to_state_machineapplies it inside awal_replayspan. The subscriber dropsINFOand below inside that span.WARNandERRORstill pass, because an invalid transition during a replay is a real defect and must stay visible.Only the log output changes. The state is applied exactly as before.
Test
replay_upto_is_the_highest_index_on_diskfails if the boundary between history and a live event is lost. 963 unit tests pass.Verified on a three-node cluster:
node removed from clusterin the journalraft store recovered from disk log_entries=48 replay_upto=Some(47)sinfoafter the restartThe last row is the one that matters: with this change alone on the cluster, an actual node removal still prints its
INFOline. The filter hides replayed history, not events.