1use std::collections::BTreeMap;
2use std::fs;
3use std::path::{Path, PathBuf};
4use std::sync::Arc;
5use std::time::{Duration, Instant};
6
7use aleph_bft::Keychain as KeychainTrait;
8use anyhow::{Context, anyhow, bail};
9use async_channel::Receiver;
10use fedimint_api_client::api::{DynGlobalApi, FederationApiExt, ServerError};
11use fedimint_api_client::query::FilterMap;
12use fedimint_core::config::P2PMessage;
13use fedimint_core::core::{DynOutput, MODULE_INSTANCE_ID_GLOBAL};
14use fedimint_core::db::{
15 Database, DatabaseError, DatabaseResult, DatabaseTransaction, IDatabaseTransactionOpsCoreTyped,
16};
17use fedimint_core::encoding::Decodable;
18use fedimint_core::endpoint_constants::AWAIT_SIGNED_SESSION_OUTCOME_ENDPOINT;
19use fedimint_core::envs::is_running_in_test_env;
20use fedimint_core::module::audit::Audit;
21use fedimint_core::module::registry::ModuleDecoderRegistry;
22use fedimint_core::module::{ApiRequestErased, SerdeModuleEncoding};
23use fedimint_core::net::DynP2PConnections;
24use fedimint_core::runtime::spawn;
25use fedimint_core::secp256k1::schnorr;
26use fedimint_core::session_outcome::{
27 AcceptedItem, ConsensusItem, SessionOutcome, SignedSessionOutcome,
28};
29use fedimint_core::task::{TaskGroup, TaskHandle, sleep};
30use fedimint_core::timing::TimeReporter;
31use fedimint_core::util::{FmtCompact as _, FmtCompactAnyhow as _};
32use fedimint_core::{NumPeers, NumPeersExt, PeerId, timing};
33use fedimint_server_core::{ServerModuleRegistry, ServerModuleRegistryExt};
34use futures::StreamExt;
35use rand::Rng;
36use rand::seq::IteratorRandom;
37use tokio::sync::watch;
38use tracing::{Level, debug, error, info, instrument, trace, warn};
39
40use crate::LOG_CONSENSUS;
41use crate::config::ServerConfig;
42use crate::consensus::aleph_bft::backup::{BackupReader, BackupWriter};
43use crate::consensus::aleph_bft::data_provider::{DataProvider, UnitData};
44use crate::consensus::aleph_bft::finalization_handler::{FinalizationHandler, OrderedUnit};
45use crate::consensus::aleph_bft::keychain::Keychain;
46use crate::consensus::aleph_bft::network::Network;
47use crate::consensus::aleph_bft::spawner::Spawner;
48use crate::consensus::aleph_bft::to_node_index;
49use crate::consensus::db::{
50 AcceptedItemKey, AcceptedItemPrefix, AcceptedTransactionKey, AlephUnitsPrefix,
51 SignedSessionOutcomeKey, SignedSessionOutcomePrefix,
52};
53use crate::consensus::debug::{DebugConsensusItem, DebugConsensusItemCompact};
54use crate::consensus::transaction::{TxProcessingMode, process_transaction_with_dbtx};
55use crate::metrics::{
56 CONSENSUS_ITEM_PROCESSING_DURATION_SECONDS,
57 CONSENSUS_ITEM_PROCESSING_MODULE_AUDIT_DURATION_SECONDS, CONSENSUS_ITEMS_PROCESSED_TOTAL,
58 CONSENSUS_ORDERING_LATENCY_SECONDS, CONSENSUS_PEER_CONTRIBUTION_SESSION_IDX,
59 CONSENSUS_SESSION_COUNT,
60};
61
62const DB_CHECKPOINTS_DIR: &str = "db_checkpoints";
64
65const MAX_ITEM_PROCESSING_ATTEMPTS: usize = 10;
70
71pub struct ConsensusEngine {
73 pub modules: ServerModuleRegistry,
74 pub db: Database,
75 pub federation_api: DynGlobalApi,
76 pub cfg: ServerConfig,
77 pub submission_receiver: Receiver<ConsensusItem>,
78 pub shutdown_receiver: watch::Receiver<Option<u64>>,
79 pub connections: DynP2PConnections<P2PMessage>,
80 pub ci_status_senders: BTreeMap<PeerId, watch::Sender<Option<u64>>>,
81 pub ord_latency_sender: watch::Sender<Option<Duration>>,
82 pub task_group: TaskGroup,
83 pub data_dir: PathBuf,
84 pub db_checkpoint_retention: u64,
85 pub session_timeout: Duration,
86}
87
88impl ConsensusEngine {
89 fn num_peers(&self) -> NumPeers {
90 self.cfg.consensus.broadcast_public_keys.to_num_peers()
91 }
92
93 fn identity(&self) -> PeerId {
94 self.cfg.local.identity
95 }
96
97 #[instrument(target = LOG_CONSENSUS, name = "run", skip_all, fields(id=%self.cfg.local.identity))]
98 pub async fn run(self) -> anyhow::Result<()> {
99 if self.num_peers().total() == 1 {
100 self.run_single_guardian(self.task_group.make_handle())
101 .await
102 } else {
103 self.run_consensus(self.task_group.make_handle()).await
104 }
105 }
106
107 pub async fn run_single_guardian(&self, task_handle: TaskHandle) -> anyhow::Result<()> {
108 assert_eq!(self.num_peers(), NumPeers::from(1));
109
110 self.initialize_checkpoint_directory(self.get_finished_session_count().await)?;
111
112 while !task_handle.is_shutting_down() {
113 let session_index = self.get_finished_session_count().await;
114
115 CONSENSUS_SESSION_COUNT.set(session_index as i64);
116
117 let mut item_index = self.pending_accepted_items().await.len() as u64;
118
119 let session_start_time = std::time::Instant::now();
120
121 while let Ok(item) = self.submission_receiver.recv().await {
122 if self
123 .process_consensus_item(session_index, item_index, item, self.identity())
124 .await
125 .is_ok()
126 {
127 item_index += 1;
128 }
129
130 if session_start_time.elapsed() > Duration::from_mins(1) {
132 break;
133 }
134 }
135
136 let session_outcome = SessionOutcome {
137 items: self.pending_accepted_items().await,
138 };
139
140 let header = session_outcome.header(session_index);
141 let signature = Keychain::new(&self.cfg).sign_schnorr(&header);
142 let signatures = BTreeMap::from_iter([(self.identity(), signature)]);
143
144 self.complete_session(
145 session_index,
146 SignedSessionOutcome {
147 session_outcome,
148 signatures,
149 },
150 )
151 .await;
152
153 self.checkpoint_database(session_index);
154
155 info!(target: LOG_CONSENSUS, "Session {session_index} completed");
156
157 if Some(session_index) == self.shutdown_receiver.borrow().to_owned() {
158 break;
159 }
160 }
161
162 info!(target: LOG_CONSENSUS, "Consensus task shut down");
163
164 Ok(())
165 }
166
167 pub async fn run_consensus(&self, task_handle: TaskHandle) -> anyhow::Result<()> {
168 assert!(self.num_peers().total() >= 4);
170
171 self.initialize_checkpoint_directory(self.get_finished_session_count().await)?;
172
173 while !task_handle.is_shutting_down() {
174 let session_index = self.get_finished_session_count().await;
175
176 CONSENSUS_SESSION_COUNT.set(session_index as i64);
177
178 let is_recovery = self.is_recovery().await;
179
180 info!(
181 target: LOG_CONSENSUS,
182 session_index,
183 is_recovery,
184 "Starting consensus session"
185 );
186
187 let session = tokio::time::timeout(
193 self.session_timeout,
194 self.run_session(self.connections.clone(), session_index),
195 )
196 .await
197 .context("Consensus session timed out, exiting...")?;
198
199 if session.is_none() {
200 return Ok(());
201 }
202
203 info!(target: LOG_CONSENSUS, ?session_index, "Completed consensus session");
204
205 if Some(session_index) == self.shutdown_receiver.borrow().to_owned() {
206 info!(target: LOG_CONSENSUS, "Initiating shutdown, waiting for peers to complete the session...");
207
208 sleep(Duration::from_mins(1)).await;
209
210 break;
211 }
212 }
213
214 info!(target: LOG_CONSENSUS, "Consensus task shut down");
215
216 Ok(())
217 }
218
219 pub async fn run_session(
220 &self,
221 connections: DynP2PConnections<P2PMessage>,
222 session_index: u64,
223 ) -> Option<()> {
224 const EXP_SLOWDOWN_ROUNDS: u16 = 1000;
242 const BASE: f64 = 1.02;
243
244 let rounds_per_session = self.cfg.consensus.broadcast_rounds_per_session;
245 let round_delay = f64::from(self.cfg.local.broadcast_round_delay_ms);
246
247 let mut delay_config = aleph_bft::default_delay_config();
248
249 delay_config.unit_creation_delay = Arc::new(move |round_index| {
250 let jitter = if is_running_in_test_env() {
254 rand::thread_rng().gen_range(0.5..=1.5)
255 } else {
256 1.0
257 };
258
259 let delay = if round_index == 0 {
260 0.0
261 } else {
262 round_delay
263 * BASE.powf(round_index.saturating_sub(rounds_per_session as usize) as f64)
264 * jitter
265 };
266
267 Duration::from_millis(delay.round() as u64)
268 });
269
270 let config = aleph_bft::create_config(
271 self.num_peers().total().into(),
272 self.identity().to_usize().into(),
273 session_index,
274 self.cfg
275 .consensus
276 .broadcast_rounds_per_session
277 .checked_add(EXP_SLOWDOWN_ROUNDS)
278 .expect("Rounds per session exceed maximum of u16::Max - EXP_SLOWDOWN_ROUNDS"),
279 delay_config,
280 Duration::from_hours(87600),
281 )
282 .expect("The exponential slowdown exceeds 10 years");
283
284 let (unit_data_sender, unit_data_receiver) = async_channel::unbounded();
287 let (signature_sender, signature_receiver) = watch::channel(None);
288 let (timestamp_sender, timestamp_receiver) = async_channel::unbounded();
289 let (terminator_sender, terminator_receiver) = futures::channel::oneshot::channel();
290
291 let (signed_outcomes_sender, signed_outcomes_receiver) = async_channel::unbounded();
293 let (signatures_sender, signatures_receiver) = async_channel::unbounded();
294
295 let aleph_handle = spawn(
296 "aleph run session",
297 aleph_bft::run_session(
298 config,
299 aleph_bft::LocalIO::new(
300 DataProvider::new(
301 self.submission_receiver.clone(),
302 signature_receiver,
303 timestamp_sender,
304 self.is_recovery().await,
305 ),
306 FinalizationHandler::new(unit_data_sender),
307 BackupWriter::new(self.db.clone()).await,
308 BackupReader::new(self.db.clone()),
309 ),
310 Network::new(
311 connections.clone(),
312 signed_outcomes_sender,
313 signatures_sender,
314 self.db.clone(),
315 ),
316 Keychain::new(&self.cfg),
317 Spawner::new(self.task_group.make_subgroup()),
318 aleph_bft::Terminator::create_root(terminator_receiver, "Terminator"),
319 ),
320 );
321
322 self.ord_latency_sender.send_replace(None);
323
324 let signed_session_outcome = self
325 .complete_signed_session_outcome(
326 session_index,
327 unit_data_receiver,
328 signature_sender,
329 timestamp_receiver,
330 signed_outcomes_receiver,
331 signatures_receiver,
332 connections,
333 )
334 .await?;
335
336 assert!(
337 self.validate_signed_session_outcome(&signed_session_outcome, session_index),
338 "Our created signed session outcome fails validation"
339 );
340
341 info!(target: LOG_CONSENSUS, ?session_index, "Terminating Aleph BFT session");
342
343 terminator_sender.send(()).ok();
346 aleph_handle.await.ok();
347
348 self.complete_session(session_index, signed_session_outcome)
352 .await;
353
354 self.checkpoint_database(session_index);
355
356 Some(())
357 }
358
359 async fn is_recovery(&self) -> bool {
360 self.db
361 .begin_transaction_nc()
362 .await
363 .find_by_prefix(&AlephUnitsPrefix)
364 .await
365 .next()
366 .await
367 .is_some()
368 }
369
370 #[allow(clippy::too_many_arguments)]
371 pub async fn complete_signed_session_outcome(
372 &self,
373 session_index: u64,
374 ordered_unit_receiver: Receiver<OrderedUnit>,
375 signature_sender: watch::Sender<Option<schnorr::Signature>>,
376 timestamp_receiver: Receiver<Instant>,
377 signed_outcomes_receiver: Receiver<(PeerId, SignedSessionOutcome)>,
378 signatures_receiver: Receiver<(PeerId, schnorr::Signature)>,
379 _connections: DynP2PConnections<P2PMessage>,
380 ) -> Option<SignedSessionOutcome> {
381 let mut item_index = 0;
384
385 let mut index_broadcast_interval = tokio::time::interval(Duration::from_secs(3));
387
388 let mut request_signed_session_outcome = Box::pin(async {
389 self.request_signed_session_outcome(&self.federation_api, session_index)
390 .await
391 });
392
393 loop {
397 tokio::select! {
398 result = ordered_unit_receiver.recv() => {
399 let ordered_unit = result.ok()?;
400
401 if ordered_unit.round >= self.cfg.consensus.broadcast_rounds_per_session {
402 info!(
403 target: LOG_CONSENSUS,
404 session_index,
405 "Reached Aleph BFT round limit, stopping item collection"
406 );
407 break;
408 }
409
410 if let Some(UnitData::Batch(bytes)) = ordered_unit.data {
411 if ordered_unit.creator == self.identity() {
412 match timestamp_receiver.try_recv() {
413 Ok(timestamp) => {
414 let latency = match *self.ord_latency_sender.borrow() {
415 Some(latency) => (9 * latency + timestamp.elapsed()) / 10,
416 None => timestamp.elapsed()
417 };
418
419 self.ord_latency_sender.send_replace(Some(latency));
420
421 CONSENSUS_ORDERING_LATENCY_SECONDS.observe(timestamp.elapsed().as_secs_f64());
422 }
423 Err(err) => {
424 debug!(target: LOG_CONSENSUS, err = %err.fmt_compact(), "Missing submission timestamp. This is normal in recovery");
425 }
426 }
427 }
428
429 match Vec::<ConsensusItem>::consensus_decode_whole(&bytes, &self.decoders()) {
430 Ok(items) => {
431 for item in items {
432 if let Ok(()) = self.process_consensus_item(
433 session_index,
434 item_index,
435 item.clone(),
436 ordered_unit.creator
437 ).await {
438 item_index += 1;
439 }
440 }
441 }
442 Err(err) => {
443 error!(
444 target: LOG_CONSENSUS,
445 session_index,
446 peer = %ordered_unit.creator,
447 err = %err.fmt_compact(),
448 "Failed to decode consensus items from peer"
449 );
450 }
451 }
452 }
453 },
454 signed_session_outcome = &mut request_signed_session_outcome => {
456 info!(
457 target: LOG_CONSENSUS,
458 ?session_index,
459 "Recovered signed session outcome from peers while processing consensus items"
460 );
461
462 let pending_accepted_items = self.pending_accepted_items().await;
463
464 let (processed, unprocessed) = signed_session_outcome
466 .session_outcome
467 .items
468 .split_at(pending_accepted_items.len());
469
470 info!(
471 target: LOG_CONSENSUS,
472 session_index,
473 processed = %processed.len(),
474 unprocessed = %unprocessed.len(),
475 "Processing remaining items..."
476 );
477
478 assert!(
479 processed.iter().eq(pending_accepted_items.iter()),
480 "Consensus Failure: pending accepted items disagree with federation consensus"
481 );
482
483 for (accepted_item, item_index) in unprocessed.iter().zip(processed.len()..) {
484 if let Err(err) = self.process_consensus_item(
485 session_index,
486 item_index as u64,
487 accepted_item.item.clone(),
488 accepted_item.peer
489 ).await {
490 panic!(
491 "Consensus Failure: rejected item accepted by federation consensus: {accepted_item:?}, items: {}+{}, session_idx: {session_index}, item_idx: {item_index}, err: {err}",
492 processed.len(),
493 unprocessed.len(),
494 );
495 }
496 }
497
498 return Some(signed_session_outcome);
499 },
500 result = signed_outcomes_receiver.recv() => {
501 let (peer_id, p2p_outcome) = result.ok()?;
502
503 if self.validate_signed_session_outcome(&p2p_outcome, session_index) {
505 info!(
506 target: LOG_CONSENSUS,
507 session_index,
508 peer_id = %peer_id,
509 "Received SignedSessionOutcome via P2P while collection signatures"
510 );
511
512 let pending_accepted_items = self.pending_accepted_items().await;
513
514 let (processed, unprocessed) = p2p_outcome
516 .session_outcome
517 .items
518 .split_at(pending_accepted_items.len());
519
520 info!(
521 target: LOG_CONSENSUS,
522 ?session_index,
523 processed = %processed.len(),
524 unprocessed = %unprocessed.len(),
525 "Processing remaining items..."
526 );
527
528 assert!(
529 processed.iter().eq(pending_accepted_items.iter()),
530 "Consensus Failure: pending accepted items disagree with federation consensus"
531 );
532
533 for (accepted_item, item_index) in unprocessed.iter().zip(processed.len()..) {
534 if let Err(err) = self.process_consensus_item(
535 session_index,
536 item_index as u64,
537 accepted_item.item.clone(),
538 accepted_item.peer
539 ).await {
540 panic!(
541 "Consensus Failure: rejected item accepted by federation consensus: {accepted_item:?}, items: {}+{}, session_idx: {session_index}, item_idx: {item_index}, err: {err}",
542 processed.len(),
543 unprocessed.len(),
544 );
545 }
546 }
547
548 info!(
549 target: LOG_CONSENSUS,
550 ?session_index,
551 peer_id = %peer_id,
552 "Successfully recovered session via P2P"
553 );
554
555 return Some(p2p_outcome);
556 }
557
558 debug!(
559 target: LOG_CONSENSUS,
560 %peer_id,
561 "Invalid P2P SignedSessionOutcome"
562 );
563 }
564 _ = index_broadcast_interval.tick() => {
565 }
571 }
572 }
573
574 let items = self.pending_accepted_items().await;
575
576 assert_eq!(item_index, items.len() as u64);
577
578 info!(target: LOG_CONSENSUS, ?session_index, ?item_index, "Processed all items for session");
579
580 let session_outcome = SessionOutcome { items };
581
582 let header = session_outcome.header(session_index);
583
584 info!(
585 target: LOG_CONSENSUS,
586 ?session_index,
587 "Signing session header..."
588 );
589
590 let keychain = Keychain::new(&self.cfg);
591
592 let our_signature = keychain.sign_schnorr(&header);
593
594 #[allow(clippy::disallowed_methods)]
596 signature_sender.send(Some(our_signature)).ok()?;
597
598 let mut signatures = BTreeMap::from_iter([(self.identity(), our_signature)]);
599
600 let items_dump = tokio::sync::OnceCell::new();
601
602 let mut signature_broadcast_interval = tokio::time::interval(Duration::from_secs(1));
604
605 while signatures.len() < self.num_peers().threshold() {
608 tokio::select! {
609 result = ordered_unit_receiver.recv() => {
611 let ordered_unit = result.ok()?;
612
613 if let Some(UnitData::Signature(signature)) = ordered_unit.data {
614 info!(
615 target: LOG_CONSENSUS,
616 ?session_index,
617 peer = %ordered_unit.creator,
618 "Collected signature from peer via AlephBFT, verifying..."
619 );
620
621 if keychain.verify(&header, &signature, to_node_index(ordered_unit.creator)){
622 signatures.insert(ordered_unit.creator, schnorr::Signature::from_slice(&signature).expect("AlephBFT signature is valid"));
623 } else {
624 error!(
625 target: LOG_CONSENSUS,
626 ?session_index,
627 peer = %ordered_unit.creator,
628 "Consensus Failure: invalid header signature from peer"
629 );
630
631 items_dump.get_or_init(|| async {
632 for (idx, item) in session_outcome.items.iter().enumerate() {
633 info!(target: LOG_CONSENSUS, idx, item = %DebugConsensusItemCompact(item), "Item");
634 }
635 }).await;
636 }
637 }
638 }
639 result = signatures_receiver.recv() => {
640 let (peer_id, signature) = result.ok()?;
641
642 if keychain.verify_schnorr(&header, &signature, peer_id) {
643 signatures.insert(peer_id, signature);
644
645 info!(
646 target: LOG_CONSENSUS,
647 session_index,
648 peer_id = %peer_id,
649 "Collected signature from peer via P2P"
650 );
651 }
652
653 debug!(
654 target: LOG_CONSENSUS,
655 session_index,
656 peer_id = %peer_id,
657 "Invalid P2P signature from peer"
658 );
659 }
660 signed_session_outcome = &mut request_signed_session_outcome => {
662 info!(
663 target: LOG_CONSENSUS,
664 ?session_index,
665 "Recovered signed session outcome from peers while collecting signatures"
666 );
667
668 assert_eq!(
669 header,
670 signed_session_outcome.session_outcome.header(session_index),
671 "Consensus Failure: header disagrees with federation consensus"
672 );
673
674 return Some(signed_session_outcome);
675 },
676 result = signed_outcomes_receiver.recv() => {
677 let (peer_id, p2p_outcome) = result.ok()?;
678
679 if self.validate_signed_session_outcome(&p2p_outcome, session_index) {
680 assert_eq!(
681 header,
682 p2p_outcome.session_outcome.header(session_index),
683 "Consensus Failure: header disagrees with federation consensus"
684 );
685
686 info!(
687 target: LOG_CONSENSUS,
688 session_index,
689 %peer_id,
690 "Recovered session via P2P while collecting signatures"
691 );
692
693 return Some(p2p_outcome);
694 }
695
696 debug!(
697 target: LOG_CONSENSUS,
698 %peer_id,
699 "Invalid P2P SignedSessionOutcome"
700 );
701 }
702 _ = signature_broadcast_interval.tick() => {
703 }
709 _ = index_broadcast_interval.tick() => {
710 }
716 }
717 }
718
719 info!(
720 target: LOG_CONSENSUS,
721 session_index,
722 "Successfully collected threshold of signatures"
723 );
724
725 Some(SignedSessionOutcome {
726 session_outcome,
727 signatures,
728 })
729 }
730
731 #[allow(unused)]
733 fn random_peer(&self) -> PeerId {
734 self.num_peers()
735 .peer_ids()
736 .filter(|p| *p != self.identity())
737 .choose(&mut rand::thread_rng())
738 .expect("We have at least three peers")
739 }
740
741 fn validate_signed_session_outcome(
743 &self,
744 outcome: &SignedSessionOutcome,
745 session_index: u64,
746 ) -> bool {
747 if outcome.signatures.len() != self.num_peers().threshold() {
748 return false;
749 }
750
751 let keychain = Keychain::new(&self.cfg);
752 let header = outcome.session_outcome.header(session_index);
753
754 outcome
755 .signatures
756 .iter()
757 .all(|(signer_id, sig)| keychain.verify_schnorr(&header, sig, *signer_id))
758 }
759
760 fn decoders(&self) -> ModuleDecoderRegistry {
761 self.modules.decoder_registry()
762 }
763
764 pub async fn pending_accepted_items(&self) -> Vec<AcceptedItem> {
765 self.db
766 .begin_transaction_nc()
767 .await
768 .find_by_prefix(&AcceptedItemPrefix)
769 .await
770 .map(|entry| entry.1)
771 .collect()
772 .await
773 }
774
775 pub async fn complete_session(
776 &self,
777 session_index: u64,
778 signed_session_outcome: SignedSessionOutcome,
779 ) {
780 let mut dbtx = self.db.begin_transaction().await;
781
782 dbtx.remove_by_prefix(&AlephUnitsPrefix).await;
783
784 dbtx.remove_by_prefix(&AcceptedItemPrefix).await;
785
786 if dbtx
787 .insert_entry(
788 &SignedSessionOutcomeKey(session_index),
789 &signed_session_outcome,
790 )
791 .await
792 .is_some()
793 {
794 panic!("We tried to overwrite a signed session outcome");
795 }
796
797 dbtx.commit_tx_result()
798 .await
799 .expect("This is the only place where we write to this key");
800 }
801
802 fn db_checkpoints_dir(&self) -> PathBuf {
804 self.data_dir.join(DB_CHECKPOINTS_DIR)
805 }
806
807 fn initialize_checkpoint_directory(&self, current_session: u64) -> anyhow::Result<()> {
811 let checkpoint_dir = self.db_checkpoints_dir();
812
813 if checkpoint_dir.exists() {
814 debug!(
815 target: LOG_CONSENSUS,
816 ?current_session,
817 "Removing database checkpoints up to `current_session`"
818 );
819
820 for checkpoint in fs::read_dir(checkpoint_dir)?.flatten() {
821 if let Ok(file_name) = checkpoint.file_name().into_string()
823 && let Ok(session) = file_name.parse::<u64>()
824 && current_session >= self.db_checkpoint_retention
825 && session < current_session - self.db_checkpoint_retention
826 {
827 fs::remove_dir_all(checkpoint.path())?;
828 }
829 }
830 } else {
831 fs::create_dir_all(&checkpoint_dir)?;
832 }
833
834 Ok(())
835 }
836
837 fn checkpoint_database(&self, session_index: u64) {
841 if self.db_checkpoint_retention == 0 {
844 return;
845 }
846
847 let checkpoint_dir = self.db_checkpoints_dir();
848 let session_checkpoint_dir = checkpoint_dir.join(format!("{session_index}"));
849
850 {
851 let _timing = timing::TimeReporter::new("database-checkpoint").level(Level::TRACE);
852 match self.db.checkpoint(&session_checkpoint_dir) {
853 Ok(()) => {
854 debug!(target: LOG_CONSENSUS, ?session_checkpoint_dir, ?session_index, "Created db checkpoint");
855 }
856 Err(err) => {
857 warn!(target: LOG_CONSENSUS, ?session_checkpoint_dir, ?session_index, err = %err.fmt_compact(), "Could not create db checkpoint");
858 }
859 }
860 }
861
862 {
863 let _timing = timing::TimeReporter::new("remove-database-checkpoint").level(Level::TRACE);
865 if let Err(err) = self.delete_old_database_checkpoint(session_index, &checkpoint_dir) {
866 warn!(target: LOG_CONSENSUS, err = %err.fmt_compact_anyhow(), "Could not delete old checkpoints");
867 }
868 }
869 }
870
871 fn delete_old_database_checkpoint(
874 &self,
875 session_index: u64,
876 checkpoint_dir: &Path,
877 ) -> anyhow::Result<()> {
878 if self.db_checkpoint_retention > session_index {
879 return Ok(());
880 }
881
882 let delete_session_index = session_index - self.db_checkpoint_retention;
883 let checkpoint_to_delete = checkpoint_dir.join(delete_session_index.to_string());
884 if checkpoint_to_delete.exists() {
885 fs::remove_dir_all(checkpoint_to_delete)?;
886 }
887
888 Ok(())
889 }
890
891 #[instrument(target = LOG_CONSENSUS, skip(self, item), level = "info")]
892 pub async fn process_consensus_item(
893 &self,
894 session_index: u64,
895 item_index: u64,
896 item: ConsensusItem,
897 peer: PeerId,
898 ) -> anyhow::Result<()> {
899 let _timing = timing::TimeReporter::new("process_consensus_item").level(Level::TRACE);
900
901 let timing_prom = CONSENSUS_ITEM_PROCESSING_DURATION_SECONDS
902 .with_label_values(&[&peer.to_usize().to_string()])
903 .start_timer();
904
905 trace!(
906 target: LOG_CONSENSUS,
907 %peer,
908 item = ?DebugConsensusItem(&item),
909 "Processing consensus item"
910 );
911
912 self.ci_status_senders
913 .get(&peer)
914 .expect("No ci status sender for peer")
915 .send_replace(Some(session_index));
916
917 CONSENSUS_PEER_CONTRIBUTION_SESSION_IDX
918 .with_label_values(&[
919 &self.cfg.local.identity.to_usize().to_string(),
920 &peer.to_usize().to_string(),
921 ])
922 .set(session_index as i64);
923
924 let mut attempt: usize = 1;
925
926 let outcome = loop {
927 match self
928 .process_consensus_item_attempt(item_index, &item, peer)
929 .await
930 {
931 Ok(outcome) => break outcome,
932 Err(err) => {
933 assert!(
939 matches!(err, DatabaseError::SnapshotTooOld(_)),
940 "Committing consensus item failed: {err}"
941 );
942
943 assert!(
944 attempt < MAX_ITEM_PROCESSING_ATTEMPTS,
945 "Committing consensus item failed after {attempt} attempts: {err}"
946 );
947
948 warn!(
949 target: LOG_CONSENSUS,
950 %peer,
951 item_index,
952 attempt,
953 err = %err.fmt_compact(),
954 "Consensus item transaction could not be validated - reprocessing item"
955 );
956
957 attempt += 1;
958 }
959 }
960 };
961
962 outcome?;
963
964 timing_prom.observe_duration();
965
966 Ok(())
967 }
968
969 async fn process_consensus_item_attempt(
975 &self,
976 item_index: u64,
977 item: &ConsensusItem,
978 peer: PeerId,
979 ) -> DatabaseResult<anyhow::Result<()>> {
980 let mut dbtx = self.db.begin_transaction().await;
981
982 dbtx.ignore_uncommitted();
983
984 if let Some(existing_item) = dbtx.get_value(&AcceptedItemKey(item_index)).await {
988 if existing_item.item == *item && existing_item.peer == peer {
989 return Ok(Ok(()));
990 }
991
992 return Ok(Err(anyhow!(
993 "Item was discarded previously: existing: {existing_item:?} {}, current: {item:?}, {peer}",
994 existing_item.peer
995 )));
996 }
997
998 if let Err(err) = self
999 .process_consensus_item_with_db_transaction(&mut dbtx.to_ref_nc(), item.clone(), peer)
1000 .await
1001 {
1002 trace!(
1004 target: LOG_CONSENSUS,
1005 %peer,
1006 item = ?DebugConsensusItem(item),
1007 err = %err.fmt_compact_anyhow(),
1008 "Rejected consensus item"
1009 );
1010
1011 return Ok(Err(err));
1012 }
1013
1014 dbtx.warn_uncommitted();
1017
1018 dbtx.insert_entry(
1019 &AcceptedItemKey(item_index),
1020 &AcceptedItem {
1021 item: item.clone(),
1022 peer,
1023 },
1024 )
1025 .await;
1026
1027 debug!(
1028 target: LOG_CONSENSUS,
1029 %peer,
1030 item = ?DebugConsensusItem(item),
1031 "Processed consensus item"
1032 );
1033 let mut audit = Audit::default();
1034
1035 for (module_instance_id, kind, module) in self.modules.iter_modules() {
1036 let _module_audit_timing =
1037 TimeReporter::new(format!("audit module {module_instance_id}")).level(Level::TRACE);
1038
1039 let timing_prom = CONSENSUS_ITEM_PROCESSING_MODULE_AUDIT_DURATION_SECONDS
1040 .with_label_values(&[
1041 MODULE_INSTANCE_ID_GLOBAL.to_string().as_str(),
1042 kind.as_str(),
1043 ])
1044 .start_timer();
1045
1046 module
1047 .audit(
1048 &mut dbtx
1049 .to_ref_with_prefix_module_id(module_instance_id)
1050 .0
1051 .into_nc(),
1052 &mut audit,
1053 module_instance_id,
1054 )
1055 .await;
1056
1057 timing_prom.observe_duration();
1058 }
1059
1060 assert!(
1061 audit
1062 .net_assets()
1063 .expect("Overflow while checking balance sheet")
1064 .milli_sat
1065 >= 0,
1066 "Balance sheet of the fed has gone negative, this should never happen! {audit}"
1067 );
1068
1069 dbtx.commit_tx_result().await?;
1070
1071 CONSENSUS_ITEMS_PROCESSED_TOTAL
1075 .with_label_values(&[&peer.to_usize().to_string()])
1076 .inc();
1077
1078 Ok(Ok(()))
1079 }
1080
1081 async fn process_consensus_item_with_db_transaction(
1082 &self,
1083 dbtx: &mut DatabaseTransaction<'_>,
1084 consensus_item: ConsensusItem,
1085 peer_id: PeerId,
1086 ) -> anyhow::Result<()> {
1087 self.decoders().assert_reject_mode();
1090
1091 match consensus_item {
1092 ConsensusItem::Module(module_item) => {
1093 let instance_id = module_item.module_instance_id();
1094
1095 let module_dbtx = &mut dbtx.to_ref_with_prefix_module_id(instance_id).0;
1096
1097 self.modules
1098 .get_expect(instance_id)
1099 .process_consensus_item(module_dbtx, &module_item, peer_id)
1100 .await
1101 }
1102 ConsensusItem::Transaction(transaction) => {
1103 let txid = transaction.tx_hash();
1104 if dbtx
1105 .get_value(&AcceptedTransactionKey(txid))
1106 .await
1107 .is_some()
1108 {
1109 debug!(
1110 target: LOG_CONSENSUS,
1111 %txid,
1112 "Transaction already accepted"
1113 );
1114 bail!("Transaction is already accepted");
1115 }
1116
1117 let modules_ids = transaction
1118 .outputs
1119 .iter()
1120 .map(DynOutput::module_instance_id)
1121 .collect::<Vec<_>>();
1122
1123 process_transaction_with_dbtx(
1124 self.modules.clone(),
1125 dbtx,
1126 &transaction,
1127 self.cfg.consensus.version,
1128 TxProcessingMode::Consensus,
1129 )
1130 .await
1131 .map_err(|error| anyhow!(error.to_string()))?;
1132
1133 debug!(target: LOG_CONSENSUS, %txid, "Transaction accepted");
1134 dbtx.insert_entry(&AcceptedTransactionKey(txid), &modules_ids)
1135 .await;
1136
1137 Ok(())
1138 }
1139 ConsensusItem::Default { variant, .. } => {
1140 warn!(
1145 target: LOG_CONSENSUS,
1146 "Minor consensus version mismatch: unexpected consensus item type: {variant}"
1147 );
1148
1149 bail!("Unexpected consensus item type: {variant}")
1150 }
1151 }
1152 }
1153
1154 async fn request_signed_session_outcome(
1155 &self,
1156 federation_api: &DynGlobalApi,
1157 index: u64,
1158 ) -> SignedSessionOutcome {
1159 let decoders = self.decoders();
1160 let keychain = Keychain::new(&self.cfg);
1161 let threshold = self.num_peers().threshold();
1162
1163 let filter_map = move |response: SerdeModuleEncoding<SignedSessionOutcome>| {
1164 let signed_session_outcome = response
1165 .try_into_inner(&decoders)
1166 .map_err(|x| ServerError::ResponseDeserialization(Box::new(x)))?;
1167 let header = signed_session_outcome.session_outcome.header(index);
1168 if signed_session_outcome.signatures.len() == threshold
1169 && signed_session_outcome
1170 .signatures
1171 .iter()
1172 .all(|(peer_id, sig)| keychain.verify_schnorr(&header, sig, *peer_id))
1173 {
1174 Ok(signed_session_outcome)
1175 } else {
1176 Err(ServerError::InvalidResponse(
1177 "Invalid signatures".to_string(),
1178 ))
1179 }
1180 };
1181
1182 federation_api
1183 .request_with_strategy_retry(
1184 FilterMap::new(filter_map.clone()),
1185 AWAIT_SIGNED_SESSION_OUTCOME_ENDPOINT.to_string(),
1186 ApiRequestErased::new(index),
1187 )
1188 .await
1189 }
1190
1191 async fn get_finished_session_count(&self) -> u64 {
1194 get_finished_session_count_static(&mut self.db.begin_transaction_nc().await).await
1195 }
1196}
1197
1198pub async fn get_finished_session_count_static(dbtx: &mut DatabaseTransaction<'_>) -> u64 {
1199 dbtx.find_by_prefix_sorted_descending(&SignedSessionOutcomePrefix)
1200 .await
1201 .next()
1202 .await
1203 .map_or(0, |entry| (entry.0.0) + 1)
1204}