Visualisation logging for sync batch states #6034

AgeManning · 2024-07-02T05:03:56Z

I have been writing up logic about how sync works and also debugging some sync issues locally.

I thought it would be an improvement to have a visual representation of a current chain state, to help see where abouts the progress of a chain is at any given point from just eyeballing the logs.

I set a few icons to represent different batch states:

    /// The current icons are:
    /// - Empty/Uninitialized: 
    /// - Downloading: 󰦗
    /// - Awaiting Download: 󰝤
    /// - Awaiting Validation: 󰦖
    /// - Failed: 
    /// - AwaitingProcessing: 

These are from nerd-fonts and should appear for any os with the fonts installed.

These changes produce a small log when we are updating the chain state showing the current state of our block downloading buffer.

Here are some example logs I've run on a mainnet head sync:

Jul 02 04:48:30.068 DEBG Requesting batch                        batch_state: [󰝤 ], start_slot: 9422560, end_slot: 9422591, downloaded: 0, processed: 0, processed_no_penalty: 0, state: Downloading(16Uiu2HAmCJEcww2BZ7Cj93Rvzkj8cf19pAmi2kiFw4qj9X5vw7AU, 13), batch_ty: blocks_and_blobs, epoch: 294455, chain: 12325625451770947895, service: range_sync, service: sync
Jul 02 04:48:30.119 DEBG Requesting batch                        batch_state: [󰦗 󰝤 ], start_slot: 9422592, end_slot: 9422623, downloaded: 0, processed: 0, processed_no_penalty: 0, state: Downloading(16Uiu2HAmFVBES8qsTwVeAM6Tv6V8qexeGZnkGKkTGhsRfjQnKbZt, 14), batch_ty: blocks_and_blobs, epoch: 294456, chain: 12325625451770947895, service: range_sync, service: sync
Jul 02 04:48:30.119 DEBG Requesting batch                        batch_state: [󰦗 󰝤 ], start_slot: 9422592, end_slot: 9422623, downloaded: 1, processed: 0, processed_no_penalty: 0, state: Downloading(16Uiu2HAmCJEcww2BZ7Cj93Rvzkj8cf19pAmi2kiFw4qj9X5vw7AU, 15), batch_ty: blocks_and_blobs, epoch: 294456, chain: 12325625451770947895, service: range_sync, service: sync
Jul 02 04:48:33.907 DEBG Requesting batch                        batch_state: [  󰦗 󰝤 ], start_slot: 9422624, end_slot: 9422655, downloaded: 0, processed: 0, processed_no_penalty: 0, state: Downloading(16Uiu2HAmUhvmM4z7XryDrMyQXVUrHB2AWMfaAPcmS5qQRoTSkzs7, 16), batch_ty: blocks_and_blobs, epoch: 294457, chain: 11891774074394069546, service: range_sync, service: sync
Jul 02 04:48:33.910 DEBG Batch downloaded                        awaiting_batches: 1, batch_state: [   󰦗 ], blocks: 0, epoch: 294456, chain: 11891774074394069546, service: range_sync, service: sync
Jul 02 04:48:36.055 DEBG Batch downloaded                        awaiting_batches: 2, batch_state: [     ], blocks: 16, epoch: 294457, chain: 11891774074394069546, service: range_sync, service: sync
Jul 02 04:48:36.462 DEBG Requesting batch                        batch_state: [󰦗 󰦗 󰝤 ], start_slot: 9422624, end_slot: 9422655, downloaded: 0, processed: 0, processed_no_penalty: 0, state: Downloading(16Uiu2HAmRtTvtezhpWsSBnRBVa29KsQf6Sb9sPA2uAqyUvnNSa6t, 17), batch_ty: blocks_and_blobs, epoch: 294457, chain: 12325625451770947895, service: range_sync, service: sync

It's not as handy as I had originally expected because the buffer is a moving window, but it is useful to show where sync might be stalling, how many we are currently downloading and what bottlenecks etc.

A more holistic approach is probably a proper sync grafana dash.

jimmygchen · 2024-07-03T05:42:28Z

The visualization is nice!! 🔥

I couldn't get it to render on my terminal though, I've tried a few built-in fonts but they don't render, looks like I might have to install something from nerd-fonts?

