1use std::{sync::Arc, time::Duration};
5
6use parking_lot::RwLock;
7use tokio::time::Instant;
8use tracing::info;
9
10use crate::{
11 CommitConsumerArgs, CommittedSubDag,
12 block::{BlockAPI, VerifiedBlock},
13 commit::{CommitAPI, load_committed_subdag_from_store},
14 commit_finalizer::{CommitFinalizer, CommitFinalizerHandle},
15 context::Context,
16 dag_state::DagState,
17 error::ConsensusResult,
18 linearizer::Linearizer,
19 storage::Store,
20 task::spawn_blocking,
21 transaction_vote_tracker::TransactionVoteTracker,
22};
23
24pub(crate) struct CommitObserver {
37 context: Arc<Context>,
38 dag_state: Arc<RwLock<DagState>>,
39 store: Arc<dyn Store>,
41 transaction_vote_tracker: TransactionVoteTracker,
42 commit_interpreter: Linearizer,
44 commit_finalizer_handle: CommitFinalizerHandle,
46}
47
48impl CommitObserver {
49 pub(crate) async fn new(
50 context: Arc<Context>,
51 commit_consumer: CommitConsumerArgs,
52 dag_state: Arc<RwLock<DagState>>,
53 transaction_vote_tracker: TransactionVoteTracker,
54 ) -> Self {
55 let store = dag_state.read().store();
56 let commit_interpreter = Linearizer::new(context.clone(), dag_state.clone());
57 let commit_finalizer_handle = CommitFinalizer::start(
58 context.clone(),
59 dag_state.clone(),
60 transaction_vote_tracker.clone(),
61 commit_consumer.commit_sender.clone(),
62 );
63
64 let mut observer = Self {
65 context,
66 dag_state,
67 store,
68 transaction_vote_tracker,
69 commit_interpreter,
70 commit_finalizer_handle,
71 };
72 observer.recover_and_send_commits(&commit_consumer).await;
73
74 if let Err(e) = spawn_blocking({
78 let transaction_vote_tracker = observer.transaction_vote_tracker.clone();
79 let gc_round = observer.dag_state.read().gc_round();
80 move || {
81 transaction_vote_tracker.recover_blocks_after_round(gc_round);
82 }
83 })
84 .await
85 {
86 info!("Skipping block recovery for transaction voting: {e}");
87 }
88
89 observer
90 }
91
92 pub(crate) async fn stop(&mut self) {
93 self.commit_finalizer_handle.stop().await;
94 }
95
96 pub(crate) fn handle_committed_leaders(
101 &mut self,
102 committed_leaders: Vec<VerifiedBlock>,
103 local: bool,
104 ) -> ConsensusResult<Vec<CommittedSubDag>> {
105 let _s = self
106 .context
107 .metrics
108 .node_metrics
109 .scope_processing_time
110 .with_label_values(&["CommitObserver::handle_committed_leaders"])
111 .start_timer();
112
113 let mut committed_sub_dags = self.commit_interpreter.handle_commit(committed_leaders);
114 self.report_metrics(&committed_sub_dags);
115
116 for subdag in committed_sub_dags.iter_mut() {
118 subdag.decided_with_local_blocks = local;
119 }
120
121 for commit in committed_sub_dags.iter() {
122 tracing::debug!(
123 "Sending commit {} leader {} to finalization and execution.",
124 commit.commit_ref,
125 commit.leader
126 );
127 tracing::trace!("Committed subdag: {:#?}", commit);
128 self.commit_finalizer_handle.send(commit.clone())?;
130 }
131
132 self.dag_state
133 .write()
134 .add_scoring_subdags(committed_sub_dags.clone());
135
136 Ok(committed_sub_dags)
137 }
138
139 pub(crate) fn send_to_finalizer(&self, subdag: CommittedSubDag) -> ConsensusResult<()> {
141 self.commit_finalizer_handle.send(subdag)
142 }
143
144 async fn recover_and_send_commits(&mut self, commit_consumer: &CommitConsumerArgs) {
145 let now = Instant::now();
146
147 let replay_after_commit_index = commit_consumer.replay_after_commit_index;
148
149 let last_commit = self
150 .store
151 .read_last_commit()
152 .expect("Reading the last commit should not fail");
153 let Some(last_commit) = &last_commit else {
154 assert_eq!(
155 replay_after_commit_index, 0,
156 "Commit replay should start at the beginning if there is no commit history"
157 );
158 info!("Nothing to recover for commit observer - starting new epoch");
159 return;
160 };
161
162 let last_commit_index = last_commit.index();
163 if last_commit_index == replay_after_commit_index {
164 info!(
165 "Nothing to recover for commit observer - replay is requested immediately after last commit index {last_commit_index}"
166 );
167 return;
168 }
169 assert!(last_commit_index > replay_after_commit_index);
170
171 info!(
172 "Recovering commit observer in the range [{}..={last_commit_index}]",
173 replay_after_commit_index + 1,
174 );
175
176 const COMMIT_RECOVERY_BATCH_SIZE: u32 = if cfg!(test) { 3 } else { 250 };
179
180 let mut last_sent_commit_index = replay_after_commit_index;
181
182 self.dag_state.read().ensure_commits_to_write_is_empty();
184
185 let mut seen_unfinalized_commit = false;
186 for start_index in (replay_after_commit_index + 1..=last_commit_index)
187 .step_by(COMMIT_RECOVERY_BATCH_SIZE as usize)
188 {
189 let end_index = start_index
190 .saturating_add(COMMIT_RECOVERY_BATCH_SIZE - 1)
191 .min(last_commit_index);
192
193 let unsent_commits = self
194 .store
195 .scan_commits((start_index..=end_index).into())
196 .expect("Scanning commits should not fail");
197 assert_eq!(
198 unsent_commits.len() as u32,
199 end_index.checked_sub(start_index).unwrap() + 1,
200 "Gap in scanned commits: start index: {start_index}, end index: {end_index}, commits: {:?}",
201 unsent_commits,
202 );
203
204 self.dag_state
207 .write()
208 .recover_commits_to_write(unsent_commits.clone());
209
210 info!(
211 "Recovering {} unsent commits in range [{start_index}..={end_index}]",
212 unsent_commits.len()
213 );
214
215 for commit in unsent_commits.into_iter() {
218 last_sent_commit_index += 1;
220 assert_eq!(commit.index(), last_sent_commit_index);
221
222 let committed_sub_dag =
223 load_committed_subdag_from_store(self.store.as_ref(), commit);
224
225 if !committed_sub_dag.recovered_rejected_transactions && !seen_unfinalized_commit {
226 info!(
227 "Starting to recover unfinalized commit from {}",
228 committed_sub_dag.commit_ref
229 );
230 seen_unfinalized_commit = true;
233 }
234
235 if seen_unfinalized_commit {
236 assert!(!committed_sub_dag.recovered_rejected_transactions);
238 assert!(!committed_sub_dag.decided_with_local_blocks);
241 self.transaction_vote_tracker
244 .recover_and_vote_on_blocks(committed_sub_dag.blocks.clone());
245 }
246
247 self.commit_finalizer_handle
248 .send(committed_sub_dag)
249 .unwrap();
250
251 self.context
252 .metrics
253 .node_metrics
254 .commit_observer_last_recovered_commit_index
255 .set(last_sent_commit_index as i64);
256
257 tokio::task::yield_now().await;
258 }
259 }
260
261 assert_eq!(
262 last_sent_commit_index, last_commit_index,
263 "We should have sent all commits up to the last commit {}",
264 last_commit_index
265 );
266
267 info!(
268 "Commit observer recovery [{}..={}] completed, took {:?}",
269 replay_after_commit_index + 1,
270 last_commit_index,
271 now.elapsed()
272 );
273 }
274
275 pub(crate) fn report_commit_metrics(&self, commit: &CommittedSubDag) {
278 let metrics = &self.context.metrics.node_metrics;
279 let utc_now = self.context.clock.timestamp_utc_ms();
280
281 info!(
282 "Consensus commit {} with leader {} has {} blocks",
283 commit.commit_ref,
284 commit.leader,
285 commit.blocks.len()
286 );
287
288 metrics
289 .last_committed_leader_round
290 .set(commit.leader.round as i64);
291 metrics
292 .last_commit_index
293 .set(commit.commit_ref.index as i64);
294 metrics
295 .blocks_per_commit_count
296 .observe(commit.blocks.len() as f64);
297
298 for block in &commit.blocks {
299 let latency_ms = utc_now.saturating_sub(block.timestamp_ms());
300 metrics
301 .block_commit_latency
302 .observe(Duration::from_millis(latency_ms).as_secs_f64());
303 if block.author() == self.context.own_index {
304 metrics
305 .proposed_block_commit_latency
306 .observe(Duration::from_millis(latency_ms).as_secs_f64());
307 }
308 }
309 }
310
311 fn report_metrics(&self, committed: &[CommittedSubDag]) {
312 for commit in committed {
313 self.report_commit_metrics(commit);
314 }
315 self.context
319 .metrics
320 .node_metrics
321 .sub_dags_per_commit_count
322 .observe(committed.len() as f64);
323 }
324}
325
326#[cfg(test)]
327mod tests {
328 use consensus_types::block::BlockRef;
329 use mysten_metrics::monitored_mpsc::UnboundedReceiver;
330 use parking_lot::RwLock;
331 use rstest::rstest;
332 use tokio::time::timeout;
333
334 use super::*;
335 use crate::{
336 CommitIndex, block_verifier::NoopBlockVerifier, context::Context, dag_state::DagState,
337 linearizer::median_timestamp_by_stake, storage::mem_store::MemStore,
338 test_dag_builder::DagBuilder,
339 };
340
341 #[rstest]
342 #[tokio::test]
343 async fn test_handle_commit() {
344 telemetry_subscribers::init_for_testing();
345 let num_authorities = 4;
346 let (context, _keys) = Context::new_for_test(num_authorities);
347 let context = Arc::new(context);
348
349 let mem_store = Arc::new(MemStore::new());
350 let dag_state = Arc::new(RwLock::new(DagState::new(
351 context.clone(),
352 mem_store.clone(),
353 )));
354 let last_processed_commit_index = 0;
355 let (commit_consumer, mut commit_receiver) =
356 CommitConsumerArgs::new(0, last_processed_commit_index);
357 let transaction_vote_tracker = TransactionVoteTracker::new(
358 context.clone(),
359 Arc::new(NoopBlockVerifier {}),
360 dag_state.clone(),
361 );
362
363 let mut observer = CommitObserver::new(
364 context.clone(),
365 commit_consumer,
366 dag_state.clone(),
367 transaction_vote_tracker.clone(),
368 )
369 .await;
370
371 let num_rounds = 10;
373 let mut builder = DagBuilder::new(context.clone());
374 builder
375 .layers(1..=num_rounds)
376 .build()
377 .persist_layers(dag_state.clone());
378 transaction_vote_tracker.add_voted_blocks(
379 builder
380 .all_blocks()
381 .iter()
382 .map(|b| (b.clone(), vec![]))
383 .collect(),
384 );
385
386 let leaders = builder
387 .leader_blocks(1..=num_rounds)
388 .into_iter()
389 .map(Option::unwrap)
390 .collect::<Vec<_>>();
391
392 let commits = observer
393 .handle_committed_leaders(leaders.clone(), true)
394 .unwrap();
395
396 let mut expected_stored_refs: Vec<BlockRef> = vec![];
398 for (idx, subdag) in commits.iter().enumerate() {
399 tracing::info!("{subdag:?}");
400 assert_eq!(subdag.leader, leaders[idx].reference());
401
402 let expected_ts = {
403 let block_refs = leaders[idx]
404 .ancestors()
405 .iter()
406 .filter(|block_ref| block_ref.round == leaders[idx].round() - 1)
407 .cloned()
408 .collect::<Vec<_>>();
409 let block_opts = dag_state.read().get_blocks(&block_refs);
410 let blocks = block_opts.iter().map(|block_opt| {
411 block_opt
412 .as_ref()
413 .expect("We should have all blocks in dag state.")
414 });
415 median_timestamp_by_stake(&context, blocks).unwrap()
416 };
417
418 let expected_ts = if idx == 0 {
419 expected_ts
420 } else {
421 expected_ts.max(commits[idx - 1].timestamp_ms)
422 };
423
424 assert_eq!(expected_ts, subdag.timestamp_ms);
425
426 if idx == 0 {
427 assert_eq!(subdag.blocks.len(), 1);
430 } else {
431 assert_eq!(subdag.blocks.len(), num_authorities);
434 }
435 for block in subdag.blocks.iter() {
436 expected_stored_refs.push(block.reference());
437 assert!(block.round() <= leaders[idx].round());
438 }
439 assert_eq!(subdag.commit_ref.index, idx as CommitIndex + 1);
440 }
441
442 let mut processed_subdag_index = 0;
444 while let Ok(Some(subdag)) = timeout(Duration::from_secs(1), commit_receiver.recv()).await {
445 assert_eq!(subdag, commits[processed_subdag_index]);
446 processed_subdag_index = subdag.commit_ref.index as usize;
447 if processed_subdag_index == leaders.len() {
448 break;
449 }
450 }
451 assert_eq!(processed_subdag_index, leaders.len());
452
453 let own_committed_blocks = commits
456 .iter()
457 .flat_map(|commit| commit.blocks.iter())
458 .filter(|block| block.author() == context.own_index)
459 .count() as u64;
460 assert!(own_committed_blocks > 0);
461 assert_eq!(
462 context
463 .metrics
464 .node_metrics
465 .proposed_block_commit_latency
466 .get_sample_count(),
467 own_committed_blocks
468 );
469 assert_eq!(
470 context
471 .metrics
472 .node_metrics
473 .proposed_block_finalization_latency
474 .get_sample_count(),
475 own_committed_blocks
476 );
477
478 verify_channel_empty(&mut commit_receiver).await;
479
480 let last_commit = mem_store.read_last_commit().unwrap().unwrap();
482 assert_eq!(
483 last_commit.index(),
484 commits.last().unwrap().commit_ref.index
485 );
486 let all_stored_commits = mem_store
487 .scan_commits((0..=CommitIndex::MAX).into())
488 .unwrap();
489 assert_eq!(all_stored_commits.len(), leaders.len());
490 let blocks_existence = mem_store.contains_blocks(&expected_stored_refs).unwrap();
491 assert!(blocks_existence.iter().all(|exists| *exists));
492 }
493
494 #[tokio::test]
495 async fn test_recover_and_send_commits() {
496 telemetry_subscribers::init_for_testing();
497 let num_authorities = 4;
498 let context = Arc::new(Context::new_for_test(num_authorities).0);
499 let mem_store = Arc::new(MemStore::new());
500 let dag_state = Arc::new(RwLock::new(DagState::new(
501 context.clone(),
502 mem_store.clone(),
503 )));
504 let transaction_vote_tracker = TransactionVoteTracker::new(
505 context.clone(),
506 Arc::new(NoopBlockVerifier {}),
507 dag_state.clone(),
508 );
509 let last_processed_commit_index = 0;
510 let (commit_consumer, mut commit_receiver) =
511 CommitConsumerArgs::new(0, last_processed_commit_index);
512
513 let mut observer = CommitObserver::new(
514 context.clone(),
515 commit_consumer,
516 dag_state.clone(),
517 transaction_vote_tracker.clone(),
518 )
519 .await;
520
521 let num_rounds = 10;
523 let mut builder = DagBuilder::new(context.clone());
524 builder
525 .layers(1..=num_rounds)
526 .build()
527 .persist_layers(dag_state.clone());
528 transaction_vote_tracker.add_voted_blocks(
529 builder
530 .all_blocks()
531 .iter()
532 .map(|b| (b.clone(), vec![]))
533 .collect(),
534 );
535
536 let leaders = builder
537 .leader_blocks(1..=num_rounds)
538 .into_iter()
539 .map(Option::unwrap)
540 .collect::<Vec<_>>();
541
542 let expected_last_processed_index: usize = 2;
545 let mut commits = observer
546 .handle_committed_leaders(leaders[..expected_last_processed_index].to_vec(), true)
547 .unwrap();
548
549 let mut processed_subdag_index = 0;
551 while let Ok(Some(subdag)) = timeout(Duration::from_secs(1), commit_receiver.recv()).await {
552 tracing::info!("Processed {subdag}");
553 assert_eq!(subdag, commits[processed_subdag_index]);
554 processed_subdag_index = subdag.commit_ref.index as usize;
555 if processed_subdag_index == expected_last_processed_index {
556 break;
557 }
558 }
559 assert_eq!(processed_subdag_index, expected_last_processed_index);
560
561 verify_channel_empty(&mut commit_receiver).await;
562
563 let last_commit = mem_store.read_last_commit().unwrap().unwrap();
565 assert_eq!(
566 last_commit.index(),
567 expected_last_processed_index as CommitIndex
568 );
569
570 commits.append(
574 &mut observer
575 .handle_committed_leaders(leaders[expected_last_processed_index..].to_vec(), true)
576 .unwrap(),
577 );
578
579 let expected_last_sent_index = num_rounds as usize;
580 while let Ok(Some(subdag)) = timeout(Duration::from_secs(1), commit_receiver.recv()).await {
581 tracing::info!("{subdag} was sent but not processed by consumer");
582 assert_eq!(subdag, commits[processed_subdag_index]);
583 assert!(subdag.decided_with_local_blocks);
584 processed_subdag_index = subdag.commit_ref.index as usize;
585 if processed_subdag_index == expected_last_sent_index {
586 break;
587 }
588 }
589 assert_eq!(processed_subdag_index, expected_last_sent_index);
590
591 verify_channel_empty(&mut commit_receiver).await;
592
593 let last_commit = mem_store.read_last_commit().unwrap().unwrap();
597 assert_eq!(last_commit.index(), expected_last_sent_index as CommitIndex);
598
599 {
601 let replay_after_commit_index = 2;
602 let consumer_last_processed_commit_index = 10;
603 let dag_state = Arc::new(RwLock::new(DagState::new(
604 context.clone(),
605 mem_store.clone(),
606 )));
607 let (commit_consumer, mut commit_receiver) = CommitConsumerArgs::new(
608 replay_after_commit_index,
609 consumer_last_processed_commit_index,
610 );
611 let _observer = CommitObserver::new(
612 context.clone(),
613 commit_consumer,
614 dag_state.clone(),
615 transaction_vote_tracker.clone(),
616 )
617 .await;
618
619 let mut processed_subdag_index = replay_after_commit_index;
620 while let Ok(Some(mut subdag)) =
621 timeout(Duration::from_secs(1), commit_receiver.recv()).await
622 {
623 tracing::info!("Received {subdag} on recovery");
624 assert_eq!(subdag.commit_ref.index, processed_subdag_index + 1);
625 assert!(subdag.recovered_rejected_transactions);
626
627 subdag.recovered_rejected_transactions = false;
629 assert_eq!(subdag, commits[processed_subdag_index as usize]);
630
631 assert!(subdag.decided_with_local_blocks);
632 processed_subdag_index = subdag.commit_ref.index;
633 if processed_subdag_index == consumer_last_processed_commit_index {
634 break;
635 }
636 }
637 assert_eq!(processed_subdag_index, consumer_last_processed_commit_index);
638
639 verify_channel_empty(&mut commit_receiver).await;
640 }
641
642 {
644 let replay_after_commit_index = 10;
645 let consumer_last_processed_commit_index = 10;
646 let dag_state = Arc::new(RwLock::new(DagState::new(
647 context.clone(),
648 mem_store.clone(),
649 )));
650 let (commit_consumer, mut commit_receiver) = CommitConsumerArgs::new(
653 replay_after_commit_index,
654 consumer_last_processed_commit_index,
655 );
656 let _observer = CommitObserver::new(
657 context.clone(),
658 commit_consumer,
659 dag_state.clone(),
660 transaction_vote_tracker.clone(),
661 )
662 .await;
663
664 verify_channel_empty(&mut commit_receiver).await;
667 }
668
669 {
671 let replay_after_commit_index = 2;
672 let consumer_last_processed_commit_index = 4;
673 let dag_state = Arc::new(RwLock::new(DagState::new(
674 context.clone(),
675 mem_store.clone(),
676 )));
677 let (commit_consumer, mut commit_receiver) = CommitConsumerArgs::new(
678 replay_after_commit_index,
679 consumer_last_processed_commit_index,
680 );
681 let _observer = CommitObserver::new(
682 context.clone(),
683 commit_consumer,
684 dag_state.clone(),
685 transaction_vote_tracker.clone(),
686 )
687 .await;
688
689 let mut processed_subdag_index = replay_after_commit_index;
692 while let Ok(Some(subdag)) =
693 timeout(Duration::from_secs(1), commit_receiver.recv()).await
694 {
695 tracing::info!("Received {subdag} on recovery");
696 assert_eq!(subdag.commit_ref.index, processed_subdag_index + 1);
697 assert!(subdag.decided_with_local_blocks);
698 processed_subdag_index = subdag.commit_ref.index;
699 if processed_subdag_index == expected_last_sent_index as CommitIndex {
700 break;
701 }
702 }
703 assert_eq!(
704 processed_subdag_index,
705 expected_last_sent_index as CommitIndex
706 );
707
708 verify_channel_empty(&mut commit_receiver).await;
709 }
710
711 {
715 let replay_after_commit_index = 2;
716 let consumer_last_processed_commit_index = 20;
717 let dag_state = Arc::new(RwLock::new(DagState::new(
718 context.clone(),
719 mem_store.clone(),
720 )));
721 let (commit_consumer, mut commit_receiver) = CommitConsumerArgs::new(
722 replay_after_commit_index,
723 consumer_last_processed_commit_index,
724 );
725 let _observer = CommitObserver::new(
726 context.clone(),
727 commit_consumer,
728 dag_state.clone(),
729 transaction_vote_tracker.clone(),
730 )
731 .await;
732
733 let mut processed_subdag_index = replay_after_commit_index;
736 while let Ok(Some(mut subdag)) =
737 timeout(Duration::from_secs(1), commit_receiver.recv()).await
738 {
739 tracing::info!("Received {subdag} on recovery");
740 assert_eq!(subdag.commit_ref.index, processed_subdag_index + 1);
741 assert!(subdag.recovered_rejected_transactions);
742
743 subdag.recovered_rejected_transactions = false;
745 assert_eq!(subdag, commits[processed_subdag_index as usize]);
746
747 assert!(subdag.decided_with_local_blocks);
748 processed_subdag_index = subdag.commit_ref.index;
749 if processed_subdag_index == expected_last_sent_index as CommitIndex {
750 break;
751 }
752 }
753 assert_eq!(
754 processed_subdag_index,
755 expected_last_sent_index as CommitIndex
756 );
757 assert_eq!(10, expected_last_sent_index);
758
759 verify_channel_empty(&mut commit_receiver).await;
760 }
761 }
762
763 async fn verify_channel_empty(receiver: &mut UnboundedReceiver<CommittedSubDag>) {
765 if let Ok(Some(_)) = timeout(Duration::from_secs(1), receiver.recv()).await {
766 panic!("Expected the consensus output channel to be empty, but found more subdags.")
767 }
768 }
769}