diff --git a/zebra-state/src/service.rs b/zebra-state/src/service.rs index 6a38c2a49..793a4cd95 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 5a310fd0e..ed5bdc085 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 e04094e94..821d42540 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 a95b65cc2..ac36cff29 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