diff --git a/Cargo.lock b/Cargo.lock index b320b67e..5f041cac 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -6308,6 +6308,7 @@ dependencies = [ "group", "halo2_proofs 0.2.0", "hex", + "humantime", "incrementalmerkletree", "itertools", "jubjub", diff --git a/zebra-chain/Cargo.toml b/zebra-chain/Cargo.toml index 7d484b88..548ca83e 100644 --- a/zebra-chain/Cargo.toml +++ b/zebra-chain/Cargo.toml @@ -13,6 +13,8 @@ proptest-impl = ["proptest", "proptest-derive", "zebra-test", "rand", "rand_chac bench = ["zebra-test"] [dependencies] + +# Cryptography aes = "0.7.5" bech32 = "0.9.0" bitvec = "1.0.1" @@ -22,41 +24,54 @@ blake2s_simd = "1.0.0" bls12_381 = "0.7.0" bs58 = { version = "0.4.0", features = ["check"] } byteorder = "1.4.3" -chrono = { version = "0.4.19", features = ["serde"] } -displaydoc = "0.2.3" +equihash = "0.1.0" fpe = "0.5.1" -futures = "0.3.21" group = "0.12.0" -halo2 = { package = "halo2_proofs", version = "0.2.0" } -hex = { version = "0.4.3", features = ["serde"] } incrementalmerkletree = "0.3.0" -itertools = "0.10.3" jubjub = "0.9.0" lazy_static = "1.4.0" primitive-types = "0.11.1" rand_core = "0.6.3" ripemd = "0.1.1" - -serde = { version = "1.0.137", features = ["serde_derive", "rc"] } -serde_with = "1.14.0" -serde-big-array = "0.4.1" # Matches version used by hdwallet secp256k1 = { version = "0.21.3", features = ["serde"] } sha2 = { version = "0.9.9", features=["compress"] } -static_assertions = "1.1.0" subtle = "2.4.1" -thiserror = "1.0.31" uint = "0.9.1" x25519-dalek = { version = "1.2.0", features = ["serde"] } +# ECC deps +halo2 = { package = "halo2_proofs", version = "0.2.0" } orchard = "0.2.0" - -equihash = "0.1.0" -zcash_note_encryption = "0.1" -zcash_primitives = { version = "0.7.0", features = ["transparent-inputs"] } zcash_encoding = "0.1.0" zcash_history = "0.3.0" +zcash_note_encryption = "0.1" +zcash_primitives = { version = "0.7.0", features = ["transparent-inputs"] } +# Time +chrono = { version = "0.4.19", features = ["serde"] } +humantime = "2.1.0" + +# Error Handling & Formatting +displaydoc = "0.2.3" +static_assertions = "1.1.0" +thiserror = "1.0.31" + +# Serialization +hex = { version = "0.4.3", features = ["serde"] } +serde = { version = "1.0.137", features = ["serde_derive", "rc"] } +serde_with = "1.14.0" +serde-big-array = "0.4.1" + +# Processing +futures = "0.3.21" +itertools = "0.10.3" + +# ZF deps +ed25519-zebra = "3.0.0" +redjubjub = "0.5.0" + +# Optional testing dependencies proptest = { version = "0.10.1", optional = true } proptest-derive = { version = "0.3.0", optional = true } @@ -65,19 +80,19 @@ rand_chacha = { version = "0.3.1", optional = true } tokio = { version = "1.20.0", features = ["tracing"], optional = true } -# ZF deps -ed25519-zebra = "3.0.0" -redjubjub = "0.5.0" - zebra-test = { path = "../zebra-test/", optional = true } [dev-dependencies] -color-eyre = "0.6.1" + +# Benchmarks criterion = { version = "0.3.5", features = ["html_reports"] } -itertools = "0.10.3" + +# Error Handling & Formatting +color-eyre = "0.6.1" spandoc = "0.2.2" tracing = "0.1.31" +# Make the optional testing dependencies required proptest = "0.10.1" proptest-derive = "0.3.0" diff --git a/zebra-chain/src/fmt.rs b/zebra-chain/src/fmt.rs index ff3bbd09..e5fa646c 100644 --- a/zebra-chain/src/fmt.rs +++ b/zebra-chain/src/fmt.rs @@ -7,6 +7,9 @@ use proptest::prelude::*; #[cfg(any(test, feature = "proptest-impl"))] use proptest_derive::Arbitrary; +pub mod time; +pub use time::{humantime_milliseconds, humantime_seconds}; + /// Wrapper to override `Debug`, redirecting it to only output the type's name. #[derive(Copy, Clone, PartialEq, Eq, PartialOrd, Ord, Hash)] #[cfg_attr(any(test, feature = "proptest-impl"), derive(Arbitrary))] diff --git a/zebra-chain/src/fmt/time.rs b/zebra-chain/src/fmt/time.rs new file mode 100644 index 00000000..63a0b0ba --- /dev/null +++ b/zebra-chain/src/fmt/time.rs @@ -0,0 +1,28 @@ +//! Human-readable formats for times and durations. + +use std::time::Duration; + +/// Returns a human-friendly formatted string for the whole number of seconds in `duration`. +pub fn humantime_seconds(duration: impl Into) -> String { + let duration = duration.into(); + + // Truncate fractional seconds. + let duration = Duration::from_secs(duration.as_secs()); + + let duration = humantime::format_duration(duration); + + format!("{}", duration) +} + +/// Returns a human-friendly formatted string for the whole number of milliseconds in `duration`. +pub fn humantime_milliseconds(duration: impl Into) -> String { + let duration = duration.into(); + + // Truncate fractional seconds. + let duration_secs = Duration::from_secs(duration.as_secs()); + let duration_millis = Duration::from_millis(duration.subsec_millis().into()); + + let duration = humantime::format_duration(duration_secs + duration_millis); + + format!("{}", duration) +} diff --git a/zebra-state/src/service/non_finalized_state/chain.rs b/zebra-state/src/service/non_finalized_state/chain.rs index 43379110..0c9f51a3 100644 --- a/zebra-state/src/service/non_finalized_state/chain.rs +++ b/zebra-state/src/service/non_finalized_state/chain.rs @@ -6,6 +6,7 @@ use std::{ collections::{BTreeMap, BTreeSet, HashMap, HashSet}, ops::{Deref, RangeInclusive}, sync::Arc, + time::Instant, }; use mset::MultiSet; @@ -14,6 +15,7 @@ use tracing::instrument; use zebra_chain::{ amount::{Amount, NegativeAllowed, NonNegative}, block::{self, Height}, + fmt::humantime_milliseconds, history_tree::HistoryTree, orchard, parameters::Network, @@ -293,11 +295,28 @@ impl Chain { forked.pop_tip(); } + // Rebuild the note commitment and history trees, starting from the finalized tip tree. + // + // Note commitments and history trees are not removed from the Chain during a fork, + // because we don't support that operation yet. Instead, we recreate the tree + // from the finalized tip. + // + // TODO: remove trees and anchors above the fork, to save CPU time (#4794) + let start_time = Instant::now(); + let rebuilt_block_count = forked.blocks.len(); + let fork_height = forked.non_finalized_tip_height(); + + info!( + ?rebuilt_block_count, + ?fork_height, + ?fork_tip, + "starting to rebuild note commitment trees after a non-finalized chain fork", + ); + let sprout_nct = Arc::make_mut(&mut forked.sprout_note_commitment_tree); let sapling_nct = Arc::make_mut(&mut forked.sapling_note_commitment_tree); let orchard_nct = Arc::make_mut(&mut forked.orchard_note_commitment_tree); - // Rebuild the note commitment trees, starting from the finalized tip tree. for block in forked.blocks.values() { for transaction in block.block.transactions.iter() { for sprout_note_commitment in transaction.sprout_note_commitments() { @@ -339,6 +358,18 @@ impl Chain { )?; } + let rebuild_time = start_time.elapsed(); + let rebuild_time_per_block = + rebuild_time / rebuilt_block_count.try_into().expect("fits in u32"); + info!( + rebuild_time = ?humantime_milliseconds(rebuild_time), + rebuild_time_per_block = ?humantime_milliseconds(rebuild_time_per_block), + ?rebuilt_block_count, + ?fork_height, + ?fork_tip, + "finished rebuilding note commitment trees after a non-finalized chain fork", + ); + Ok(Some(forked)) } @@ -1230,6 +1261,12 @@ impl UpdateWith>> for Chain { _position: RevertPosition, ) { if let Some(joinsplit_data) = joinsplit_data { + // Note commitments are not removed from the Chain during a fork, + // because we don't support that operation yet. Instead, we + // recreate the tree from the finalized tip in Chain::fork(). + // + // TODO: remove trees and anchors above the fork, to save CPU time (#4794) + check::nullifier::remove_from_non_finalized_chain( &mut self.sprout_nullifiers, joinsplit_data.nullifiers(), @@ -1277,9 +1314,11 @@ where _position: RevertPosition, ) { if let Some(sapling_shielded_data) = sapling_shielded_data { - // Note commitments are not removed from the tree here because we - // don't support that operation yet. Instead, we recreate the tree - // from the finalized tip in `NonFinalizedState`. + // Note commitments are not removed from the Chain during a fork, + // because we don't support that operation yet. Instead, we + // recreate the tree from the finalized tip in Chain::fork(). + // + // TODO: remove trees and anchors above the fork, to save CPU time (#4794) check::nullifier::remove_from_non_finalized_chain( &mut self.sapling_nullifiers, @@ -1322,9 +1361,11 @@ impl UpdateWith> for Chain { _position: RevertPosition, ) { if let Some(orchard_shielded_data) = orchard_shielded_data { - // Note commitments are not removed from the tree here because we - // don't support that operation yet. Instead, we recreate the tree - // from the finalized tip in NonFinalizedState. + // Note commitments are not removed from the Chain during a fork, + // because we don't support that operation yet. Instead, we + // recreate the tree from the finalized tip in Chain::fork(). + // + // TODO: remove trees and anchors above the fork, to save CPU time (#4794) check::nullifier::remove_from_non_finalized_chain( &mut self.orchard_nullifiers, diff --git a/zebrad/src/components/sync/progress.rs b/zebrad/src/components/sync/progress.rs index e8240dcc..43b51f06 100644 --- a/zebrad/src/components/sync/progress.rs +++ b/zebrad/src/components/sync/progress.rs @@ -8,11 +8,12 @@ use num_integer::div_ceil; use zebra_chain::{ block::Height, chain_tip::ChainTip, + fmt::humantime_seconds, parameters::{Network, NetworkUpgrade, POST_BLOSSOM_POW_TARGET_SPACING}, }; use zebra_consensus::CheckpointList; -use crate::components::{sync::SyncStatus, tracing::humantime_seconds}; +use crate::components::sync::SyncStatus; /// The amount of time between progress logs. const LOG_INTERVAL: Duration = Duration::from_secs(60); diff --git a/zebrad/src/components/tracing.rs b/zebrad/src/components/tracing.rs index 778cc1fc..d78739cb 100644 --- a/zebrad/src/components/tracing.rs +++ b/zebrad/src/components/tracing.rs @@ -2,14 +2,12 @@ mod component; mod endpoint; -mod fmt; #[cfg(feature = "flamegraph")] mod flame; pub use component::Tracing; pub use endpoint::TracingEndpoint; -pub use fmt::humantime_seconds; #[cfg(feature = "flamegraph")] pub use flame::{layer, Grapher}; diff --git a/zebrad/src/components/tracing/fmt.rs b/zebrad/src/components/tracing/fmt.rs deleted file mode 100644 index e6825618..00000000 --- a/zebrad/src/components/tracing/fmt.rs +++ /dev/null @@ -1,15 +0,0 @@ -//! Formatting for traced values. - -use std::time::Duration; - -/// Returns a human-friendly formatted string for `duration.as_secs()`. -pub fn humantime_seconds(duration: impl Into) -> String { - let duration = duration.into(); - - // Truncate fractional seconds. - let duration = Duration::from_secs(duration.as_secs()); - - let duration = humantime::format_duration(duration); - - format!("{}", duration) -}