fix(eth): log periodic sync status every cycle - #2544
Conversation
|
Important Review skippedAuto reviews are disabled on base/target branches other than the default branch. Please check the settings in the CodeRabbit UI or the ⚙️ Run configurationConfiguration used: defaults Review profile: CHILL Plan: Pro Plus Run ID: You can disable this status message by setting the Use the checkbox below for a quick retry:
Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out. Comment |
There was a problem hiding this comment.
Pull request overview
Updates sync-status logging to compare local TD with the best peer rather than downloader activity.
Changes:
- Extracts sync reporting into
reportSyncStatus. - Adds tests for TD-based logging.
- The announcement-driven path remains incompletely covered because peer TD can be stale or reference the announced block’s parent.
Reviewed changes
Copilot reviewed 2 out of 2 changed files in this pull request and generated 1 comment.
| File | Description |
|---|---|
eth/sync.go |
Adds peer-TD-based sync-status reporting. |
eth/sync_test.go |
Tests logging for synthetic peer TD states. |
💡 Add a code-review agent skill or configure MCP servers for context-aware, tailored reviews. Learn more in the docs.
5adea82 to
7c28fd7
Compare
7c28fd7 to
f99487b
Compare
There was a problem hiding this comment.
Pull request overview
Copilot reviewed 4 out of 4 changed files in this pull request and generated 2 comments.
Suppressed comments (1)
eth/handler.go:776
- A propagated block's number is also copied into the monotonic tip before the fetcher applies its distance/queue checks (
eth/fetcher/block_fetcher.go:661-667).SanityCheckonly requires the number to fit inuint64, so an untrusted far-future block that the fetcher rejects can permanently poison this peer's reported high-water mark. Record the tip only once the fetcher accepts or validates the block.
p.SetTipNumber(request.Block.NumberU64())
f99487b to
3ca534b
Compare
3ca534b to
52aa5ae
Compare
There was a problem hiding this comment.
Pull request overview
Copilot reviewed 6 out of 6 changed files in this pull request and generated 2 comments.
Suppressed comments (1)
eth/fetcher/block_fetcher.go:60
- The bounds checks can still overflow when the chain height approaches
math.MaxUint64:height + maxQueueDist(andnumber + maxUncleDist) wraps, causing values that are actually inside the plausibility window to be rejected. Compare the ordered values by subtraction instead; subtraction is safe after the branch and also handles the far-future input correctly.
if number < height {
return height <= maxUncleDist+number
}
return number <= maxQueueDist+height
52aa5ae to
df2faf6
Compare
de7725d to
d6305a2
Compare
d6305a2 to
c8283fe
Compare
c8283fe to
26eab1b
Compare
The sync status logger only fired while the downloader was inside a bulk historical sync. Once the node is caught up, new blocks are followed through the block fetcher / BFT announcements, so Synchronising() stays false and the warn log appeared only once or never over hours of normal operation instead of every 10 minutes. The logger now emits a status line on every 10-minute cycle with a neutral message (current / highest / behind / peers). While the downloader is actively synchronising it seeds current and highest from the downloader's progress (the snap block and the discovered target); otherwise it seeds current from the local chain head. In both states the reported highest is the maximum of the seeded value and the per-peer live high-water mark fed by block announcements (NewBlockMsg / NewBlockHashesMsg), so the gap stays current even when the downloader is idle. The announced numbers are only trusted after passing the fetcher's plausibility window, exposed as IsPlausibleAnnouncement, so a peer cannot inflate the reported gap.
26eab1b to
7a8e38e
Compare
Problem
The "Block synchronisation in progress" warn log was designed to be emitted every 10 minutes so operators can see sync progress even when info/debug logs are filtered out. In practice it barely fires: over 10+ hours of normal operation it appeared only once on a mainnet node and not at all on a testnet node, instead of every cycle.
Root cause
The logger gated on
pm.downloader.Synchronising(), which is only true while the downloader is running a bulk historical sync (d.synchronisingis set insideDownloader.synchroniseand cleared when it returns). On XDPoS, once a node catches up to the network head, new blocks are followed through the block fetcher / BFT announcements, so the downloader flag stays false even while the node is still catching up. As a result the warn log almost never fires during steady-state operation.Fix
The design intent of this logger is a periodic sync status heartbeat that is always visible, not an indicator of downloader activity. The logger now emits a status line on every 10-minute cycle with a neutral message (
Block synchronisation statuswithcurrent/highest/behind/peers).The reported values are assembled from two sources, merged so the higher one wins:
CurrentSnapBlock.tipNumber, updated onNewBlockMsg/NewBlockHashesMsg), which stays current in the steady-state announcement-driven catch-up path.Because announced block numbers are untrusted, they are only recorded after passing the fetcher's plausibility window, exposed as
fetcher.IsPlausibleAnnouncement([-maxUncleDist, +maxQueueDist]= 7 behind / 32 ahead). The helper uses an overflow-safe branch formulation, and it is now reused by every untrusted-number path: theNewBlockMsg/NewBlockHashesMsgtip recording in the handler and theBlockFetcher.enqueuedrop check for propagated blocks (which previously used a signedint64subtraction, so aMaxUint64block wrapped to distance -1 and could enter the queue on low-height nodes). All paths now reject the same values, so a peer cannot inflate the recorded tip and make the heartbeat report a false gap.Behavior comparison (before / after)
Testing
Added/updated tests in
eth/sync_test.goandeth/fetcher/block_fetcher_test.go:TestSyncStatusLoggercovers the steady-state heartbeat (live high-water mark, gap, zero-gap);TestAnnouncementUpdatesPeerTipandTestNewBlockMsgUpdatesTipdeliver realNewBlockHashesMsg/NewBlockMsgmessages through the handler and verify plausible values update the tip while far-future (MaxUint64) values do not;TestComputeSyncStatuscovers the merge logic;TestSyncStatusDuringSyncverifies the heartbeat reports the downloader target while synchronising, holding the downloader deterministically in that state via astalledDownloaderPeerstub (which answers the height probe and ancestor search, then blocks the bulk download) instead of relying on a real sync remaining in flight;TestIsPlausibleAnnouncementcovers the plausibility window boundaries;TestMaxUint64PropagationDiscardingverifies aMaxUint64block is dropped byenqueueon a low-height chain where the old signed subtraction wrapped and accepted it. Log capture uses a mutex-protectedlockedBufferso the concurrent protocol/downloader goroutines writing trace logs cannot race with the test's read/reset. Verified withgo build ./...,go vet ./eth/..., the fullethandeth/fetchertest suites, and the sync/fetcher tests under-race.Compatibility
Logging-only change plus a small security hardening of tip tracking and propagated-block validation. Adds a per-peer counter and unifies the plausibility checks on the two untrusted announcement paths; no impact on consensus, block validation, RPC, database schema, or network protocol. No configuration or migration required for node operators. The only behavioral change is a warn-level status line every 10 minutes, which matches the documented intent of the logger.