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