From f745333ff217277294ad65d76ad5c3282c4e24bf Mon Sep 17 00:00:00 2001 From: teor Date: Fri, 9 Jul 2021 22:47:09 +1000 Subject: [PATCH] Use the block verifier and non-finalized state in the cached state tests (#2463) * Use the block verifier and non-finalized state in the cached state tests This substantially increases test coverage. Previously, the cached state tests were configured with `checkpoint_sync = true`, which only uses the checkpoint verifier and the finalized state. * Log the source of blocks in commit_finalized_direct This lets us check that we're actually testing the non-finalized state and block verifier in the cached state tests. It also improves diagnostics for state errors. * Fail cached state tests if they're using incorrect heights or configs This makes sure that the cached state tests actually test the transition from checkpoint to block verification, and the non-finalized state. --- zebra-state/src/service.rs | 2 +- zebra-state/src/service/finalized_state.rs | 20 +++++++--- .../src/service/finalized_state/tests/prop.rs | 5 ++- zebrad/tests/acceptance.rs | 39 +++++++++++++++++-- 4 files changed, 55 insertions(+), 11 deletions(-) diff --git a/zebra-state/src/service.rs b/zebra-state/src/service.rs index 6a38c2a4..793a4cd9 100644 --- a/zebra-state/src/service.rs +++ b/zebra-state/src/service.rs @@ -158,7 +158,7 @@ impl StateService { tracing::trace!("finalizing block past the reorg limit"); let finalized = self.mem.finalize(); self.disk - .commit_finalized_direct(finalized) + .commit_finalized_direct(finalized, "best non-finalized chain root") .expect("expected that disk errors would not occur"); } diff --git a/zebra-state/src/service/finalized_state.rs b/zebra-state/src/service/finalized_state.rs index 5a310fd0..ed5bdc08 100644 --- a/zebra-state/src/service/finalized_state.rs +++ b/zebra-state/src/service/finalized_state.rs @@ -177,9 +177,12 @@ impl FinalizedState { } /// Immediately commit `finalized` to the finalized state. + /// + /// Use `source` as the source of the block in log messages. pub fn commit_finalized_direct( &mut self, finalized: FinalizedBlock, + source: &str, ) -> Result { block_precommit_metrics(&finalized); @@ -204,12 +207,14 @@ impl FinalizedState { if self.is_empty(hash_by_height) { assert_eq!( GENESIS_PREVIOUS_BLOCK_HASH, block.header.previous_block_hash, - "the first block added to an empty state must be a genesis block" + "the first block added to an empty state must be a genesis block, source: {}", + source, ); assert_eq!( block::Height(0), height, - "cannot commit genesis: invalid height" + "cannot commit genesis: invalid height, source: {}", + source, ); } else { assert_eq!( @@ -217,13 +222,15 @@ impl FinalizedState { .expect("state must have a genesis block committed") + 1, Some(height), - "committed block height must be 1 more than the finalized tip height" + "committed block height must be 1 more than the finalized tip height, source: {}", + source, ); assert_eq!( self.finalized_tip_hash(), block.header.previous_block_hash, - "committed block must be a child of the finalized tip" + "committed block must be a child of the finalized tip, source: {}", + source, ); } @@ -297,7 +304,10 @@ impl FinalizedState { let result = self.db.write(batch).map(|()| hash); + tracing::trace!(?source, "committed block from"); + if result.is_ok() && self.is_at_stop_height(height) { + tracing::info!(?source, "committed block from"); tracing::info!(?height, ?hash, "stopping at configured height"); // We'd like to drop the database here, because that closes the // column families and the database. But Rust's ownership rules @@ -318,7 +328,7 @@ impl FinalizedState { /// [`FinalizedState`]. fn commit_finalized(&mut self, queued_block: QueuedFinalized) { let (finalized, rsp_tx) = queued_block; - let result = self.commit_finalized_direct(finalized); + let result = self.commit_finalized_direct(finalized, "CommitFinalized request"); let _ = rsp_tx.send(result.map_err(Into::into)); } diff --git a/zebra-state/src/service/finalized_state/tests/prop.rs b/zebra-state/src/service/finalized_state/tests/prop.rs index e04094e9..821d4254 100644 --- a/zebra-state/src/service/finalized_state/tests/prop.rs +++ b/zebra-state/src/service/finalized_state/tests/prop.rs @@ -25,7 +25,10 @@ fn blocks_with_v5_transactions() -> Result<()> { let mut height = Height(0); // use `count` to minimize test failures, so they are easier to diagnose for block in chain.iter().take(count) { - let hash = state.commit_finalized_direct(FinalizedBlock::from(block.clone())); + let hash = state.commit_finalized_direct( + FinalizedBlock::from(block.clone()), + "blocks_with_v5_transactions test" + ); prop_assert_eq!(Some(height), state.finalized_tip_height()); prop_assert_eq!(hash.unwrap(), block.hash); // TODO: check that the nullifiers were correctly inserted (#2230) diff --git a/zebrad/tests/acceptance.rs b/zebrad/tests/acceptance.rs index a95b65cc..ac36cff2 100644 --- a/zebrad/tests/acceptance.rs +++ b/zebrad/tests/acceptance.rs @@ -858,12 +858,26 @@ fn sync_until( fn cached_mandatory_checkpoint_test_config() -> Result { let mut config = persistent_test_config()?; - config.consensus.checkpoint_sync = true; config.state.cache_dir = "/zebrad-cache".into(); Ok(config) } -fn create_cached_database_height(network: Network, height: Height) -> Result<()> { +/// Create or update a cached state for `network`, stopping at `height`. +/// +/// Callers can supply an extra `test_child_predicate`, which is called on +/// the `TestChild` between the startup checks, and the final +/// `STOP_AT_HEIGHT_REGEX` check. +/// +/// The `TestChild` is spawned with a timeout, so the predicate should use +/// `expect_stdout_line_matches` or `expect_stderr_line_matches`. +fn create_cached_database_height

( + network: Network, + height: Height, + test_child_predicate: impl Into>, +) -> Result<()> +where + P: FnOnce(&mut TestChild) -> Result<()>, +{ println!("Creating cached database"); // 8 hours let timeout = Duration::from_secs(60 * 60 * 8); @@ -887,6 +901,10 @@ fn create_cached_database_height(network: Network, height: Height) -> Result<()> child.expect_stdout_line_matches("starting legacy chain check")?; child.expect_stdout_line_matches("no legacy chain found")?; + if let Some(test_child_predicate) = test_child_predicate.into() { + test_child_predicate(&mut child)?; + } + child.expect_stdout_line_matches(STOP_AT_HEIGHT_REGEX)?; child.kill()?; @@ -896,12 +914,25 @@ fn create_cached_database_height(network: Network, height: Height) -> Result<()> fn create_cached_database(network: Network) -> Result<()> { let height = network.mandatory_checkpoint_height(); - create_cached_database_height(network, height) + create_cached_database_height(network, height, |test_child: &mut TestChild| { + // make sure pre-cached databases finish before the mandatory checkpoint + test_child.expect_stdout_line_matches("CommitFinalized request")?; + Ok(()) + }) } fn sync_past_mandatory_checkpoint(network: Network) -> Result<()> { let height = network.mandatory_checkpoint_height() + 1200; - create_cached_database_height(network, height.unwrap()) + create_cached_database_height( + network, + height.unwrap(), + |test_child: &mut TestChild| { + // make sure cached database tests finish after the mandatory checkpoint, + // using the non-finalized state (the checkpoint_sync config must be false) + test_child.expect_stdout_line_matches("best non-finalized chain root")?; + Ok(()) + }, + ) } // These tests are ignored because they're too long running to run during our