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