Track timing of consensus stages

Cargo.toml

@@ -296,10 +296,15 @@ serial = [
   "snarkos-node-sync/serial",
   "snarkvm/serial"
 ]
+tokio_console = [ "snarkos-cli/tokio_console" ]
+# Set low puzzle targets for easier testing.
 test_targets = [ "snarkos-cli/test_targets" ]
+# Set custom consensus heights for easier testing.
 test_consensus_heights = [ "snarkos-cli/test_consensus_heights" ]
+# Set low puzzle targets and custom consensus heights for easier testing.
 test_network = [ "snarkos-cli/test_network" ]
-tokio_console = [ "snarkos-cli/tokio_console" ]
+# Track duration of consensus stages.
+test_consensus_tracking = [ "snarkos-node/test_consensus_tracking" ]
 
 [dependencies.clap]
 workspace = true

node/Cargo.toml

@@ -54,6 +54,7 @@ serial = [
   "snarkvm/serial",
   "snarkos-node-bft/serial"
 ]
+test_consensus_tracking = [ "snarkos-node-bft/test_consensus_tracking", "snarkos-node-consensus/test_consensus_tracking" ] 
 test = []
 
 [dependencies.aleo-std]

node/bft/Cargo.toml

@@ -45,6 +45,7 @@ test = [
   "snarkos-node-bft-ledger-service/test",
   "snarkos-node-bft-storage-service/test"
 ]
+test_consensus_tracking = [ ]
 serial = [
   "snarkos-node-metrics/serial",
   "snarkos-node-bft-ledger-service/serial"
@@ -97,6 +98,16 @@ workspace = true
 [dependencies.rayon]
 workspace = true
 
+[dependencies.serde]
+workspace = true
+features = [ "derive" ]
+
+[dependencies.serde_json]
+workspace = true
+
+[dependencies.once_cell]
+version = "1.0"
+
 [dependencies.sha2]
 version = "0.10"
 default-features = false

node/bft/src/bft.rs

@@ -13,6 +13,8 @@
 // See the License for the specific language governing permissions and
 // limitations under the License.
 
+#[cfg(feature = "test_consensus_tracking")]
+use crate::helpers::{ConsensusStage, SubdagStage, record_event, start_subdag_stage};
 use crate::{
     MAX_LEADER_CERTIFICATE_DELAY_IN_SECS,
     Primary,
@@ -506,6 +508,9 @@ impl<N: Network> BFT<N> {
         // Insert the certificate into the DAG.
         self.dag.write().insert(certificate);
 
+        #[cfg(feature = "test_consensus_tracking")]
+        record_event(certificate_round, ConsensusStage::CertificateAdded);
+
         // ### Second, determine if a new leader certificate can be committed. ###
         let commit_round = certificate_round.saturating_sub(1);
 
@@ -596,6 +601,9 @@ impl<N: Network> BFT<N> {
 
         // Fetch the leader round.
         let latest_leader_round = leader_certificate.round();
+
+        #[cfg(feature = "test_consensus_tracking")]
+        start_subdag_stage(latest_leader_round.saturating_sub(2), latest_leader_round, SubdagStage::SubdagProcessing);
         // Determine the list of all previous leader certificates since the last committed round.
         // The order of the leader certificates is from **newest** to **oldest**.
         let mut leader_certificates = vec![leader_certificate.clone()];

node/bft/src/helpers/mod.rs

@@ -51,6 +51,11 @@ pub use telemetry::*;
 pub mod timestamp;
 pub use timestamp::*;
 
+#[cfg(feature = "test_consensus_tracking")]
+pub mod timing;
+#[cfg(feature = "test_consensus_tracking")]
+pub use timing::*;
+
 /// Formats an ID into a truncated identifier (for logging purposes).
 pub fn fmt_id(id: impl ToString) -> String {
     let id = id.to_string();