I tried emojis and they work well (on my machine) - think it might be worth considering since some of them have been part of the Unicode standard for a while and should have wide OS support. I've only tested on MacOS though ;)

dapplion · 2024-07-03T08:51:56Z

is it expected for icons to not render on the browser?

ackintosh · 2024-07-03T14:00:41Z

I installed the 0xProto font on my Ubuntu machine and saw the following icons:

Using emojis seems like a good idea. 💡

AgeManning · 2024-07-09T01:21:38Z

Yeah sorry. The fonts I used aren't widely used.

If someone can suggest some good emoji's maybe we can do with that.

jimmygchen · 2024-07-09T01:50:06Z

Some options:

fn visualize(&self) -> &'static str {
    match self {
        BatchState::Downloading(_, _) => "⏬",
        BatchState::Processing(_) => "🔄",
        BatchState::AwaitingValidation(_) => "⏳",
        BatchState::AwaitingDownload => "📥",
        BatchState::Failed => "❌",
        BatchState::AwaitingProcessing(_, _) => "🕓",
        BatchState::Poisoned => "💀",
    }
}

Face emojis from neutral to happy face

fn visualize(&self) -> &'static str {
    match self {
        BatchState::AwaitingDownload => "😐",
        BatchState::Downloading(_, _) => "🙂",
        BatchState::AwaitingProcessing(_, _) => "😊",
        BatchState::Processing(_) => "😃",
        BatchState::AwaitingValidation(_) => "😁",
        BatchState::Failed => "😞",
        BatchState::Poisoned => "😵",
    }
}

AgeManning · 2024-07-09T02:19:16Z

Awesome thanks. I replaced them with emoji's now.

dapplion · 2024-07-10T08:54:13Z

Not sure how I feel to have debug logs full of emojis now.. haha

This batch state codes will be read by a small minority of devs who could memorize the meaning of a few letters. Plus there are ordering rules of states that reduce the max possible combination of states. ASCII has a bunch of disctict symbols that can de used.

For example:

Downloading -> D
Processing -> P
AwaitingX -> lowercase x
Failed -> F
Poisoned -> P

fn visualize(&self) -> &'static str {
    match self {
        BatchState::Downloading(_, _) => "D",
        BatchState::Processing(_) => "P",
        BatchState::AwaitingValidation(_) => "v",
        BatchState::AwaitingDownload => "d",
        BatchState::Failed => "F",
        BatchState::AwaitingProcessing(_, _) => "p",
        BatchState::Poisoned => "X",
    }
}

AgeManning · 2024-07-11T06:03:15Z

Yeah fair. I'm not sold on this PR and if people don't find it useful, happy to ditch it.

The reason I built it was, i saw a couple of times sync being stalled and it was kind of pain to track down and figure out what we were waiting on this (because the batches are all numbers).

Happy to switch to text for the states. If i get a few thumbs on this, then I'll consider this PR useful, switch to text and merge down.

If not many thumbs <3, i'll close this PR

jimmygchen · 2024-07-11T06:09:07Z

Gave you both my thumbs 👍

dapplion · 2024-07-11T12:26:32Z

The reason I built it was, i saw a couple of times sync being stalled and it was kind of pain to track down and figure out what we were waiting on this (because the batches are all numbers).

Sync lookup has now a gadget to detect when it gets stuck and drops a nice long report to logs. This has been the key to debug stalls in minutes instead of hours. We could do the same for other syncs

beacon_node/network/src/sync/range_sync/batch.rs

beacon_node/network/src/sync/range_sync/chain.rs

jimmygchen

Added some minor comments, otherwise looks good to me!

beacon_node/network/src/sync/range_sync/batch.rs

dapplion

There's a Cargo.lock diff

beacon_node/network/src/sync/range_sync/batch.rs

AgeManning · 2024-07-25T06:01:14Z

@Mergifyio queue

mergify · 2024-07-25T06:01:20Z

queue

🛑 Branch protection settings are not validated anymore

Branch protection is enabled and is preventing Mergify to merge the pull request. Mergify will merge when branch protection settings validate the pull request once again. (detail: 1 review requesting changes and 1 approving review by reviewers with write access.)

