Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Log about historical backfill less frequently #2600

Merged
merged 3 commits into from
Sep 16, 2021

Conversation

paulhauner
Copy link
Member

Issue Addressed

NA

Proposed Changes

This proposal changes the way we log when we're doing a historical back fill. Presently, we log like this:

INFO New block received                      hash: 0x0a7f36b4dd0755da69cbcd50015ca9398222e7c2037b77b8fb94f8fbc137af30, slot: 1265603
INFO Synced - Downloading historical blocks  est_time: 2 hrs 37 mins, speed: 132.00 slots/sec, distance: 1246433 slots (24 weeks 5 days), peers: 45, service: slot_notifier
INFO New block received                      hash: 0xdfd08ffd942a88c4ae0e4eabfba2716ac4c7a7a5dab6d7acdad0e0b5da80eb87, slot: 1265604
INFO Synced - Downloading historical blocks  est_time: 4 hrs 43 mins, speed: 73.33 slots/sec, distance: 1246433 slots (24 weeks 5 days), peers: 45, service: slot_notifier
INFO New block received                      hash: 0x1dce940086f301ea1b58717fc71bba6167a29fbad63c083d9d8a13cbf95df921, slot: 1265605
INFO Synced - Downloading historical blocks  est_time: 4 hrs 59 mins, speed: 69.34 slots/sec, distance: 1244257 slots (24 weeks 4 days), peers: 46, service: slot_notifier
INFO New block received                      hash: 0x8e84cf0a2312177424c091f3a42c8335a1cb7ad14a8b4d656e805ee0e3ab62f9, slot: 1265606
INFO Synced - Downloading historical blocks  est_time: 3 hrs 55 mins, speed: 87.98 slots/sec, distance: 1242210 slots (24 weeks 4 days), peers: 43, service: slot_notifier

This PR changes it so the logs look more like this:

INFO Downloading historical blocks           est_time: 1 hr 48 mins, speed: 144.01 slots/sec, distance: 935201 slots (18 weeks 3 days), service: slot_notifier
INFO Synced                                  slot: 1265824, block: 0x211a…b6cc, epoch: 39557, finalized_epoch: 39555, finalized_root: 0xc39c…2a5f, peers: 14, service: slot_notifier
INFO New block received                      hash: 0x74ddf3b377d499ab0c185e487fc59b5839dcfd9299423507c2a8bc2ffe3d6d15, slot: 1265825
INFO Synced                                  slot: 1265825, block: 0x74dd…6d15, epoch: 39557, finalized_epoch: 39555, finalized_root: 0xc39c…2a5f, peers: 23, service: slot_notifier
INFO Synced                                  slot: 1265826, block:    …  empty, epoch: 39557, finalized_epoch: 39555, finalized_root: 0xc39c…2a5f, peers: 30, service: slot_notifier
INFO New block received                      hash: 0x1a9cf144823e21a006a654cced535f419878d36890f84ee84e48fd0074159455, slot: 1265827
INFO Synced                                  slot: 1265827, block: 0x1a9c…9455, epoch: 39557, finalized_epoch: 39555, finalized_root: 0xc39c…2a5f, peers: 30, service: slot_notifier
INFO Synced                                  slot: 1265828, block:    …  empty, epoch: 39557, finalized_epoch: 39555, finalized_root: 0xc39c…2a5f, peers: 37, service: slot_notifier
INFO New block received                      hash: 0x1a6089665a565d901bbe2a3226112469c6d883bbc9995a9d70674b3a0a6852e8, slot: 1265829
INFO Downloading historical blocks           est_time: 2 hrs 18 mins, speed: 112.01 slots/sec, distance: 928481 slots (18 weeks 2 days), service: slot_notifier
INFO Synced                                  slot: 1265829, block: 0x1a60…52e8, epoch: 39557, finalized_epoch: 39555, finalized_root: 0xc39c…2a5f, peers: 37, service: slot_notifier

In this new logging format we log the typical Synced logs and then every 5 slots (1 minute) we log about the historical back fill progress (if back fill is in progress).

I think logging the typical Synced messages with the occasional back fill message will place the "your node is synced and ready" message in the foreground and the "backfill is in progress" message in the background. I worry the existing logs might place the historical sync at the foreground, without making it clear that we're ready to go for staking.

Also, the typical Synced messages print info about the current slot, epoch and finalized epoch which I think is handy to see.

Additional Info

I've added a little Historical block download complete message when the notifier sees that we were back filling, but aren't anymore. I haven't actually seen this log fire because my node hasn't finished back filling yet. I'll keep an eye on it.

@paulhauner paulhauner added the ready-for-review The code is ready for review label Sep 15, 2021
Copy link
Member

@michaelsproul michaelsproul left a comment

Choose a reason for hiding this comment

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

Nice, this is much neater, thanks

@michaelsproul michaelsproul merged commit 8e32a1e into sigp:weak-subj-sync Sep 16, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
ready-for-review The code is ready for review
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants