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 _;
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::peer_availability::PeerActivity;
55use crate::consensus::transaction::{TxProcessingMode, process_transaction_with_dbtx};
56use crate::metrics::{
57    CONSENSUS_ITEM_PROCESSING_DURATION_SECONDS,
58    CONSENSUS_ITEM_PROCESSING_MODULE_AUDIT_DURATION_SECONDS, CONSENSUS_ITEMS_PROCESSED_TOTAL,
59    CONSENSUS_ORDERING_LATENCY_SECONDS, CONSENSUS_PEER_CONTRIBUTION_SESSION_IDX,
60    CONSENSUS_SESSION_COUNT,
61};
62
63// The name of the directory where the database checkpoints are stored.
64const DB_CHECKPOINTS_DIR: &str = "db_checkpoints";
65
66/// How many times a single ordered consensus item is processed before we give
67/// up. Only a database transaction that could not be validated at commit time
68/// costs an attempt, and reprocessing takes a fresh snapshot, so needing more
69/// than a couple of these means something is wrong beyond a stale snapshot.
70const MAX_ITEM_PROCESSING_ATTEMPTS: usize = 10;
71
72/// Runs the main server consensus loop
73pub struct ConsensusEngine {
74    pub modules: ServerModuleRegistry,
75    pub db: Database,
76    pub federation_api: DynGlobalApi,
77    pub cfg: ServerConfig,
78    pub submission_receiver: Receiver<ConsensusItem>,
79    pub shutdown_receiver: watch::Receiver<Option<u64>>,
80    pub connections: DynP2PConnections<P2PMessage>,
81    pub ci_status_senders: BTreeMap<PeerId, watch::Sender<Option<u64>>>,
82    pub ord_latency_sender: watch::Sender<Option<Duration>>,
83    /// Notified whenever consensus accepts an item.
84    pub accepted_item_sender: watch::Sender<()>,
85    /// Notified whenever consensus completes a session.
86    pub completed_session_sender: watch::Sender<()>,
87    pub task_group: TaskGroup,
88    pub data_dir: PathBuf,
89    pub db_checkpoint_retention: u64,
90    pub session_timeout: Duration,
91    pub peer_activity: Arc<std::sync::Mutex<PeerActivity>>,
92}
93
94impl ConsensusEngine {
95    fn num_peers(&self) -> NumPeers {
96        self.cfg.consensus.broadcast_public_keys.to_num_peers()
97    }
98
99    fn identity(&self) -> PeerId {
100        self.cfg.local.identity
101    }
102
103    #[instrument(target = LOG_CONSENSUS, name = "run", skip_all, fields(id=%self.cfg.local.identity))]
104    pub async fn run(self) -> anyhow::Result<()> {
105        if self.num_peers().total() == 1 {
106            self.run_single_guardian(self.task_group.make_handle())
107                .await
108        } else {
109            self.run_consensus(self.task_group.make_handle()).await
110        }
111    }
112
113    pub async fn run_single_guardian(&self, task_handle: TaskHandle) -> anyhow::Result<()> {
114        assert_eq!(self.num_peers(), NumPeers::from(1));
115
116        self.initialize_checkpoint_directory(self.get_finished_session_count().await)?;
117
118        while !task_handle.is_shutting_down() {
119            let session_index = self.get_finished_session_count().await;
120
121            CONSENSUS_SESSION_COUNT.set(session_index as i64);
122
123            let mut item_index = self.pending_accepted_items().await.len() as u64;
124
125            let session_start_time = std::time::Instant::now();
126
127            while let Ok(item) = self.submission_receiver.recv().await {
128                if self
129                    .process_consensus_item(session_index, item_index, item, self.identity())
130                    .await
131                    .is_ok()
132                {
133                    item_index += 1;
134                }
135
136                // we rely on the module consensus items to notice the timeout
137                if session_start_time.elapsed() > Duration::from_mins(1) {
138                    break;
139                }
140            }
141
142            let session_outcome = SessionOutcome {
143                items: self.pending_accepted_items().await,
144            };
145
146            let header = session_outcome.header(session_index);
147            let signature = Keychain::new(&self.cfg).sign_schnorr(&header);
148            let signatures = BTreeMap::from_iter([(self.identity(), signature)]);
149
150            self.complete_session(
151                session_index,
152                SignedSessionOutcome {
153                    session_outcome,
154                    signatures,
155                },
156            )
157            .await;
158
159            self.checkpoint_database(session_index);
160
161            info!(target: LOG_CONSENSUS, "Session {session_index} completed");
162
163            if Some(session_index) == self.shutdown_receiver.borrow().to_owned() {
164                break;
165            }
166        }
167
168        info!(target: LOG_CONSENSUS, "Consensus task shut down");
169
170        Ok(())
171    }
172
173    pub async fn run_consensus(&self, task_handle: TaskHandle) -> anyhow::Result<()> {
174        // We need four peers to run the atomic broadcast
175        assert!(self.num_peers().total() >= 4);
176
177        self.initialize_checkpoint_directory(self.get_finished_session_count().await)?;
178
179        while !task_handle.is_shutting_down() {
180            let session_index = self.get_finished_session_count().await;
181
182            CONSENSUS_SESSION_COUNT.set(session_index as i64);
183
184            let is_recovery = self.is_recovery().await;
185
186            info!(
187                target: LOG_CONSENSUS,
188                session_index,
189                is_recovery,
190                "Starting consensus session"
191            );
192
193            // If a session gets stuck for an extended period of time we exit
194            // the process such that our supervisor restarts fedimintd, which
195            // has been observed to resolve stuck sessions. Since AlephBFT
196            // persists its units to the database this is equivalent to a crash
197            // and therefore safe.
198            let session = tokio::time::timeout(
199                self.session_timeout,
200                self.run_session(self.connections.clone(), session_index),
201            )
202            .await
203            .context("Consensus session timed out, exiting...")?;
204
205            if session.is_none() {
206                return Ok(());
207            }
208
209            info!(target: LOG_CONSENSUS, ?session_index, "Completed consensus session");
210
211            if Some(session_index) == self.shutdown_receiver.borrow().to_owned() {
212                info!(target: LOG_CONSENSUS, "Initiating shutdown, waiting for peers to complete the session...");
213
214                sleep(Duration::from_mins(1)).await;
215
216                break;
217            }
218        }
219
220        info!(target: LOG_CONSENSUS, "Consensus task shut down");
221
222        Ok(())
223    }
224
225    pub async fn run_session(
226        &self,
227        connections: DynP2PConnections<P2PMessage>,
228        session_index: u64,
229    ) -> Option<()> {
230        // In order to bound a sessions RAM consumption we need to bound its number of
231        // units and therefore its number of rounds. Since we use a session to
232        // create a naive secp256k1 threshold signature for the header of session
233        // outcome we have to guarantee that an attacker cannot exhaust our
234        // memory by preventing the creation of a threshold signature, thereby
235        // keeping the session open indefinitely. Hence, after a certain round
236        // index, we increase the delay between rounds exponentially such that
237        // the end of the aleph bft session would only be reached after a minimum
238        // of 10 years. In case of such an attack the broadcast stops ordering any
239        // items until the attack subsides as no items are ordered while the
240        // signatures are collected. The maximum RAM consumption of the aleph bft
241        // broadcast instance is therefore bound by:
242        //
243        // self.keychain.peer_count()
244        //      * (broadcast_rounds_per_session + EXP_SLOWDOWN_ROUNDS)
245        //      * ALEPH_BFT_UNIT_BYTE_LIMIT
246
247        const EXP_SLOWDOWN_ROUNDS: u16 = 1000;
248        const BASE: f64 = 1.02;
249
250        let rounds_per_session = self.cfg.consensus.broadcast_rounds_per_session;
251        let round_delay = f64::from(self.cfg.local.broadcast_round_delay_ms);
252
253        let mut delay_config = aleph_bft::default_delay_config();
254
255        delay_config.unit_creation_delay = Arc::new(move |round_index| {
256            // In a test environment all peers are started in lockstep, so we
257            // add jitter to the unit creation delay to break it; in production
258            // the peers' timing drifts naturally.
259            let jitter = if is_running_in_test_env() {
260                rand::thread_rng().gen_range(0.5..=1.5)
261            } else {
262                1.0
263            };
264
265            let delay = if round_index == 0 {
266                0.0
267            } else {
268                round_delay
269                    * BASE.powf(round_index.saturating_sub(rounds_per_session as usize) as f64)
270                    * jitter
271            };
272
273            Duration::from_millis(delay.round() as u64)
274        });
275
276        let config = aleph_bft::create_config(
277            self.num_peers().total().into(),
278            self.identity().to_usize().into(),
279            session_index,
280            self.cfg
281                .consensus
282                .broadcast_rounds_per_session
283                .checked_add(EXP_SLOWDOWN_ROUNDS)
284                .expect("Rounds per session exceed maximum of u16::Max - EXP_SLOWDOWN_ROUNDS"),
285            delay_config,
286            Duration::from_hours(87600),
287        )
288        .expect("The exponential slowdown exceeds 10 years");
289
290        // we can use an unbounded channel here since the number and size of units
291        // ordered in a single aleph session is bounded as described above
292        let (unit_data_sender, unit_data_receiver) = async_channel::unbounded();
293        let (signature_sender, signature_receiver) = watch::channel(None);
294        let (timestamp_sender, timestamp_receiver) = async_channel::unbounded();
295        let (terminator_sender, terminator_receiver) = futures::channel::oneshot::channel();
296
297        // Create channels for P2P session sync
298        let (signed_outcomes_sender, signed_outcomes_receiver) = async_channel::unbounded();
299        let (signatures_sender, signatures_receiver) = async_channel::unbounded();
300
301        let aleph_handle = spawn(
302            "aleph run session",
303            aleph_bft::run_session(
304                config,
305                aleph_bft::LocalIO::new(
306                    DataProvider::new(
307                        self.submission_receiver.clone(),
308                        signature_receiver,
309                        timestamp_sender,
310                        self.is_recovery().await,
311                    ),
312                    FinalizationHandler::new(unit_data_sender),
313                    BackupWriter::new(self.db.clone()).await,
314                    BackupReader::new(self.db.clone()),
315                ),
316                Network::new(
317                    connections.clone(),
318                    self.peer_activity.clone(),
319                    signed_outcomes_sender,
320                    signatures_sender,
321                    self.db.clone(),
322                ),
323                Keychain::new(&self.cfg),
324                Spawner::new(self.task_group.make_subgroup()),
325                aleph_bft::Terminator::create_root(terminator_receiver, "Terminator"),
326            ),
327        );
328
329        self.ord_latency_sender.send_replace(None);
330
331        let signed_session_outcome = self
332            .complete_signed_session_outcome(
333                session_index,
334                unit_data_receiver,
335                signature_sender,
336                timestamp_receiver,
337                signed_outcomes_receiver,
338                signatures_receiver,
339                connections,
340            )
341            .await?;
342
343        assert!(
344            self.validate_signed_session_outcome(&signed_session_outcome, session_index),
345            "Our created signed session outcome fails validation"
346        );
347
348        info!(target: LOG_CONSENSUS, ?session_index, "Terminating Aleph BFT session");
349
350        // We can terminate the session instead of waiting for other peers to complete
351        // it since they can always download the signed session outcome from us
352        terminator_sender.send(()).ok();
353        aleph_handle.await.ok();
354
355        // This method removes the backup of the current session from the database
356        // and therefore has to be called after we have waited for the session to
357        // shut down, or we risk write-write conflicts with the UnitSaver
358        self.complete_session(session_index, signed_session_outcome)
359            .await;
360
361        self.checkpoint_database(session_index);
362
363        Some(())
364    }
365
366    async fn is_recovery(&self) -> bool {
367        self.db
368            .begin_transaction_nc()
369            .await
370            .find_by_prefix(&AlephUnitsPrefix)
371            .await
372            .next()
373            .await
374            .is_some()
375    }
376
377    #[allow(clippy::too_many_arguments)]
378    pub async fn complete_signed_session_outcome(
379        &self,
380        session_index: u64,
381        ordered_unit_receiver: Receiver<OrderedUnit>,
382        signature_sender: watch::Sender<Option<schnorr::Signature>>,
383        timestamp_receiver: Receiver<Instant>,
384        signed_outcomes_receiver: Receiver<(PeerId, SignedSessionOutcome)>,
385        signatures_receiver: Receiver<(PeerId, schnorr::Signature)>,
386        _connections: DynP2PConnections<P2PMessage>,
387    ) -> Option<SignedSessionOutcome> {
388        // It is guaranteed that aleph bft will always replay all previously processed
389        // items from the current session from index zero
390        let mut item_index = 0;
391
392        // We request the signed session outcome every three seconds from a random peer
393        let mut index_broadcast_interval = tokio::time::interval(Duration::from_secs(3));
394
395        let mut request_signed_session_outcome = Box::pin(async {
396            self.request_signed_session_outcome(&self.federation_api, session_index)
397                .await
398        });
399
400        // We build a session outcome out of the ordered batches until either we have
401        // processed broadcast_rounds_per_session rounds or a threshold signed
402        // session outcome is obtained from our peers
403        loop {
404            tokio::select! {
405                result = ordered_unit_receiver.recv() => {
406                    let ordered_unit = result.ok()?;
407
408                    if ordered_unit.round >= self.cfg.consensus.broadcast_rounds_per_session {
409                        info!(
410                            target: LOG_CONSENSUS,
411                            session_index,
412                            "Reached Aleph BFT round limit, stopping item collection"
413                        );
414                        break;
415                    }
416
417                    if let Some(UnitData::Batch(bytes)) = ordered_unit.data {
418                        if ordered_unit.creator == self.identity() {
419                            match timestamp_receiver.try_recv() {
420                                Ok(timestamp) => {
421                                    let latency = match *self.ord_latency_sender.borrow() {
422                                        Some(latency) => (9 * latency +  timestamp.elapsed()) / 10,
423                                        None => timestamp.elapsed()
424                                    };
425
426                                    self.ord_latency_sender.send_replace(Some(latency));
427
428                                    CONSENSUS_ORDERING_LATENCY_SECONDS.observe(timestamp.elapsed().as_secs_f64());
429                                }
430                                Err(err) => {
431                                    debug!(target: LOG_CONSENSUS, err = %err.fmt_compact(), "Missing submission timestamp. This is normal in recovery");
432                                }
433                            }
434                        }
435
436                        match Vec::<ConsensusItem>::consensus_decode_whole(&bytes, &self.decoders()) {
437                            Ok(items) => {
438                                for item in items {
439                                    if let Ok(()) = self.process_consensus_item(
440                                        session_index,
441                                        item_index,
442                                        item.clone(),
443                                        ordered_unit.creator
444                                    ).await {
445                                        item_index += 1;
446                                    }
447                                }
448                            }
449                            Err(err) => {
450                                error!(
451                                    target: LOG_CONSENSUS,
452                                    session_index,
453                                    peer = %ordered_unit.creator,
454                                    err = %err.fmt_compact(),
455                                    "Failed to decode consensus items from peer"
456                                );
457                            }
458                        }
459                    }
460                },
461                // TODO: remove this branch in 0.11.0
462                signed_session_outcome = &mut request_signed_session_outcome => {
463                    info!(
464                        target: LOG_CONSENSUS,
465                        ?session_index,
466                        "Recovered signed session outcome from peers while processing consensus items"
467                    );
468
469                    let pending_accepted_items = self.pending_accepted_items().await;
470
471                    // this panics if we have more accepted items than the signed session outcome
472                    let (processed, unprocessed) = signed_session_outcome
473                        .session_outcome
474                        .items
475                        .split_at(pending_accepted_items.len());
476
477                    info!(
478                        target: LOG_CONSENSUS,
479                        session_index,
480                        processed = %processed.len(),
481                        unprocessed = %unprocessed.len(),
482                        "Processing remaining items..."
483                    );
484
485                    assert!(
486                        processed.iter().eq(pending_accepted_items.iter()),
487                        "Consensus Failure: pending accepted items disagree with federation consensus"
488                    );
489
490                    for (accepted_item, item_index) in unprocessed.iter().zip(processed.len()..) {
491                        if let Err(err) = self.process_consensus_item(
492                            session_index,
493                            item_index as u64,
494                            accepted_item.item.clone(),
495                            accepted_item.peer
496                        ).await {
497                            panic!(
498                                "Consensus Failure: rejected item accepted by federation consensus: {accepted_item:?}, items: {}+{}, session_idx: {session_index}, item_idx: {item_index}, err: {err}",
499                                processed.len(),
500                                unprocessed.len(),
501                            );
502                        }
503                    }
504
505                    return Some(signed_session_outcome);
506                },
507                result = signed_outcomes_receiver.recv() => {
508                    let (peer_id, p2p_outcome) = result.ok()?;
509
510                    // Validate signatures
511                    if self.validate_signed_session_outcome(&p2p_outcome, session_index) {
512                        info!(
513                            target: LOG_CONSENSUS,
514                            session_index,
515                            peer_id = %peer_id,
516                            "Received SignedSessionOutcome via P2P while collection signatures"
517                        );
518
519                        let pending_accepted_items = self.pending_accepted_items().await;
520
521                        // this panics if we have more accepted items than the signed session outcome
522                        let (processed, unprocessed) = p2p_outcome
523                            .session_outcome
524                            .items
525                            .split_at(pending_accepted_items.len());
526
527                        info!(
528                            target: LOG_CONSENSUS,
529                            ?session_index,
530                            processed = %processed.len(),
531                            unprocessed = %unprocessed.len(),
532                            "Processing remaining items..."
533                        );
534
535                        assert!(
536                            processed.iter().eq(pending_accepted_items.iter()),
537                            "Consensus Failure: pending accepted items disagree with federation consensus"
538                        );
539
540                        for (accepted_item, item_index) in unprocessed.iter().zip(processed.len()..) {
541                            if let Err(err) = self.process_consensus_item(
542                                session_index,
543                                item_index as u64,
544                                accepted_item.item.clone(),
545                                accepted_item.peer
546                            ).await {
547                                panic!(
548                                    "Consensus Failure: rejected item accepted by federation consensus: {accepted_item:?}, items: {}+{}, session_idx: {session_index}, item_idx: {item_index}, err: {err}",
549                                    processed.len(),
550                                    unprocessed.len(),
551                                );
552                            }
553                        }
554
555                        info!(
556                            target: LOG_CONSENSUS,
557                            ?session_index,
558                            peer_id = %peer_id,
559                            "Successfully recovered session via P2P"
560                        );
561
562                        return Some(p2p_outcome);
563                    }
564
565                    debug!(
566                        target: LOG_CONSENSUS,
567                        %peer_id,
568                        "Invalid P2P SignedSessionOutcome"
569                    );
570                }
571                _ = index_broadcast_interval.tick() => {
572                    // TODO: start sending the new messages in 0.11.0
573                    // connections.send(
574                    //     Recipient::Peer(self.random_peer()),
575                    //     P2PMessage::SessionIndex(session_index),
576                    // );
577                }
578            }
579        }
580
581        let items = self.pending_accepted_items().await;
582
583        assert_eq!(item_index, items.len() as u64);
584
585        info!(target: LOG_CONSENSUS, ?session_index, ?item_index, "Processed all items for session");
586
587        let session_outcome = SessionOutcome { items };
588
589        let header = session_outcome.header(session_index);
590
591        info!(
592            target: LOG_CONSENSUS,
593            ?session_index,
594            "Signing session header..."
595        );
596
597        let keychain = Keychain::new(&self.cfg);
598
599        let our_signature = keychain.sign_schnorr(&header);
600
601        // Send our own signature to the data provider to be submitted to AlephBFT
602        #[allow(clippy::disallowed_methods)]
603        signature_sender.send(Some(our_signature)).ok()?;
604
605        let mut signatures = BTreeMap::from_iter([(self.identity(), our_signature)]);
606
607        let items_dump = tokio::sync::OnceCell::new();
608
609        // We request the session signature every second to all peers
610        let mut signature_broadcast_interval = tokio::time::interval(Duration::from_secs(1));
611
612        // We collect the ordered signatures until we either obtain a threshold
613        // signature or a signed session outcome arrives from our peers
614        while signatures.len() < self.num_peers().threshold() {
615            tokio::select! {
616                // TODO: remove this branch in 0.11.0
617                result = ordered_unit_receiver.recv() => {
618                    let ordered_unit = result.ok()?;
619
620                    if let Some(UnitData::Signature(signature)) = ordered_unit.data {
621                        info!(
622                            target: LOG_CONSENSUS,
623                            ?session_index,
624                            peer = %ordered_unit.creator,
625                            "Collected signature from peer via AlephBFT, verifying..."
626                        );
627
628                        if keychain.verify(&header, &signature, to_node_index(ordered_unit.creator)){
629                            signatures.insert(ordered_unit.creator, schnorr::Signature::from_slice(&signature).expect("AlephBFT signature is valid"));
630                        } else {
631                            error!(
632                                target: LOG_CONSENSUS,
633                                ?session_index,
634                                peer = %ordered_unit.creator,
635                                "Consensus Failure: invalid header signature from peer"
636                            );
637
638                            items_dump.get_or_init(|| async {
639                                for (idx, item) in session_outcome.items.iter().enumerate() {
640                                    info!(target: LOG_CONSENSUS, idx, item = %DebugConsensusItemCompact(item), "Item");
641                                }
642                            }).await;
643                        }
644                    }
645                }
646                result = signatures_receiver.recv() => {
647                    let (peer_id, signature) = result.ok()?;
648
649                    if keychain.verify_schnorr(&header, &signature, peer_id) {
650                        signatures.insert(peer_id, signature);
651
652                        info!(
653                            target: LOG_CONSENSUS,
654                            session_index,
655                            peer_id = %peer_id,
656                            "Collected signature from peer via P2P"
657                        );
658                    }
659
660                    debug!(
661                        target: LOG_CONSENSUS,
662                        session_index,
663                        peer_id = %peer_id,
664                        "Invalid P2P signature from peer"
665                    );
666                }
667                // TODO: remove this branch in 0.11.0
668                signed_session_outcome = &mut request_signed_session_outcome => {
669                    info!(
670                        target: LOG_CONSENSUS,
671                        ?session_index,
672                        "Recovered signed session outcome from peers while collecting signatures"
673                    );
674
675                    assert_eq!(
676                        header,
677                        signed_session_outcome.session_outcome.header(session_index),
678                        "Consensus Failure: header disagrees with federation consensus"
679                    );
680
681                    return Some(signed_session_outcome);
682                },
683                result = signed_outcomes_receiver.recv() => {
684                    let (peer_id, p2p_outcome) = result.ok()?;
685
686                    if self.validate_signed_session_outcome(&p2p_outcome, session_index) {
687                        assert_eq!(
688                            header,
689                            p2p_outcome.session_outcome.header(session_index),
690                            "Consensus Failure: header disagrees with federation consensus"
691                        );
692
693                        info!(
694                            target: LOG_CONSENSUS,
695                            session_index,
696                            %peer_id,
697                            "Recovered session via P2P while collecting signatures"
698                        );
699
700                        return Some(p2p_outcome);
701                    }
702
703                    debug!(
704                        target: LOG_CONSENSUS,
705                        %peer_id,
706                        "Invalid P2P SignedSessionOutcome"
707                    );
708                }
709                _ = signature_broadcast_interval.tick() => {
710                    // TODO: start sending the new messages in 0.11.0
711                    // connections.send(
712                    //     Recipient::Everyone,
713                    //     P2PMessage::SessionSignature(our_signature),
714                    // );
715                }
716                _ = index_broadcast_interval.tick() => {
717                    // TODO: start sending the new messages in 0.11.0
718                    // connections.send(
719                    //     Recipient::Peer(self.random_peer()),
720                    //     P2PMessage::SessionIndex(session_index),
721                    // );
722                }
723            }
724        }
725
726        info!(
727            target: LOG_CONSENSUS,
728            session_index,
729            "Successfully collected threshold of signatures"
730        );
731
732        Some(SignedSessionOutcome {
733            session_outcome,
734            signatures,
735        })
736    }
737
738    /// Returns a random peer ID excluding ourselves
739    #[allow(unused)]
740    fn random_peer(&self) -> PeerId {
741        self.num_peers()
742            .peer_ids()
743            .filter(|p| *p != self.identity())
744            .choose(&mut rand::thread_rng())
745            .expect("We have at least three peers")
746    }
747
748    /// Validate a SignedSessionOutcome received via P2P
749    fn validate_signed_session_outcome(
750        &self,
751        outcome: &SignedSessionOutcome,
752        session_index: u64,
753    ) -> bool {
754        if outcome.signatures.len() != self.num_peers().threshold() {
755            return false;
756        }
757
758        let keychain = Keychain::new(&self.cfg);
759        let header = outcome.session_outcome.header(session_index);
760
761        outcome
762            .signatures
763            .iter()
764            .all(|(signer_id, sig)| keychain.verify_schnorr(&header, sig, *signer_id))
765    }
766
767    fn decoders(&self) -> ModuleDecoderRegistry {
768        self.modules.decoder_registry()
769    }
770
771    pub async fn pending_accepted_items(&self) -> Vec<AcceptedItem> {
772        self.db
773            .begin_transaction_nc()
774            .await
775            .find_by_prefix(&AcceptedItemPrefix)
776            .await
777            .map(|entry| entry.1)
778            .collect()
779            .await
780    }
781
782    pub async fn complete_session(
783        &self,
784        session_index: u64,
785        signed_session_outcome: SignedSessionOutcome,
786    ) {
787        let mut dbtx = self.db.begin_transaction().await;
788
789        dbtx.remove_by_prefix(&AlephUnitsPrefix).await;
790
791        dbtx.remove_by_prefix(&AcceptedItemPrefix).await;
792
793        if dbtx
794            .insert_entry(
795                &SignedSessionOutcomeKey(session_index),
796                &signed_session_outcome,
797            )
798            .await
799            .is_some()
800        {
801            panic!("We tried to overwrite a signed session outcome");
802        }
803
804        dbtx.commit_tx_result()
805            .await
806            .expect("This is the only place where we write to this key");
807
808        self.completed_session_sender.send_replace(());
809    }
810
811    /// Returns the full path where the database checkpoints are stored.
812    fn db_checkpoints_dir(&self) -> PathBuf {
813        self.data_dir.join(DB_CHECKPOINTS_DIR)
814    }
815
816    /// Creates the directory within the data directory for storing the database
817    /// checkpoints or deletes checkpoints before `current_session` -
818    /// `checkpoint_retention`.
819    fn initialize_checkpoint_directory(&self, current_session: u64) -> anyhow::Result<()> {
820        let checkpoint_dir = self.db_checkpoints_dir();
821
822        if checkpoint_dir.exists() {
823            debug!(
824                target: LOG_CONSENSUS,
825                ?current_session,
826                "Removing database checkpoints up to `current_session`"
827            );
828
829            for checkpoint in fs::read_dir(checkpoint_dir)?.flatten() {
830                // Validate that the directory is a session index
831                if let Ok(file_name) = checkpoint.file_name().into_string()
832                    && let Ok(session) = file_name.parse::<u64>()
833                    && current_session >= self.db_checkpoint_retention
834                    && session < current_session - self.db_checkpoint_retention
835                {
836                    fs::remove_dir_all(checkpoint.path())?;
837                }
838            }
839        } else {
840            fs::create_dir_all(&checkpoint_dir)?;
841        }
842
843        Ok(())
844    }
845
846    /// Creates a backup of the database in the checkpoint directory. These
847    /// checkpoints can be used to restore the database in case the
848    /// federation falls out of consensus (recommended for experts only).
849    fn checkpoint_database(&self, session_index: u64) {
850        // If `checkpoint_retention` has been turned off, don't checkpoint the database
851        // at all.
852        if self.db_checkpoint_retention == 0 {
853            return;
854        }
855
856        let checkpoint_dir = self.db_checkpoints_dir();
857        let session_checkpoint_dir = checkpoint_dir.join(format!("{session_index}"));
858
859        {
860            let _timing /* logs on drop */ = timing::TimeReporter::new("database-checkpoint").level(Level::TRACE);
861            match self.db.checkpoint(&session_checkpoint_dir) {
862                Ok(()) => {
863                    debug!(target: LOG_CONSENSUS, ?session_checkpoint_dir, ?session_index, "Created db checkpoint");
864                }
865                Err(err) => {
866                    warn!(target: LOG_CONSENSUS, ?session_checkpoint_dir, ?session_index, err = %err.fmt_compact(), "Could not create db checkpoint");
867                }
868            }
869        }
870
871        {
872            // Check if any old checkpoint need to be cleaned up
873            let _timing /* logs on drop */ = timing::TimeReporter::new("remove-database-checkpoint").level(Level::TRACE);
874            if let Err(err) = self.delete_old_database_checkpoint(session_index, &checkpoint_dir) {
875                warn!(target: LOG_CONSENSUS, err = %err.fmt_compact(), "Could not delete old checkpoints");
876            }
877        }
878    }
879
880    /// Deletes the database checkpoint directory equal to `session_index` -
881    /// `checkpoint_retention`
882    fn delete_old_database_checkpoint(
883        &self,
884        session_index: u64,
885        checkpoint_dir: &Path,
886    ) -> anyhow::Result<()> {
887        if self.db_checkpoint_retention > session_index {
888            return Ok(());
889        }
890
891        let delete_session_index = session_index - self.db_checkpoint_retention;
892        let checkpoint_to_delete = checkpoint_dir.join(delete_session_index.to_string());
893        if checkpoint_to_delete.exists() {
894            fs::remove_dir_all(checkpoint_to_delete)?;
895        }
896
897        Ok(())
898    }
899
900    #[instrument(target = LOG_CONSENSUS, skip(self, item), level = "info")]
901    pub async fn process_consensus_item(
902        &self,
903        session_index: u64,
904        item_index: u64,
905        item: ConsensusItem,
906        peer: PeerId,
907    ) -> anyhow::Result<()> {
908        let _timing /* logs on drop */ = timing::TimeReporter::new("process_consensus_item").level(Level::TRACE);
909
910        let timing_prom = CONSENSUS_ITEM_PROCESSING_DURATION_SECONDS
911            .with_label_values(&[&peer.to_usize().to_string()])
912            .start_timer();
913
914        trace!(
915            target: LOG_CONSENSUS,
916            %peer,
917            item = ?DebugConsensusItem(&item),
918            "Processing consensus item"
919        );
920
921        self.ci_status_senders
922            .get(&peer)
923            .expect("No ci status sender for peer")
924            .send_replace(Some(session_index));
925
926        CONSENSUS_PEER_CONTRIBUTION_SESSION_IDX
927            .with_label_values(&[
928                &self.cfg.local.identity.to_usize().to_string(),
929                &peer.to_usize().to_string(),
930            ])
931            .set(session_index as i64);
932
933        let mut attempt: usize = 1;
934
935        let outcome = loop {
936            match self
937                .process_consensus_item_attempt(item_index, &item, peer)
938                .await
939            {
940                Ok(outcome) => break outcome,
941                Err(err) => {
942                    // A snapshot that aged out of the backend's write history is the only
943                    // commit failure we can do anything about, and the only way to recover
944                    // is to rerun the whole operation against a fresh transaction. Nothing
945                    // was written, and reprocessing an ordered item is deterministic, so
946                    // the replay is equivalent to having processed it a moment later.
947                    assert!(
948                        matches!(err, DatabaseError::SnapshotTooOld(_)),
949                        "Committing consensus item failed: {err}"
950                    );
951
952                    assert!(
953                        attempt < MAX_ITEM_PROCESSING_ATTEMPTS,
954                        "Committing consensus item failed after {attempt} attempts: {err}"
955                    );
956
957                    warn!(
958                        target: LOG_CONSENSUS,
959                        %peer,
960                        item_index,
961                        attempt,
962                        err = %err.fmt_compact(),
963                        "Consensus item transaction could not be validated - reprocessing item"
964                    );
965
966                    attempt += 1;
967                }
968            }
969        };
970
971        outcome?;
972
973        timing_prom.observe_duration();
974
975        Ok(())
976    }
977
978    /// Process a single ordered consensus item in one database transaction.
979    ///
980    /// The outer `Err` means the transaction could not be committed and the
981    /// caller has to rerun the whole operation in a fresh one. The inner `Err`
982    /// means the item itself was rejected, which is a normal, final outcome.
983    async fn process_consensus_item_attempt(
984        &self,
985        item_index: u64,
986        item: &ConsensusItem,
987        peer: PeerId,
988    ) -> DatabaseResult<anyhow::Result<()>> {
989        let mut dbtx = self.db.begin_transaction().await;
990
991        dbtx.ignore_uncommitted();
992
993        // When we recover from a mid-session crash aleph bft will replay the units that
994        // were already processed before the crash. We therefore skip all consensus
995        // items until we have seen every previously accepted items again.
996        if let Some(existing_item) = dbtx.get_value(&AcceptedItemKey(item_index)).await {
997            if existing_item.item == *item && existing_item.peer == peer {
998                return Ok(Ok(()));
999            }
1000
1001            return Ok(Err(anyhow!(
1002                "Item was discarded previously: existing: {existing_item:?} {}, current: {item:?}, {peer}",
1003                existing_item.peer
1004            )));
1005        }
1006
1007        if let Err(err) = self
1008            .process_consensus_item_with_db_transaction(&mut dbtx.to_ref_nc(), item.clone(), peer)
1009            .await
1010        {
1011            // Rejected items are very common, so only trace level
1012            trace!(
1013                target: LOG_CONSENSUS,
1014                %peer,
1015                item = ?DebugConsensusItem(item),
1016                err = %err.fmt_compact(),
1017                "Rejected consensus item"
1018            );
1019
1020            return Ok(Err(err));
1021        }
1022
1023        // After this point we have to commit the database transaction since the
1024        // item has been fully processed without errors
1025        dbtx.warn_uncommitted();
1026
1027        dbtx.insert_entry(
1028            &AcceptedItemKey(item_index),
1029            &AcceptedItem {
1030                item: item.clone(),
1031                peer,
1032            },
1033        )
1034        .await;
1035
1036        debug!(
1037            target: LOG_CONSENSUS,
1038            %peer,
1039            item = ?DebugConsensusItem(item),
1040            "Processed consensus item"
1041        );
1042        let mut audit = Audit::default();
1043
1044        for (module_instance_id, kind, module) in self.modules.iter_modules() {
1045            let _module_audit_timing =
1046                TimeReporter::new(format!("audit module {module_instance_id}")).level(Level::TRACE);
1047
1048            let timing_prom = CONSENSUS_ITEM_PROCESSING_MODULE_AUDIT_DURATION_SECONDS
1049                .with_label_values(&[
1050                    MODULE_INSTANCE_ID_GLOBAL.to_string().as_str(),
1051                    kind.as_str(),
1052                ])
1053                .start_timer();
1054
1055            module
1056                .audit(
1057                    &mut dbtx
1058                        .to_ref_with_prefix_module_id(module_instance_id)
1059                        .0
1060                        .into_nc(),
1061                    &mut audit,
1062                    module_instance_id,
1063                )
1064                .await;
1065
1066            timing_prom.observe_duration();
1067        }
1068
1069        assert!(
1070            audit
1071                .net_assets()
1072                .expect("Overflow while checking balance sheet")
1073                .milli_sat
1074                >= 0,
1075            "Balance sheet of the fed has gone negative, this should never happen! {audit}"
1076        );
1077
1078        dbtx.commit_tx_result().await?;
1079
1080        self.accepted_item_sender.send_replace(());
1081
1082        // Counted here rather than in the caller so that only an attempt that actually
1083        // committed is counted: the replay and rejection paths above return early, and
1084        // a failed attempt loops back around to a fresh transaction.
1085        CONSENSUS_ITEMS_PROCESSED_TOTAL
1086            .with_label_values(&[&peer.to_usize().to_string()])
1087            .inc();
1088
1089        Ok(Ok(()))
1090    }
1091
1092    async fn process_consensus_item_with_db_transaction(
1093        &self,
1094        dbtx: &mut DatabaseTransaction<'_>,
1095        consensus_item: ConsensusItem,
1096        peer_id: PeerId,
1097    ) -> anyhow::Result<()> {
1098        // We rely on decoding rejecting any unknown module instance ids to avoid
1099        // peer-triggered panic here
1100        self.decoders().assert_reject_mode();
1101
1102        match consensus_item {
1103            ConsensusItem::Module(module_item) => {
1104                let instance_id = module_item.module_instance_id();
1105
1106                let module_dbtx = &mut dbtx.to_ref_with_prefix_module_id(instance_id).0;
1107
1108                self.modules
1109                    .get_expect(instance_id)
1110                    .process_consensus_item(module_dbtx, &module_item, peer_id)
1111                    .await
1112            }
1113            ConsensusItem::Transaction(transaction) => {
1114                let txid = transaction.tx_hash();
1115                if dbtx
1116                    .get_value(&AcceptedTransactionKey(txid))
1117                    .await
1118                    .is_some()
1119                {
1120                    debug!(
1121                        target: LOG_CONSENSUS,
1122                        %txid,
1123                        "Transaction already accepted"
1124                    );
1125                    bail!("Transaction is already accepted");
1126                }
1127
1128                let modules_ids = transaction
1129                    .outputs
1130                    .iter()
1131                    .map(DynOutput::module_instance_id)
1132                    .collect::<Vec<_>>();
1133
1134                process_transaction_with_dbtx(
1135                    self.modules.clone(),
1136                    dbtx,
1137                    &transaction,
1138                    self.cfg.consensus.version,
1139                    TxProcessingMode::Consensus,
1140                )
1141                .await
1142                .map_err(|error| anyhow!(error.to_string()))?;
1143
1144                debug!(target: LOG_CONSENSUS, %txid,  "Transaction accepted");
1145                dbtx.insert_entry(&AcceptedTransactionKey(txid), &modules_ids)
1146                    .await;
1147
1148                Ok(())
1149            }
1150            ConsensusItem::Default { variant, .. } => {
1151                // `ConsensusItem` has an `#[encodable_default]` variant, so an unknown
1152                // discriminant decodes successfully instead of erroring. The variant byte
1153                // is attacker-controlled: a malicious peer can put an arbitrary batch into
1154                // its unit, so this must be rejected rather than treated as unreachable.
1155                warn!(
1156                    target: LOG_CONSENSUS,
1157                    "Minor consensus version mismatch: unexpected consensus item type: {variant}"
1158                );
1159
1160                bail!("Unexpected consensus item type: {variant}")
1161            }
1162        }
1163    }
1164
1165    async fn request_signed_session_outcome(
1166        &self,
1167        federation_api: &DynGlobalApi,
1168        index: u64,
1169    ) -> SignedSessionOutcome {
1170        let decoders = self.decoders();
1171        let keychain = Keychain::new(&self.cfg);
1172        let threshold = self.num_peers().threshold();
1173
1174        let filter_map = move |response: SerdeModuleEncoding<SignedSessionOutcome>| {
1175            let signed_session_outcome = response
1176                .try_into_inner(&decoders)
1177                .map_err(|x| ServerError::ResponseDeserialization(Box::new(x)))?;
1178            let header = signed_session_outcome.session_outcome.header(index);
1179            if signed_session_outcome.signatures.len() == threshold
1180                && signed_session_outcome
1181                    .signatures
1182                    .iter()
1183                    .all(|(peer_id, sig)| keychain.verify_schnorr(&header, sig, *peer_id))
1184            {
1185                Ok(signed_session_outcome)
1186            } else {
1187                Err(ServerError::InvalidResponse(
1188                    "Invalid signatures".to_string(),
1189                ))
1190            }
1191        };
1192
1193        federation_api
1194            .request_with_strategy_retry(
1195                FilterMap::new(filter_map.clone()),
1196                AWAIT_SIGNED_SESSION_OUTCOME_ENDPOINT.to_string(),
1197                ApiRequestErased::new(index),
1198            )
1199            .await
1200    }
1201
1202    /// Returns the number of sessions already saved in the database. This count
1203    /// **does not** include the currently running session.
1204    async fn get_finished_session_count(&self) -> u64 {
1205        get_finished_session_count_static(&mut self.db.begin_transaction_nc().await).await
1206    }
1207}
1208
1209pub async fn get_finished_session_count_static(dbtx: &mut DatabaseTransaction<'_>) -> u64 {
1210    dbtx.find_by_prefix_sorted_descending(&SignedSessionOutcomePrefix)
1211        .await
1212        .next()
1213        .await
1214        .map_or(0, |entry| (entry.0.0) + 1)
1215}