jimmygchen · 2024-07-25T13:41:50Z

@mergify requeue

mergify · 2024-07-25T13:42:10Z

requeue

✅ This pull request will be re-embarked automatically

The followup queue command will be automatically executed to re-embark the pull request

mergify · 2024-07-25T13:42:11Z

queue

🛑 The pull request has been removed from the queue `default`

The queue conditions cannot be satisfied due to failing checks.

You can take a look at Queue: Embarked in merge queue check runs for more details.

In case of a failure due to a flaky test, you should first retrigger the CI.
Then, re-embark the pull request into the merge queue by posting the comment
@mergifyio refresh on the pull request.

jimmygchen · 2024-07-25T23:45:14Z

@mergify requeue

mergify · 2024-07-25T23:45:23Z

requeue

✅ This pull request will be re-embarked automatically

The followup queue command will be automatically executed to re-embark the pull request

mergify · 2024-07-25T23:45:24Z

queue

🛑 Branch protection settings are not validated anymore

Branch protection is enabled and is preventing Mergify to merge the pull request. Mergify will merge when branch protection settings validate the pull request once again. (detail: 1 review requesting changes and 1 approving review by reviewers with write access.)

AgeManning · 2024-07-29T03:11:18Z

@Mergifyio refresh

mergify · 2024-07-29T03:11:22Z

refresh

✅ Pull request refreshed

jimmygchen · 2024-07-29T05:25:36Z

@mergify requeue

mergify · 2024-07-29T05:26:08Z

requeue

✅ This pull request will be re-embarked automatically

The followup queue command will be automatically executed to re-embark the pull request

mergify · 2024-07-29T05:26:09Z

queue

✅ The pull request has been merged automatically

The pull request has been merged automatically at a3b1ef3

Add visualization for batch states

ed4246a

jimmygchen added the UX-and-logs label Jul 3, 2024

Replace icons with emojis

660ccfc

jimmygchen reviewed Jul 23, 2024

View reviewed changes

beacon_node/network/src/sync/range_sync/batch.rs Outdated Show resolved Hide resolved

Reviewers comments

b949fb7

jimmygchen reviewed Jul 23, 2024

View reviewed changes

beacon_node/network/src/sync/range_sync/batch.rs Outdated Show resolved Hide resolved

jimmygchen reviewed Jul 23, 2024

View reviewed changes

beacon_node/network/src/sync/range_sync/chain.rs Outdated Show resolved Hide resolved

jimmygchen approved these changes Jul 23, 2024

View reviewed changes

AgeManning added 3 commits July 23, 2024 14:24

Change empty emoji and improve docs comments

9260896

Fix lints

11cc003

Move to letters rather than emojis

1517193

jimmygchen reviewed Jul 23, 2024

View reviewed changes

beacon_node/network/src/sync/range_sync/batch.rs Outdated Show resolved Hide resolved

Replace 'V' with 'v'. Cargo update

b9253ae

dapplion requested changes Jul 24, 2024

View reviewed changes

dapplion reviewed Jul 24, 2024

View reviewed changes

beacon_node/network/src/sync/range_sync/batch.rs Outdated Show resolved Hide resolved

AgeManning added 3 commits July 25, 2024 13:03

Merge latest unstable

6fe56af

Improve docs around visualisation

883da37

Merge branch 'unstable' into sync-batch-state

b99cdfe

mergify bot added a commit that referenced this pull request Jul 25, 2024

Merge of #6034

3c5eec3

jimmygchen added the ready-for-merge This PR is ready to merge. label Jul 25, 2024

mergify bot mentioned this pull request Jul 25, 2024

merge queue: embarking unstable (4e5a363) and #6034 together #6177

Closed

5 tasks

jimmygchen approved these changes Jul 25, 2024

View reviewed changes

mergify bot added a commit that referenced this pull request Jul 25, 2024

Merge of #6034

2ed29a5

mergify bot mentioned this pull request Jul 25, 2024

merge queue: embarking unstable (62a39af) and #6034 together #6182

Closed

5 tasks

mergify bot added a commit that referenced this pull request Jul 25, 2024

Merge of #6034

