From 4e5ef6bce24b69a08bae937103d06f153938d28c Mon Sep 17 00:00:00 2001
From: carllin <carl@solana.com>
Date: Fri, 2 Apr 2021 21:48:44 -0700
Subject: [PATCH] Add cluster state verifier logging (#16330)

* Add cluster state verifier logging

* Add duplicate-slots iterator to ledger tool
---
 core/src/cluster_slot_state_verifier.rs  | 22 ++++++++++++++++++++++
 core/src/heaviest_subtree_fork_choice.rs | 10 ++++++++++
 core/src/replay_stage.rs                 |  1 -
 ledger-tool/src/main.rs                  | 16 ++++++++++++++++
 ledger/src/blockstore.rs                 |  7 +++++++
 5 files changed, 55 insertions(+), 1 deletion(-)

diff --git a/core/src/cluster_slot_state_verifier.rs b/core/src/cluster_slot_state_verifier.rs
index 0edff63f80..caa91dbad2 100644
--- a/core/src/cluster_slot_state_verifier.rs
+++ b/core/src/cluster_slot_state_verifier.rs
@@ -239,6 +239,15 @@ pub(crate) fn check_slot_agrees_with_cluster(
     fork_choice: &mut HeaviestSubtreeForkChoice,
     slot_state_update: SlotStateUpdate,
 ) {
+    info!(
+        "check_slot_agrees_with_cluster()
+        slot: {},
+        root: {},
+        frozen_hash: {:?},
+        update: {:?}",
+        slot, root, frozen_hash, slot_state_update
+    );
+
     if slot <= root {
         return;
     }
@@ -252,6 +261,7 @@ pub(crate) fn check_slot_agrees_with_cluster(
 
     let frozen_hash = frozen_hash.unwrap();
     let gossip_duplicate_confirmed_hash = gossip_duplicate_confirmed_slots.get(&slot);
+
     let is_local_replay_duplicate_confirmed = progress.is_duplicate_confirmed(slot).expect("If the frozen hash exists, then the slot must exist in bank forks and thus in progress map");
     let cluster_duplicate_confirmed_hash = get_cluster_duplicate_confirmed_hash(
         slot,
@@ -273,6 +283,18 @@ pub(crate) fn check_slot_agrees_with_cluster(
     }
     let is_dead = progress.is_dead(slot).expect("If the frozen hash exists, then the slot must exist in bank forks and thus in progress map");
 
+    info!(
+        "check_slot_agrees_with_cluster() state
+        is_local_replay_duplicate_confirmed: {:?},
+        cluster_duplicate_confirmed_hash: {:?},
+        is_slot_duplicate: {:?},
+        is_dead: {:?}",
+        is_local_replay_duplicate_confirmed,
+        cluster_duplicate_confirmed_hash,
+        is_slot_duplicate,
+        is_dead,
+    );
+
     let state_handler = slot_state_update.to_handler();
     let state_changes = state_handler(
         slot,
diff --git a/core/src/heaviest_subtree_fork_choice.rs b/core/src/heaviest_subtree_fork_choice.rs
index 3248ed4739..43d183563b 100644
--- a/core/src/heaviest_subtree_fork_choice.rs
+++ b/core/src/heaviest_subtree_fork_choice.rs
@@ -471,6 +471,12 @@ impl HeaviestSubtreeForkChoice {
 
     fn mark_slot_valid(&mut self, valid_slot: Slot) {
         if let Some(fork_info) = self.fork_infos.get_mut(&valid_slot) {
+            if !fork_info.is_candidate {
+                info!(
+                    "marked previously invalid fork starting at slot: {} as valid",
+                    valid_slot
+                );
+            }
             fork_info.is_candidate = true;
         }
     }
@@ -683,6 +689,10 @@ impl ForkChoice for HeaviestSubtreeForkChoice {
     }
 
     fn mark_fork_invalid_candidate(&mut self, invalid_slot: Slot) {
+        info!(
+            "marking fork starting at slot: {} invalid candidate",
+            invalid_slot
+        );
         let fork_info = self.fork_infos.get_mut(&invalid_slot);
         if let Some(fork_info) = fork_info {
             if fork_info.is_candidate {
diff --git a/core/src/replay_stage.rs b/core/src/replay_stage.rs
index 283ac0ce78..40f3c2f2b3 100644
--- a/core/src/replay_stage.rs
+++ b/core/src/replay_stage.rs
@@ -934,7 +934,6 @@ impl ReplayStage {
         for (duplicate_slot, bank_hash) in duplicate_slots.into_iter().zip(bank_hashes.into_iter())
         {
             // WindowService should only send the signal once per slot
-
             check_slot_agrees_with_cluster(
                 duplicate_slot,
                 root_slot,
diff --git a/ledger-tool/src/main.rs b/ledger-tool/src/main.rs
index 3796413011..35f0f786f8 100644
--- a/ledger-tool/src/main.rs
+++ b/ledger-tool/src/main.rs
@@ -921,6 +921,11 @@ fn main() {
             .arg(&starting_slot_arg)
             .about("Print all the dead slots in the ledger")
         )
+        .subcommand(
+            SubCommand::with_name("duplicate-slots")
+            .arg(&starting_slot_arg)
+            .about("Print all the duplicate slots in the ledger")
+        )
         .subcommand(
             SubCommand::with_name("set-dead-slot")
             .about("Mark one or more slots dead")
@@ -1601,6 +1606,17 @@ fn main() {
                 println!("{}", slot);
             }
         }
+        ("duplicate-slots", Some(arg_matches)) => {
+            let blockstore = open_blockstore(
+                &ledger_path,
+                AccessType::TryPrimaryThenSecondary,
+                wal_recovery_mode,
+            );
+            let starting_slot = value_t_or_exit!(arg_matches, "starting_slot", Slot);
+            for slot in blockstore.duplicate_slots_iterator(starting_slot).unwrap() {
+                println!("{}", slot);
+            }
+        }
         ("set-dead-slot", Some(arg_matches)) => {
             let slots = values_t_or_exit!(arg_matches, "slots", Slot);
             let blockstore =
diff --git a/ledger/src/blockstore.rs b/ledger/src/blockstore.rs
index 01920ffc0d..882a30b812 100644
--- a/ledger/src/blockstore.rs
+++ b/ledger/src/blockstore.rs
@@ -2855,6 +2855,13 @@ impl Blockstore {
         Ok(dead_slots_iterator.map(|(slot, _)| slot))
     }
 
+    pub fn duplicate_slots_iterator(&self, slot: Slot) -> Result<impl Iterator<Item = Slot> + '_> {
+        let duplicate_slots_iterator = self
+            .db
+            .iter::<cf::DuplicateSlots>(IteratorMode::From(slot, IteratorDirection::Forward))?;
+        Ok(duplicate_slots_iterator.map(|(slot, _)| slot))
+    }
+
     pub fn last_root(&self) -> Slot {
         *self.last_root.read().unwrap()
     }