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

Execution stage progress reporting starts at 100% #6140

Closed
1 task done
mattsse opened this issue Jan 19, 2024 · 2 comments · Fixed by #6579
Closed
1 task done

Execution stage progress reporting starts at 100% #6140

mattsse opened this issue Jan 19, 2024 · 2 comments · Fixed by #6579
Assignees
Labels
A-observability Related to tracing, metrics, logs and other observability tools C-bug An unexpected or incorrect behavior

Comments

@mattsse
Copy link
Collaborator

mattsse commented Jan 19, 2024

Describe the bug

incorrect 100% reporting at transition into execution stage

2024-01-19T23:50:56.937875Z  INFO reth::commands::node::events: Executing stage pipeline_stages=4/13 stage=SenderRecovery checkpoint=765769 target=771292 stage_progress=100.00% stage_eta=unknown
2024-01-19T23:51:00.984839Z  INFO reth::commands::node::events: Forkchoice updated head_block_hash=0x8ca448535b9a06452dc16c36d6e15642f859af84e2ae606dff77ffa6e7da2c27 safe_block_hash=0xf780d11707a3db8d167e5bc3f19a22d8da8ee9936f2367dc2d99e3f72fd0e9c8 finalized_block_hash=0x4e0d95e557f5618567826484ee2477f06044cb6dc4dad96957de45810527b0df status=Syncing
2024-01-19T23:51:03.460903Z  INFO reth::commands::node::events: Stage finished executing pipeline_stages=4/13 stage=SenderRecovery checkpoint=771292 target=771292 stage_progress=100.00% stage_eta=unknown
2024-01-19T23:51:03.559389Z  INFO reth::commands::node::events: Executing stage pipeline_stages=5/13 stage=Execution checkpoint=765769 target=771292 stage_progress=100.00%
2024-01-19T23:51:05.237379Z  INFO reth::cli: Status connected_peers=1 freelist=126138 stage=Execution checkpoint=765769 target=771292 stage_progress=100.00%
....
2024-01-19T23:52:03.294980Z  INFO reth::commands::node::events: Stage finished executing pipeline_stages=5/13 stage=Execution checkpoint=771292 target=771292 stage_progress=100.00%

looks like the initial % calc is wrong if there's one batch

Steps to reproduce

Node logs

No response

Platform(s)

No response

What version/commit are you on?

No response

What database version are you on?

No response

What type of node are you running?

None

What prune config do you use, if any?

No response

If you've built Reth from source, provide the full command you used

No response

Code of Conduct

  • I agree to follow the Code of Conduct
@mattsse mattsse added C-bug An unexpected or incorrect behavior S-needs-triage This issue needs to be labelled labels Jan 19, 2024
@mattsse mattsse added A-observability Related to tracing, metrics, logs and other observability tools and removed S-needs-triage This issue needs to be labelled labels Jan 19, 2024
@pistomat
Copy link
Contributor

pistomat commented Feb 7, 2024

+1 I am also having this issue.

@shekhirin
Copy link
Collaborator

So I believe the issue is that when processing the PipelineEvent::Run, we grab the checkpoint from previous execution

PipelineEvent::Run { pipeline_stages_progress, stage_id, checkpoint, target } => {
let checkpoint = checkpoint.unwrap_or_default();
let current_stage = CurrentStage {
stage_id,
eta: match &self.current_stage {
Some(current_stage) if current_stage.stage_id == stage_id => {
current_stage.eta
}
_ => Eta::default(),
},
checkpoint,
target,
};
let stage_progress = OptionalField(
checkpoint.entities().and_then(|entities| entities.fmt_percentage()),
);

which means that it contains the outdated progress (which is gas processed for the Execution stage).

When processing the PipelineEvent::Ran, we have new checkpoint coming from the fresh execution

PipelineEvent::Ran {
pipeline_stages_progress,
stage_id,
result: ExecOutput { checkpoint, done },
} => {
if stage_id.is_finish() {
self.latest_block = Some(checkpoint.block_number);
}
if let Some(current_stage) = self.current_stage.as_mut() {
current_stage.checkpoint = checkpoint;
current_stage.eta.update(checkpoint);
let target = OptionalField(current_stage.target);
let stage_progress = OptionalField(
checkpoint.entities().and_then(|entities| entities.fmt_percentage()),
);
and it should contain the up-to-date information.

I would suggest we remove the stage_progress field from Executing stage message and leave only checkpoint and target. For Stage committed progress and Stage finished executing messages, we can leave the stage_progress as-is.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
A-observability Related to tracing, metrics, logs and other observability tools C-bug An unexpected or incorrect behavior
Projects
Archived in project
Development

Successfully merging a pull request may close this issue.

3 participants