test: add extra stats to cross_shard_tx (#3057)

The usefulness and flakiness of `cross_shard_tx` depends heavily on the block production time. This change adds printing block stats every minute, we will print the following: - ratio of number of blocks to longest chain - maximum divergence between recently produced blocks In addition we will fail `cross_shard_tx` test if the ratio is too high or to low, depending on test parameters. #3014
near · Aug 11, 2020 · 58a0370 · 58a0370
1 parent 8ddefbf
commit 58a0370
Show file tree

Hide file tree

Showing 7 changed files with 171 additions and 24 deletions.
diff --git a/chain/client/src/test_utils.rs b/chain/client/src/test_utils.rs
@@ -1,7 +1,9 @@
+use log::info;
 use std::cmp::max;
 use std::collections::{HashMap, HashSet};
 use std::ops::DerefMut;
 use std::sync::{Arc, RwLock};
+use std::time::Duration;
 
 use actix::actors::mocker::Mocker;
 use actix::{Actor, Addr, AsyncContext, Context};
@@ -46,6 +48,7 @@ use near_primitives::receipt::Receipt;
 use near_primitives::sharding::{EncodedShardChunk, ReedSolomonWrapper};
 use num_rational::Rational;
 use std::mem::swap;
+use std::time::Instant;
 
 pub type NetworkMock = Mocker<PeerManagerActor>;
 
@@ -200,6 +203,105 @@ fn sample_binary(n: u64, k: u64) -> bool {
     thread_rng().gen_range(0, k) <= n
 }
 
+pub struct BlockStats {
+    hash2depth: HashMap<CryptoHash, u64>,
+    num_blocks: u64,
+    max_chain_length: u64,
+    last_check: Instant,
+    max_divergence: u64,
+    last_hash: Option<CryptoHash>,
+    parent: HashMap<CryptoHash, CryptoHash>,
+}
+
+impl BlockStats {
+    fn new() -> BlockStats {
+        BlockStats {
+            hash2depth: HashMap::new(),
+            num_blocks: 0,
+            max_chain_length: 0,
+            last_check: Instant::now(),
+            max_divergence: 0,
+            last_hash: None,
+            parent: HashMap::new(),
+        }
+    }
+
+    fn calculate_distance(&mut self, mut lhs: CryptoHash, mut rhs: CryptoHash) -> u64 {
+        let mut dlhs = *self.hash2depth.get(&lhs).unwrap();
+        let mut drhs = *self.hash2depth.get(&rhs).unwrap();
+
+        let mut result: u64 = 0;
+        while dlhs > drhs {
+            lhs = *self.parent.get(&lhs).unwrap();
+            dlhs -= 1;
+            result += 1;
+        }
+        while dlhs < drhs {
+            rhs = *self.parent.get(&rhs).unwrap();
+            drhs -= 1;
+            result += 1;
+        }
+        while lhs != rhs {
+            lhs = *self.parent.get(&lhs).unwrap();
+            rhs = *self.parent.get(&rhs).unwrap();
+            result += 2;
+        }
+        result
+    }
+
+    fn add_block(&mut self, block: &Block) {
+        if self.hash2depth.contains_key(block.hash()) {
+            return;
+        }
+        let prev_height = self.hash2depth.get(block.header().prev_hash()).map(|v| *v).unwrap_or(0);
+        self.hash2depth.insert(*block.hash(), prev_height + 1);
+        self.num_blocks += 1;
+        self.max_chain_length = max(self.max_chain_length, prev_height + 1);
+        self.parent.insert(*block.hash(), *block.header().prev_hash());
+
+        if let Some(last_hash2) = self.last_hash {
+            self.max_divergence =
+                max(self.max_divergence, self.calculate_distance(last_hash2, block.hash().clone()));
+        }
+
+        self.last_hash = Some(block.hash().clone());
+    }
+
+    pub fn check_stats(&mut self, force: bool) {
+        let now = Instant::now();
+        let diff = now.duration_since(self.last_check);
+        if !force && diff.lt(&Duration::from_secs(60)) {
+            return;
+        }
+        self.last_check = now;
+        let cur_ratio = (self.num_blocks as f64) / (max(1, self.max_chain_length) as f64);
+        info!(
+            "Block stats: ratio: {:.2}, num_blocks: {} max_chain_length: {} max_divergence: {}",
+            cur_ratio, self.num_blocks, self.max_chain_length, self.max_divergence
+        );
+    }
+
+    pub fn check_block_ratio(&mut self, min_ratio: Option<f64>, max_ratio: Option<f64>) {
+        let cur_ratio = (self.num_blocks as f64) / (max(1, self.max_chain_length) as f64);
+        if let Some(min_ratio2) = min_ratio {
+            if cur_ratio < min_ratio2 {
+                panic!(
+                    "ratio of blocks to longest chain is too low got: {:.2} expected: {:.2}",
+                    cur_ratio, min_ratio2
+                );
+            }
+        }
+        if let Some(max_ratio2) = max_ratio {
+            if cur_ratio > max_ratio2 {
+                panic!(
+                    "ratio of blocks to longest chain is too high got: {:.2} expected: {:.2}",
+                    cur_ratio, max_ratio2
+                );
+            }
+        }
+    }
+}
+
 /// Sets up ClientActor and ViewClientActor with mock PeerManager.
 ///
 /// # Arguments
@@ -243,8 +345,9 @@ pub fn setup_mock_all_validators(
     epoch_length: BlockHeightDelta,
     enable_doomslug: bool,
     archive: Vec<bool>,
+    check_block_stats: bool,
     network_mock: Arc<RwLock<Box<dyn FnMut(String, &NetworkRequests) -> (NetworkResponses, bool)>>>,
-) -> (Block, Vec<(Addr<ClientActor>, Addr<ViewClientActor>)>) {
+) -> (Block, Vec<(Addr<ClientActor>, Addr<ViewClientActor>)>, Arc<RwLock<BlockStats>>) {
     let validators_clone = validators.clone();
     let key_pairs = key_pairs;
 
@@ -267,8 +370,10 @@ pub fn setup_mock_all_validators(
     let largest_endorsed_height = Arc::new(RwLock::new(vec![0u64; key_pairs.len()]));
     let largest_skipped_height = Arc::new(RwLock::new(vec![0u64; key_pairs.len()]));
     let hash_to_height = Arc::new(RwLock::new(HashMap::new()));
+    let block_stats = Arc::new(RwLock::new(BlockStats::new()));
 
     for (index, account_id) in validators.into_iter().flatten().enumerate() {
+        let block_stats1 = block_stats.clone();
         let view_client_addr = Arc::new(RwLock::new(None));
         let view_client_addr1 = view_client_addr.clone();
         let validators_clone1 = validators_clone.clone();
@@ -347,6 +452,12 @@ pub fn setup_mock_all_validators(
 
                     match msg {
                         NetworkRequests::Block { block } => {
+                            if check_block_stats {
+                                let block_stats2 = &mut *block_stats1.write().unwrap();
+                                block_stats2.add_block(block);
+                                block_stats2.check_stats(false);
+                            }
+
                             for (client, _) in connectors1.read().unwrap().iter() {
                                 client.do_send(NetworkClientMessages::Block(
                                     block.clone(),
@@ -696,7 +807,7 @@ pub fn setup_mock_all_validators(
         .insert(*genesis_block.read().unwrap().as_ref().unwrap().header().clone().hash(), 0);
     *locked_connectors = ret.clone();
     let value = genesis_block.read().unwrap();
-    (value.clone().unwrap(), ret)
+    (value.clone().unwrap(), ret, block_stats)
 }
 
 /// Sets up ClientActor and ViewClientActor without network.

diff --git a/chain/client/tests/bug_repros.rs b/chain/client/tests/bug_repros.rs
@@ -38,7 +38,7 @@ fn repro_1183() {
         let validators2 = validators.clone();
         let last_block: Arc<RwLock<Option<Block>>> = Arc::new(RwLock::new(None));
         let delayed_one_parts: Arc<RwLock<Vec<NetworkRequests>>> = Arc::new(RwLock::new(vec![]));
-        let (_, conn) = setup_mock_all_validators(
+        let (_, conn, _) = setup_mock_all_validators(
             validators.clone(),
             key_pairs.clone(),
             validator_groups,
@@ -49,6 +49,7 @@ fn repro_1183() {
             5,
             false,
             vec![false; validators.iter().map(|x| x.len()).sum()],
+            false,
             Arc::new(RwLock::new(Box::new(move |_account_id: String, msg: &NetworkRequests| {
                 if let NetworkRequests::Block { block } = msg {
                     let mut last_block = last_block.write().unwrap();
@@ -149,7 +150,7 @@ fn test_sync_from_achival_node() {
         > = Arc::new(RwLock::new(Box::new(|_: String, _: &NetworkRequests| {
             (NetworkResponses::NoResponse, true)
         })));
-        let (_, conns) = setup_mock_all_validators(
+        let (_, conns, _) = setup_mock_all_validators(
             validators.clone(),
             key_pairs,
             1,
@@ -160,6 +161,7 @@ fn test_sync_from_achival_node() {
             epoch_length,
             false,
             vec![true, false, false, false],
+            false,
             network_mock.clone(),
         );
         let mut block_counter = 0;

diff --git a/chain/client/tests/catching_up.rs b/chain/client/tests/catching_up.rs
@@ -135,7 +135,7 @@ mod tests {
             if sync_hold {
                 block_prod_time *= STATE_SYNC_TIMEOUT as u64;
             }
-            let (_, conn) = setup_mock_all_validators(
+            let (_, conn, _) = setup_mock_all_validators(
                 validators.clone(),
                 key_pairs.clone(),
                 validator_groups,
@@ -146,6 +146,7 @@ mod tests {
                 5,
                 false,
                 vec![true; validators.iter().map(|x| x.len()).sum()],
+                false,
                 Arc::new(RwLock::new(Box::new(
                     move |_account_id: String, msg: &NetworkRequests| {
                         let account_from = "test3.3".to_string();
@@ -432,7 +433,7 @@ mod tests {
                 };
 
             let connectors1 = connectors.clone();
-            let (_, conn) = setup_mock_all_validators(
+            let (_, conn, _) = setup_mock_all_validators(
                 validators.clone(),
                 key_pairs.clone(),
                 validator_groups,
@@ -443,6 +444,7 @@ mod tests {
                 5,
                 false,
                 vec![false; validators.iter().map(|x| x.len()).sum()],
+                false,
                 Arc::new(RwLock::new(Box::new(
                     move |_account_id: String, msg: &NetworkRequests| {
                         let mut seen_heights_same_block = seen_heights_same_block.write().unwrap();
@@ -631,7 +633,7 @@ mod tests {
 
             let (validators, key_pairs) = get_validators_and_key_pairs();
 
-            let (_, conn) = setup_mock_all_validators(
+            let (_, conn, _) = setup_mock_all_validators(
                 validators.clone(),
                 key_pairs.clone(),
                 validator_groups,
@@ -642,6 +644,7 @@ mod tests {
                 5,
                 false,
                 vec![false; validators.iter().map(|x| x.len()).sum()],
+                false,
                 Arc::new(RwLock::new(Box::new(
                     move |_account_id: String, msg: &NetworkRequests| {
                         if let NetworkRequests::Block { block } = msg {
@@ -691,7 +694,7 @@ mod tests {
 
             let (validators, key_pairs) = get_validators_and_key_pairs();
 
-            let (_, conn) = setup_mock_all_validators(
+            let (_, conn, _) = setup_mock_all_validators(
                 validators.clone(),
                 key_pairs.clone(),
                 validator_groups,
@@ -702,6 +705,7 @@ mod tests {
                 5,
                 true,
                 vec![false; validators.iter().map(|x| x.len()).sum()],
+                false,
                 Arc::new(RwLock::new(Box::new(
                     move |_account_id: String, msg: &NetworkRequests| {
                         let propagate = if let NetworkRequests::Block { block } = msg {
@@ -764,7 +768,7 @@ mod tests {
             let _connectors1 = connectors.clone();
 
             let block_prod_time: u64 = 1200;
-            let (_, conn) = setup_mock_all_validators(
+            let (_, conn, _) = setup_mock_all_validators(
                 validators.clone(),
                 key_pairs.clone(),
                 validator_groups,
@@ -775,6 +779,7 @@ mod tests {
                 5,
                 true,
                 vec![false; validators.iter().map(|x| x.len()).sum()],
+                false,
                 Arc::new(RwLock::new(Box::new(
                     move |sender_account_id: String, msg: &NetworkRequests| {
                         let mut grieving_chunk_hash = grieving_chunk_hash.write().unwrap();
@@ -917,7 +922,7 @@ mod tests {
             let responded =
                 Arc::new(RwLock::new(HashSet::<(CryptoHash, Vec<u64>, ChunkHash)>::new()));
 
-            let (_, conn) = setup_mock_all_validators(
+            let (_, conn, _) = setup_mock_all_validators(
                 validators.clone(),
                 key_pairs.clone(),
                 validator_groups,
@@ -928,6 +933,7 @@ mod tests {
                 epoch_length,
                 false,
                 vec![false; validators.iter().map(|x| x.len()).sum()],
+                false,
                 Arc::new(RwLock::new(Box::new(
                     move |sender_account_id: String, msg: &NetworkRequests| {
                         let mut seen_chunk_same_sender = seen_chunk_same_sender.write().unwrap();

diff --git a/chain/client/tests/chunks_management.rs b/chain/client/tests/chunks_management.rs
@@ -108,7 +108,7 @@ fn chunks_produced_and_distributed_common(
         let mut partial_chunk_msgs = 0;
         let mut partial_chunk_request_msgs = 0;
 
-        let (_, conn) = setup_mock_all_validators(
+        let (_, conn, _) = setup_mock_all_validators(
             validators.clone(),
             key_pairs.clone(),
             validator_groups,
@@ -119,6 +119,7 @@ fn chunks_produced_and_distributed_common(
             5,
             true,
             vec![false; validators.iter().map(|x| x.len()).sum()],
+            false,
             Arc::new(RwLock::new(Box::new(move |from_whom: String, msg: &NetworkRequests| {
                 match msg {
                     NetworkRequests::Block { block } => {

diff --git a/chain/client/tests/consensus.rs b/chain/client/tests/consensus.rs
@@ -57,7 +57,7 @@ mod tests {
             let largest_block_height = Arc::new(RwLock::new(0u64));
             let delayed_blocks = Arc::new(RwLock::new(vec![]));
 
-            let (_, conn) = setup_mock_all_validators(
+            let (_, conn, _) = setup_mock_all_validators(
                 validators.clone(),
                 key_pairs.clone(),
                 1,
@@ -68,6 +68,7 @@ mod tests {
                 4,
                 true,
                 vec![true; validators.iter().map(|x| x.len()).sum()],
+                false,
                 Arc::new(RwLock::new(Box::new(move |from_whom: String, msg: &NetworkRequests| {
                     let mut all_blocks: RwLockWriteGuard<BTreeMap<BlockHeight, Block>> =
                         all_blocks.write().unwrap();