54bc2a4

This was referenced Jul 25, 2024

merge queue: embarking unstable (24169b2) and [#6034 + #6091] together #6186

Closed

Fix lighthouse account validator subcommands help text #6091

Merged

jimmygchen approved these changes Jul 26, 2024

View reviewed changes

dapplion approved these changes Jul 26, 2024

View reviewed changes

mergify bot added a commit that referenced this pull request Jul 29, 2024

Merge of #6034

0f10534

This was referenced Jul 29, 2024

merge queue: embarking unstable (f4ddc45) and [#6034 + #6181 + #6195] together #6196

Closed

Data column gossip validation and error handling #6181

Merged

Update database migration docs for 5.3 #6195

Merged

mergify bot merged commit a3b1ef3 into sigp:unstable Jul 29, 2024
28 checks passed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Visualisation logging for sync batch states #6034

Visualisation logging for sync batch states #6034

AgeManning commented Jul 2, 2024

jimmygchen commented Jul 3, 2024 •

edited

Loading

dapplion commented Jul 3, 2024

ackintosh commented Jul 3, 2024

AgeManning commented Jul 9, 2024

jimmygchen commented Jul 9, 2024

AgeManning commented Jul 9, 2024

dapplion commented Jul 10, 2024

AgeManning commented Jul 11, 2024

jimmygchen commented Jul 11, 2024

dapplion commented Jul 11, 2024

jimmygchen left a comment

dapplion left a comment

AgeManning commented Jul 25, 2024

mergify bot commented Jul 25, 2024 •

edited

Loading

jimmygchen commented Jul 25, 2024

mergify bot commented Jul 25, 2024

mergify bot commented Jul 25, 2024 •

edited

Loading

jimmygchen commented Jul 25, 2024

mergify bot commented Jul 25, 2024

mergify bot commented Jul 25, 2024 •

edited

Loading

AgeManning commented Jul 29, 2024

mergify bot commented Jul 29, 2024

jimmygchen commented Jul 29, 2024

mergify bot commented Jul 29, 2024

mergify bot commented Jul 29, 2024 •

edited

Loading

Visualisation logging for sync batch states #6034

Visualisation logging for sync batch states #6034

Conversation

AgeManning commented Jul 2, 2024

jimmygchen commented Jul 3, 2024 • edited Loading

dapplion commented Jul 3, 2024

ackintosh commented Jul 3, 2024

AgeManning commented Jul 9, 2024

jimmygchen commented Jul 9, 2024

AgeManning commented Jul 9, 2024

dapplion commented Jul 10, 2024

AgeManning commented Jul 11, 2024

jimmygchen commented Jul 11, 2024

dapplion commented Jul 11, 2024

jimmygchen left a comment

Choose a reason for hiding this comment

dapplion left a comment

Choose a reason for hiding this comment

AgeManning commented Jul 25, 2024

mergify bot commented Jul 25, 2024 • edited Loading

🛑 Branch protection settings are not validated anymore

jimmygchen commented Jul 25, 2024

mergify bot commented Jul 25, 2024

✅ This pull request will be re-embarked automatically

mergify bot commented Jul 25, 2024 • edited Loading

🛑 The pull request has been removed from the queue default

jimmygchen commented Jul 25, 2024

mergify bot commented Jul 25, 2024

✅ This pull request will be re-embarked automatically

mergify bot commented Jul 25, 2024 • edited Loading

🛑 Branch protection settings are not validated anymore

AgeManning commented Jul 29, 2024

mergify bot commented Jul 29, 2024

✅ Pull request refreshed

jimmygchen commented Jul 29, 2024

mergify bot commented Jul 29, 2024

✅ This pull request will be re-embarked automatically

mergify bot commented Jul 29, 2024 • edited Loading

✅ The pull request has been merged automatically

jimmygchen commented Jul 3, 2024 •

edited

Loading

mergify bot commented Jul 25, 2024 •

edited

Loading

mergify bot commented Jul 25, 2024 •

edited

Loading

🛑 The pull request has been removed from the queue `default`

mergify bot commented Jul 25, 2024 •

edited

Loading

mergify bot commented Jul 29, 2024 •

edited

Loading