Skip to main content

fedimint_server/consensus/
engine.rs

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
61// The name of the directory where the database checkpoints are stored.
62const DB_CHECKPOINTS_DIR: &str = "db_checkpoints";
63
64/// How many times a single ordered consensus item is processed before we give
65/// up. Only a database transaction that could not be validated at commit time
66/// costs an attempt, and reprocessing takes a fresh snapshot, so needing more
67/// than a couple of these means something is wrong beyond a stale snapshot.
68const MAX_ITEM_PROCESSING_ATTEMPTS: usize = 10;
69
70/// Runs the main server consensus loop
71pub 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                // we rely on the module consensus items to notice the timeout
130                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        // We need four peers to run the atomic broadcast
168        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            // If a session gets stuck for an extended period of time we exit
187            // the process such that our supervisor restarts fedimintd, which
188            // has been observed to resolve stuck sessions. Since AlephBFT
189            // persists its units to the database this is equivalent to a crash
190            // and therefore safe.
191            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        // In order to bound a sessions RAM consumption we need to bound its number of
224        // units and therefore its number of rounds. Since we use a session to
225        // create a naive secp256k1 threshold signature for the header of session
226        // outcome we have to guarantee that an attacker cannot exhaust our
227        // memory by preventing the creation of a threshold signature, thereby
228        // keeping the session open indefinitely. Hence, after a certain round
229        // index, we increase the delay between rounds exponentially such that
230        // the end of the aleph bft session would only be reached after a minimum
231        // of 10 years. In case of such an attack the broadcast stops ordering any
232        // items until the attack subsides as no items are ordered while the
233        // signatures are collected. The maximum RAM consumption of the aleph bft
234        // broadcast instance is therefore bound by:
235        //
236        // self.keychain.peer_count()
237        //      * (broadcast_rounds_per_session + EXP_SLOWDOWN_ROUNDS)
238        //      * ALEPH_BFT_UNIT_BYTE_LIMIT
239
240        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            // In a test environment all peers are started in lockstep, so we
250            // add jitter to the unit creation delay to break it; in production
251            // the peers' timing drifts naturally.
252            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        // we can use an unbounded channel here since the number and size of units
284        // ordered in a single aleph session is bounded as described above
285        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        // Create channels for P2P session sync
291        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        // We can terminate the session instead of waiting for other peers to complete
343        // it since they can always download the signed session outcome from us
344        terminator_sender.send(()).ok();
345        aleph_handle.await.ok();
346
347        // This method removes the backup of the current session from the database
348        // and therefore has to be called after we have waited for the session to
349        // shut down, or we risk write-write conflicts with the UnitSaver
350        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        // It is guaranteed that aleph bft will always replay all previously processed
381        // items from the current session from index zero
382        let mut item_index = 0;
383
384        // We request the signed session outcome every three seconds from a random peer
385        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        // We build a session outcome out of the ordered batches until either we have
393        // processed broadcast_rounds_per_session rounds or a threshold signed
394        // session outcome is obtained from our peers
395        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                // TODO: remove this branch in 0.11.0
454                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                    // this panics if we have more accepted items than the signed session outcome
464                    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                    // Validate signatures
503                    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                        // this panics if we have more accepted items than the signed session outcome
514                        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                    // TODO: start sending the new messages in 0.11.0
565                    // connections.send(
566                    //     Recipient::Peer(self.random_peer()),
567                    //     P2PMessage::SessionIndex(session_index),
568                    // );
569                }
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        // Send our own signature to the data provider to be submitted to AlephBFT
594        #[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        // We request the session signature every second to all peers
602        let mut signature_broadcast_interval = tokio::time::interval(Duration::from_secs(1));
603
604        // We collect the ordered signatures until we either obtain a threshold
605        // signature or a signed session outcome arrives from our peers
606        while signatures.len() < self.num_peers().threshold() {
607            tokio::select! {
608                // TODO: remove this branch in 0.11.0
609                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                // TODO: remove this branch in 0.11.0
660                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                    // TODO: start sending the new messages in 0.11.0
703                    // connections.send(
704                    //     Recipient::Everyone,
705                    //     P2PMessage::SessionSignature(our_signature),
706                    // );
707                }
708                _ = index_broadcast_interval.tick() => {
709                    // TODO: start sending the new messages in 0.11.0
710                    // connections.send(
711                    //     Recipient::Peer(self.random_peer()),
712                    //     P2PMessage::SessionIndex(session_index),
713                    // );
714                }
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    /// Returns a random peer ID excluding ourselves
731    #[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    /// Validate a SignedSessionOutcome received via P2P
741    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    /// Returns the full path where the database checkpoints are stored.
802    fn db_checkpoints_dir(&self) -> PathBuf {
803        self.data_dir.join(DB_CHECKPOINTS_DIR)
804    }
805
806    /// Creates the directory within the data directory for storing the database
807    /// checkpoints or deletes checkpoints before `current_session` -
808    /// `checkpoint_retention`.
809    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                // Validate that the directory is a session index
821                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    /// Creates a backup of the database in the checkpoint directory. These
837    /// checkpoints can be used to restore the database in case the
838    /// federation falls out of consensus (recommended for experts only).
839    fn checkpoint_database(&self, session_index: u64) {
840        // If `checkpoint_retention` has been turned off, don't checkpoint the database
841        // at all.
842        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 /* logs on drop */ = 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            // Check if any old checkpoint need to be cleaned up
863            let _timing /* logs on drop */ = 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    /// Deletes the database checkpoint directory equal to `session_index` -
871    /// `checkpoint_retention`
872    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 /* logs on drop */ = 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                    // A snapshot that aged out of the backend's write history is the only
933                    // commit failure we can do anything about, and the only way to recover
934                    // is to rerun the whole operation against a fresh transaction. Nothing
935                    // was written, and reprocessing an ordered item is deterministic, so
936                    // the replay is equivalent to having processed it a moment later.
937                    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    /// Process a single ordered consensus item in one database transaction.
969    ///
970    /// The outer `Err` means the transaction could not be committed and the
971    /// caller has to rerun the whole operation in a fresh one. The inner `Err`
972    /// means the item itself was rejected, which is a normal, final outcome.
973    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        // When we recover from a mid-session crash aleph bft will replay the units that
984        // were already processed before the crash. We therefore skip all consensus
985        // items until we have seen every previously accepted items again.
986        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            // Rejected items are very common, so only trace level
1002            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        // After this point we have to commit the database transaction since the
1014        // item has been fully processed without errors
1015        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        // Counted here rather than in the caller so that only an attempt that actually
1071        // committed is counted: the replay and rejection paths above return early, and
1072        // a failed attempt loops back around to a fresh transaction.
1073        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        // We rely on decoding rejecting any unknown module instance ids to avoid
1087        // peer-triggered panic here
1088        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                // `ConsensusItem` has an `#[encodable_default]` variant, so an unknown
1140                // discriminant decodes successfully instead of erroring. The variant byte
1141                // is attacker-controlled: a malicious peer can put an arbitrary batch into
1142                // its unit, so this must be rejected rather than treated as unreachable.
1143                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    /// Returns the number of sessions already saved in the database. This count
1189    /// **does not** include the currently running session.
1190    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}