diff --git a/examples/Cargo.toml b/examples/Cargo.toml index b4e4860ee..0ef457282 100644 --- a/examples/Cargo.toml +++ b/examples/Cargo.toml @@ -23,17 +23,18 @@ doc = false [features] concurrent = ["winterfell/concurrent", "std"] default = ["std"] -std = ["hex/std", "winterfell/std", "core-utils/std", "rand-utils"] +std = ["core-utils/std", "hex/std", "rand-utils", "winterfell/std"] [dependencies] -winterfell = { version="0.7", path = "../winterfell", default-features = false } +blake3 = { version = "1.5", default-features = false } core-utils = { version = "0.7", path = "../utils/core", package = "winter-utils", default-features = false } -rand-utils = { version = "0.7", path = "../utils/rand", package = "winter-rand-utils", optional = true } hex = { version = "0.4", optional = true } -log = { version = "0.4", default-features = false } -blake3 = { version = "1.5", default-features = false } -env_logger = { version = "0.10", default-features = false } +rand-utils = { version = "0.7", path = "../utils/rand", package = "winter-rand-utils", optional = true } structopt = { version = "0.3", default-features = false } +tracing = { version = "0.1", default-features = false } +tracing-subscriber = { version = "0.3", features = ["std", "env-filter"] } +tracing-forest = { version = "0.1", features = ["ansi", "smallvec"], optional = true } +winterfell = { version="0.7", path = "../winterfell", default-features = false } [dev-dependencies] criterion = "0.5" diff --git a/examples/src/fibonacci/fib2/mod.rs b/examples/src/fibonacci/fib2/mod.rs index 85dd78b86..c97ef8fde 100644 --- a/examples/src/fibonacci/fib2/mod.rs +++ b/examples/src/fibonacci/fib2/mod.rs @@ -6,8 +6,8 @@ use super::utils::compute_fib_term; use crate::{Blake3_192, Blake3_256, Example, ExampleOptions, HashFunction, Sha3_256}; use core::marker::PhantomData; -use log::debug; use std::time::Instant; +use tracing::{field, info_span}; use winterfell::{ crypto::{DefaultRandomCoin, ElementHasher}, math::{fields::f128::BaseElement, FieldElement}, @@ -65,7 +65,7 @@ impl FibExample { // compute Fibonacci sequence let now = Instant::now(); let result = compute_fib_term(sequence_length); - debug!( + println!( "Computed Fibonacci sequence up to {}th term in {} ms", sequence_length, now.elapsed().as_millis() @@ -88,9 +88,8 @@ where H: ElementHasher, { fn prove(&self) -> StarkProof { - debug!( - "Generating proof for computing Fibonacci sequence (2 terms per step) up to {}th term\n\ - ---------------------", + println!( + "Generating proof for computing Fibonacci sequence (2 terms per step) up to {}th term", self.sequence_length ); @@ -98,17 +97,13 @@ where let prover = FibProver::::new(self.options.clone()); // generate execution trace - let now = Instant::now(); - let trace = prover.build_trace(self.sequence_length); - - let trace_width = trace.width(); - let trace_length = trace.length(); - debug!( - "Generated execution trace of {} registers and 2^{} steps in {} ms", - trace_width, - trace_length.ilog2(), - now.elapsed().as_millis() - ); + let trace = + info_span!("generate_execution_trace", num_cols = TRACE_WIDTH, steps = field::Empty) + .in_scope(|| { + let trace = prover.build_trace(self.sequence_length); + tracing::Span::current().record("steps", trace.length()); + trace + }); // generate the proof prover.prove(trace).unwrap() diff --git a/examples/src/fibonacci/fib8/mod.rs b/examples/src/fibonacci/fib8/mod.rs index d639fa692..866c4a084 100644 --- a/examples/src/fibonacci/fib8/mod.rs +++ b/examples/src/fibonacci/fib8/mod.rs @@ -6,8 +6,8 @@ use super::utils::compute_fib_term; use crate::{Blake3_192, Blake3_256, Example, ExampleOptions, HashFunction, Sha3_256}; use core::marker::PhantomData; -use log::debug; use std::time::Instant; +use tracing::{field, info_span}; use winterfell::{ crypto::{DefaultRandomCoin, ElementHasher}, math::{fields::f128::BaseElement, FieldElement}, @@ -65,7 +65,7 @@ impl Fib8Example { // compute Fibonacci sequence let now = Instant::now(); let result = compute_fib_term(sequence_length); - debug!( + println!( "Computed Fibonacci sequence up to {}th term in {} ms", sequence_length, now.elapsed().as_millis() @@ -88,9 +88,8 @@ where H: ElementHasher, { fn prove(&self) -> StarkProof { - debug!( - "Generating proof for computing Fibonacci sequence (8 terms per step) up to {}th term\n\ - ---------------------", + println!( + "Generating proof for computing Fibonacci sequence (8 terms per step) up to {}th term", self.sequence_length ); @@ -98,16 +97,13 @@ where let prover = Fib8Prover::::new(self.options.clone()); // generate execution trace - let now = Instant::now(); - let trace = prover.build_trace(self.sequence_length); - let trace_width = trace.width(); - let trace_length = trace.length(); - debug!( - "Generated execution trace of {} registers and 2^{} steps in {} ms", - trace_width, - trace_length.ilog2(), - now.elapsed().as_millis() - ); + let trace = + info_span!("generate_execution_trace", num_cols = TRACE_WIDTH, steps = field::Empty) + .in_scope(|| { + let trace = prover.build_trace(self.sequence_length); + tracing::Span::current().record("steps", trace.length()); + trace + }); // generate the proof prover.prove(trace).unwrap() diff --git a/examples/src/fibonacci/fib_small/mod.rs b/examples/src/fibonacci/fib_small/mod.rs index 26484787b..5b149a42f 100644 --- a/examples/src/fibonacci/fib_small/mod.rs +++ b/examples/src/fibonacci/fib_small/mod.rs @@ -6,8 +6,8 @@ use super::utils::compute_fib_term; use crate::{Example, ExampleOptions, HashFunction}; use core::marker::PhantomData; -use log::debug; use std::time::Instant; +use tracing::{field, info_span}; use winterfell::{ crypto::{DefaultRandomCoin, ElementHasher}, math::{fields::f64::BaseElement, FieldElement}, @@ -80,7 +80,7 @@ impl FibExample { // compute Fibonacci sequence let now = Instant::now(); let result = compute_fib_term::(sequence_length); - debug!( + println!( "Computed Fibonacci sequence up to {}th term in {} ms", sequence_length, now.elapsed().as_millis() @@ -103,9 +103,8 @@ where H: ElementHasher, { fn prove(&self) -> StarkProof { - debug!( - "Generating proof for computing Fibonacci sequence (2 terms per step) up to {}th term\n\ - ---------------------", + println!( + "Generating proof for computing Fibonacci sequence (2 terms per step) up to {}th term", self.sequence_length ); @@ -113,17 +112,13 @@ where let prover = FibSmallProver::::new(self.options.clone()); // generate execution trace - let now = Instant::now(); - let trace = prover.build_trace(self.sequence_length); - - let trace_width = trace.width(); - let trace_length = trace.length(); - debug!( - "Generated execution trace of {} registers and 2^{} steps in {} ms", - trace_width, - trace_length.ilog2(), - now.elapsed().as_millis() - ); + let trace = + info_span!("generate_execution_trace", num_cols = TRACE_WIDTH, steps = field::Empty) + .in_scope(|| { + let trace = prover.build_trace(self.sequence_length); + tracing::Span::current().record("steps", trace.length()); + trace + }); // generate the proof prover.prove(trace).unwrap() @@ -132,6 +127,7 @@ where fn verify(&self, proof: StarkProof) -> Result<(), VerifierError> { let acceptable_options = winterfell::AcceptableOptions::OptionSet(vec![proof.options().clone()]); + winterfell::verify::>( proof, self.result, diff --git a/examples/src/fibonacci/mulfib2/air.rs b/examples/src/fibonacci/mulfib2/air.rs index 403e9e4bd..3f32b4b35 100644 --- a/examples/src/fibonacci/mulfib2/air.rs +++ b/examples/src/fibonacci/mulfib2/air.rs @@ -3,6 +3,7 @@ // This source code is licensed under the MIT license found in the // LICENSE file in the root directory of this source tree. +use super::TRACE_WIDTH; use crate::utils::are_equal; use winterfell::{ math::{fields::f128::BaseElement, FieldElement}, @@ -13,8 +14,6 @@ use winterfell::{ // FIBONACCI AIR // ================================================================================================ -const TRACE_WIDTH: usize = 2; - pub struct MulFib2Air { context: AirContext, result: BaseElement, diff --git a/examples/src/fibonacci/mulfib2/mod.rs b/examples/src/fibonacci/mulfib2/mod.rs index 214828d2e..8abf025dc 100644 --- a/examples/src/fibonacci/mulfib2/mod.rs +++ b/examples/src/fibonacci/mulfib2/mod.rs @@ -6,8 +6,8 @@ use super::utils::compute_mulfib_term; use crate::{Blake3_192, Blake3_256, Example, ExampleOptions, HashFunction, Sha3_256}; use core::marker::PhantomData; -use log::debug; use std::time::Instant; +use tracing::{field, info_span}; use winterfell::{ crypto::{DefaultRandomCoin, ElementHasher}, math::{fields::f128::BaseElement, FieldElement}, @@ -23,6 +23,11 @@ use prover::MulFib2Prover; #[cfg(test)] mod tests; +// CONSTANTS +// ================================================================================================ + +const TRACE_WIDTH: usize = 2; + // FIBONACCI EXAMPLE // ================================================================================================ @@ -59,7 +64,7 @@ impl MulFib2Example { // compute Fibonacci sequence let now = Instant::now(); let result = compute_mulfib_term(sequence_length); - debug!( + println!( "Computed multiplicative Fibonacci sequence up to {}th term in {} ms", sequence_length, now.elapsed().as_millis() @@ -83,9 +88,8 @@ where { fn prove(&self) -> StarkProof { let sequence_length = self.sequence_length; - debug!( - "Generating proof for computing multiplicative Fibonacci sequence (8 terms per step) up to {}th term\n\ - ---------------------", + println!( + "Generating proof for computing multiplicative Fibonacci sequence (2 terms per step) up to {}th term", sequence_length ); @@ -93,16 +97,13 @@ where let prover = MulFib2Prover::::new(self.options.clone()); // generate execution trace - let now = Instant::now(); - let trace = prover.build_trace(sequence_length); - let trace_width = trace.width(); - let trace_length = trace.length(); - debug!( - "Generated execution trace of {} registers and 2^{} steps in {} ms", - trace_width, - trace_length.ilog2(), - now.elapsed().as_millis() - ); + let trace = + info_span!("generate_execution_trace", num_cols = TRACE_WIDTH, steps = field::Empty) + .in_scope(|| { + let trace = prover.build_trace(sequence_length); + tracing::Span::current().record("steps", trace.length()); + trace + }); // generate the proof prover.prove(trace).unwrap() diff --git a/examples/src/fibonacci/mulfib8/air.rs b/examples/src/fibonacci/mulfib8/air.rs index 4d16add1b..862e912ac 100644 --- a/examples/src/fibonacci/mulfib8/air.rs +++ b/examples/src/fibonacci/mulfib8/air.rs @@ -3,6 +3,7 @@ // This source code is licensed under the MIT license found in the // LICENSE file in the root directory of this source tree. +use super::TRACE_WIDTH; use crate::utils::are_equal; use winterfell::{ math::{fields::f128::BaseElement, FieldElement}, @@ -13,8 +14,6 @@ use winterfell::{ // FIBONACCI AIR // ================================================================================================ -const TRACE_WIDTH: usize = 8; - pub struct MulFib8Air { context: AirContext, result: BaseElement, diff --git a/examples/src/fibonacci/mulfib8/mod.rs b/examples/src/fibonacci/mulfib8/mod.rs index 7ca3a398b..b9763761a 100644 --- a/examples/src/fibonacci/mulfib8/mod.rs +++ b/examples/src/fibonacci/mulfib8/mod.rs @@ -6,8 +6,8 @@ use super::utils::compute_mulfib_term; use crate::{Blake3_192, Blake3_256, Example, ExampleOptions, HashFunction, Sha3_256}; use core::marker::PhantomData; -use log::debug; use std::time::Instant; +use tracing::{field, info_span}; use winterfell::{ crypto::{DefaultRandomCoin, ElementHasher}, math::{fields::f128::BaseElement, FieldElement}, @@ -23,6 +23,11 @@ use prover::MulFib8Prover; #[cfg(test)] mod tests; +// CONSTANTS +// ================================================================================================ + +const TRACE_WIDTH: usize = 8; + // FIBONACCI EXAMPLE // ================================================================================================ @@ -60,7 +65,7 @@ impl MulFib8Example { // compute Fibonacci sequence let now = Instant::now(); let result = compute_mulfib_term(sequence_length); - debug!( + println!( "Computed multiplicative Fibonacci sequence up to {}th term in {} ms", sequence_length, now.elapsed().as_millis() @@ -84,9 +89,8 @@ where { fn prove(&self) -> StarkProof { let sequence_length = self.sequence_length; - debug!( - "Generating proof for computing multiplicative Fibonacci sequence (2 terms per step) up to {}th term\n\ - ---------------------", + println!( + "Generating proof for computing multiplicative Fibonacci sequence (8 terms per step) up to {}th term", sequence_length ); @@ -94,16 +98,13 @@ where let prover = MulFib8Prover::::new(self.options.clone()); // generate execution trace - let now = Instant::now(); - let trace = prover.build_trace(sequence_length); - let trace_width = trace.width(); - let trace_length = trace.length(); - debug!( - "Generated execution trace of {} registers and 2^{} steps in {} ms", - trace_width, - trace_length.ilog2(), - now.elapsed().as_millis() - ); + let trace = + info_span!("generate_execution_trace", num_cols = TRACE_WIDTH, steps = field::Empty) + .in_scope(|| { + let trace = prover.build_trace(sequence_length); + tracing::Span::current().record("steps", trace.length()); + trace + }); // generate the proof prover.prove(trace).unwrap() diff --git a/examples/src/lamport/aggregate/mod.rs b/examples/src/lamport/aggregate/mod.rs index 7b49ad261..765c4896d 100644 --- a/examples/src/lamport/aggregate/mod.rs +++ b/examples/src/lamport/aggregate/mod.rs @@ -8,8 +8,8 @@ use super::{ }; use crate::{Blake3_192, Blake3_256, ExampleOptions, HashFunction, Sha3_256}; use core::marker::PhantomData; -use log::debug; use std::time::Instant; +use tracing::{field, info_span}; use winterfell::{ crypto::{DefaultRandomCoin, ElementHasher}, math::{fields::f128::BaseElement, get_power_series, FieldElement, StarkField}, @@ -69,7 +69,7 @@ impl LamportAggregateExample { private_keys.push(PrivateKey::from_seed([i as u8; 32])); public_keys.push(private_keys[i].pub_key().to_elements()); } - debug!( + println!( "Generated {} private-public key pairs in {} ms", num_signatures, now.elapsed().as_millis() @@ -84,7 +84,7 @@ impl LamportAggregateExample { signatures.push(private_key.sign(msg.as_bytes())); messages.push(message_to_elements(msg.as_bytes())); } - debug!("Signed {} messages in {} ms", num_signatures, now.elapsed().as_millis()); + println!("Signed {} messages in {} ms", num_signatures, now.elapsed().as_millis()); // verify signature let now = Instant::now(); @@ -95,7 +95,7 @@ impl LamportAggregateExample { let msg = format!("test message {i}"); assert!(pk.verify(msg.as_bytes(), signature)); } - debug!("Verified {} signature in {} ms", num_signatures, now.elapsed().as_millis()); + println!("Verified {} signature in {} ms", num_signatures, now.elapsed().as_millis()); LamportAggregateExample { options, @@ -116,25 +116,20 @@ where { fn prove(&self) -> StarkProof { // generate the execution trace - debug!( - "Generating proof for verifying {} Lamport+ signatures \n\ - ---------------------", - self.signatures.len(), - ); + println!("Generating proof for verifying {} Lamport+ signatures", self.signatures.len()); // create a prover let prover = LamportAggregateProver::::new(&self.pub_keys, &self.messages, self.options.clone()); - let now = Instant::now(); - let trace = prover.build_trace(&self.messages, &self.signatures); - let trace_length = trace.length(); - debug!( - "Generated execution trace of {} registers and 2^{} steps in {} ms", - trace.width(), - trace_length.ilog2(), - now.elapsed().as_millis() - ); + // generate execution trace + let trace = + info_span!("generate_execution_trace", num_cols = TRACE_WIDTH, steps = field::Empty) + .in_scope(|| { + let trace = prover.build_trace(&self.messages, &self.signatures); + tracing::Span::current().record("steps", trace.length()); + trace + }); // generate the proof prover.prove(trace).unwrap() diff --git a/examples/src/lamport/threshold/mod.rs b/examples/src/lamport/threshold/mod.rs index 3c2f84ce6..092433f07 100644 --- a/examples/src/lamport/threshold/mod.rs +++ b/examples/src/lamport/threshold/mod.rs @@ -9,8 +9,8 @@ use super::{ }; use crate::{Blake3_192, Blake3_256, ExampleOptions, HashFunction, Sha3_256}; use core::marker::PhantomData; -use log::debug; use std::time::Instant; +use tracing::{field, info_span}; use winterfell::{ crypto::{DefaultRandomCoin, ElementHasher}, math::{fields::f128::BaseElement, get_power_series, FieldElement, StarkField}, @@ -72,7 +72,7 @@ impl LamportThresholdExample { // generate private/public key pairs for the specified number of signatures let now = Instant::now(); let private_keys = build_keys(num_signers); - debug!( + println!( "Generated {} private-public key pairs in {} ms", num_signers, now.elapsed().as_millis() @@ -91,7 +91,7 @@ impl LamportThresholdExample { // build the aggregated public key let now = Instant::now(); let pub_key = AggPublicKey::new(public_keys); - debug!("Built aggregated public key in {} ms", now.elapsed().as_millis()); + println!("Built aggregated public key in {} ms", now.elapsed().as_millis()); let (options, _) = options.to_proof_options(28, 8); @@ -114,9 +114,8 @@ where { fn prove(&self) -> StarkProof { // generate the execution trace - debug!( - "Generating proof for verifying {}-of-{} signature \n\ - ---------------------", + println!( + "Generating proof for verifying {}-of-{} signature", self.signatures.len(), self.pub_key.num_keys(), ); @@ -130,15 +129,13 @@ where ); // generate execution trace - let now = Instant::now(); - let trace = prover.build_trace(&self.pub_key, self.message, &self.signatures); - let trace_length = trace.length(); - debug!( - "Generated execution trace of {} registers and 2^{} steps in {} ms", - trace.width(), - trace_length.ilog2(), - now.elapsed().as_millis() - ); + let trace = + info_span!("generate_execution_trace", num_cols = TRACE_WIDTH, steps = field::Empty) + .in_scope(|| { + let trace = prover.build_trace(&self.pub_key, self.message, &self.signatures); + tracing::Span::current().record("steps", trace.length()); + trace + }); // generate the proof prover.prove(trace).unwrap() diff --git a/examples/src/main.rs b/examples/src/main.rs index 97ff87bcc..f406d9975 100644 --- a/examples/src/main.rs +++ b/examples/src/main.rs @@ -3,10 +3,14 @@ // This source code is licensed under the MIT license found in the // LICENSE file in the root directory of this source tree. -use log::debug; -use std::io::Write; use std::time::Instant; use structopt::StructOpt; +use tracing::info_span; +#[cfg(feature = "tracing-forest")] +use tracing_forest::ForestLayer; +#[cfg(not(feature = "tracing-forest"))] +use tracing_subscriber::fmt::format::FmtSpan; +use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt, EnvFilter}; use winterfell::StarkProof; use examples::{fibonacci, rescue, vdf, ExampleOptions, ExampleType}; @@ -18,16 +22,32 @@ use examples::{lamport, merkle, rescue_raps}; fn main() { // configure logging - env_logger::Builder::new() - .format(|buf, record| writeln!(buf, "{}", record.args())) - .filter_level(log::LevelFilter::Debug) - .init(); + if std::env::var("WINTER_LOG").is_err() { + std::env::set_var("WINTER_LOG", "info"); + } + let registry = + tracing_subscriber::registry::Registry::default().with(EnvFilter::from_env("WINTER_LOG")); + + #[cfg(feature = "tracing-forest")] + registry.with(ForestLayer::default()).init(); + + #[cfg(not(feature = "tracing-forest"))] + { + let format = tracing_subscriber::fmt::layer() + .with_level(false) + .with_target(false) + .with_thread_names(false) + .with_span_events(FmtSpan::CLOSE) + .with_ansi(false) + .with_timer(tracing_subscriber::fmt::time::SystemTime) + .compact(); + + registry.with(format).init(); + } // read command-line args let options = ExampleOptions::from_args(); - debug!("============================================================"); - // instantiate and prepare the example let example = match options.example { ExampleType::Fib { sequence_length } => { @@ -67,37 +87,35 @@ fn main() { // generate proof let now = Instant::now(); - let example = example.as_ref(); - let proof = example.prove(); - debug!("---------------------\nProof generated in {} ms", now.elapsed().as_millis()); + let proof = info_span!("generate_proof").in_scope(|| example.as_ref().prove()); + println!("---------------------\nProof generated in {} ms", now.elapsed().as_millis()); let proof_bytes = proof.to_bytes(); - debug!("Proof size: {:.1} KB", proof_bytes.len() as f64 / 1024f64); + println!("Proof size: {:.1} KB", proof_bytes.len() as f64 / 1024f64); let conjectured_security_level = options.get_proof_security_level(&proof, true); #[cfg(feature = "std")] { let proven_security_level = options.get_proof_security_level(&proof, false); - debug!( + println!( "Proof security: {} bits ({} proven)", conjectured_security_level, proven_security_level, ); } #[cfg(not(feature = "std"))] - debug!("Proof security: {} bits", conjectured_security_level); + println!("Proof security: {} bits", conjectured_security_level); #[cfg(feature = "std")] - debug!("Proof hash: {}", hex::encode(blake3::hash(&proof_bytes).as_bytes())); + println!("Proof hash: {}", hex::encode(blake3::hash(&proof_bytes).as_bytes())); // verify the proof - debug!("---------------------"); + println!("---------------------"); let parsed_proof = StarkProof::from_bytes(&proof_bytes).unwrap(); assert_eq!(proof, parsed_proof); let now = Instant::now(); match example.verify(proof) { - Ok(_) => debug!("Proof verified in {:.1} ms", now.elapsed().as_micros() as f64 / 1000f64), - Err(msg) => debug!("Failed to verify proof: {}", msg), + Ok(_) => println!("Proof verified in {:.1} ms", now.elapsed().as_micros() as f64 / 1000f64), + Err(msg) => println!("Failed to verify proof: {}", msg), } - debug!("============================================================"); } diff --git a/examples/src/merkle/mod.rs b/examples/src/merkle/mod.rs index 6aff9d9cc..d99d0dd78 100644 --- a/examples/src/merkle/mod.rs +++ b/examples/src/merkle/mod.rs @@ -12,9 +12,9 @@ use crate::{ Blake3_192, Blake3_256, Example, ExampleOptions, HashFunction, Sha3_256, }; use core::marker::PhantomData; -use log::debug; use rand_utils::{rand_value, rand_vector}; use std::time::Instant; +use tracing::{field, info_span}; use winterfell::{ crypto::{DefaultRandomCoin, Digest, ElementHasher, MerkleTree}, math::{fields::f128::BaseElement, FieldElement, StarkField}, @@ -77,12 +77,12 @@ impl MerkleExample { // build Merkle tree of the specified depth let now = Instant::now(); let tree = build_merkle_tree(tree_depth, value, index); - debug!("Built Merkle tree of depth {} in {} ms", tree_depth, now.elapsed().as_millis(),); + println!("Built Merkle tree of depth {} in {} ms", tree_depth, now.elapsed().as_millis(),); // compute Merkle path form the leaf specified by the index let now = Instant::now(); let path = tree.prove(index).unwrap(); - debug!( + println!( "Computed Merkle path from leaf {} to root {} in {} ms", index, hex::encode(tree.root().as_bytes()), @@ -109,24 +109,21 @@ where { fn prove(&self) -> StarkProof { // generate the execution trace - debug!( - "Generating proof for proving membership in a Merkle tree of depth {}\n\ - ---------------------", + println!( + "Generating proof for proving membership in a Merkle tree of depth {}", self.path.len() ); // create the prover let prover = MerkleProver::::new(self.options.clone()); - // generate the execution trace - let now = Instant::now(); - let trace = prover.build_trace(self.value, &self.path, self.index); - let trace_length = trace.length(); - debug!( - "Generated execution trace of {} registers and 2^{} steps in {} ms", - trace.width(), - trace_length.ilog2(), - now.elapsed().as_millis() - ); + // generate execution trace + let trace = + info_span!("generate_execution_trace", num_cols = TRACE_WIDTH, steps = field::Empty) + .in_scope(|| { + let trace = prover.build_trace(self.value, &self.path, self.index); + tracing::Span::current().record("steps", trace.length()); + trace + }); // generate the proof prover.prove(trace).unwrap() diff --git a/examples/src/rescue/mod.rs b/examples/src/rescue/mod.rs index 67cf793d6..9f79fec96 100644 --- a/examples/src/rescue/mod.rs +++ b/examples/src/rescue/mod.rs @@ -5,8 +5,8 @@ use crate::{Blake3_192, Blake3_256, Example, ExampleOptions, HashFunction, Sha3_256}; use core::marker::PhantomData; -use log::debug; use std::time::Instant; +use tracing::{field, info_span}; use winterfell::{ crypto::{DefaultRandomCoin, ElementHasher}, math::{fields::f128::BaseElement, FieldElement}, @@ -71,7 +71,7 @@ impl RescueExample { // compute the sequence of hashes using external implementation of Rescue hash let now = Instant::now(); let result = compute_hash_chain(seed, chain_length); - debug!( + println!( "Computed a chain of {} Rescue hashes in {} ms", chain_length, now.elapsed().as_millis(), @@ -96,25 +96,19 @@ where { fn prove(&self) -> StarkProof { // generate the execution trace - debug!( - "Generating proof for computing a chain of {} Rescue hashes\n\ - ---------------------", - self.chain_length - ); + println!("Generating proof for computing a chain of {} Rescue hashes", self.chain_length); // create a prover let prover = RescueProver::::new(self.options.clone()); - // generate the execution trace - let now = Instant::now(); - let trace = prover.build_trace(self.seed, self.chain_length); - let trace_length = trace.length(); - debug!( - "Generated execution trace of {} registers and 2^{} steps in {} ms", - trace.width(), - trace_length.ilog2(), - now.elapsed().as_millis() - ); + // generate execution trace + let trace = + info_span!("generate_execution_trace", num_cols = TRACE_WIDTH, steps = field::Empty) + .in_scope(|| { + let trace = prover.build_trace(self.seed, self.chain_length); + tracing::Span::current().record("steps", trace.length()); + trace + }); // generate the proof prover.prove(trace).unwrap() diff --git a/examples/src/rescue_raps/mod.rs b/examples/src/rescue_raps/mod.rs index 6a30bae5d..33828eca1 100644 --- a/examples/src/rescue_raps/mod.rs +++ b/examples/src/rescue_raps/mod.rs @@ -5,9 +5,9 @@ use crate::{Blake3_192, Blake3_256, Example, ExampleOptions, HashFunction, Sha3_256}; use core::marker::PhantomData; -use log::debug; use rand_utils::rand_array; use std::time::Instant; +use tracing::{field, info_span}; use winterfell::{ crypto::{DefaultRandomCoin, ElementHasher}, math::{fields::f128::BaseElement, ExtensionOf, FieldElement}, @@ -83,7 +83,7 @@ impl RescueRapsExample { // compute the sequence of hashes using external implementation of Rescue hash let now = Instant::now(); let result = compute_permuted_hash_chains(&seeds, &permuted_seeds); - debug!( + println!( "Computed two permuted chains of {} Rescue hashes in {} ms", chain_length, now.elapsed().as_millis(), @@ -109,25 +109,19 @@ where { fn prove(&self) -> StarkProof { // generate the execution trace - debug!( - "Generating proof for computing a chain of {} Rescue hashes\n\ - ---------------------", - self.chain_length - ); + println!("Generating proof for computing a chain of {} Rescue hashes", self.chain_length); // create a prover let prover = RescueRapsProver::::new(self.options.clone()); - // generate the execution trace - let now = Instant::now(); - let trace = prover.build_trace(&self.seeds, &self.permuted_seeds, self.result); - let trace_length = trace.length(); - debug!( - "Generated execution trace of {} registers and 2^{} steps in {} ms", - trace.width(), - trace_length.ilog2(), - now.elapsed().as_millis() - ); + // generate execution trace + let trace = + info_span!("generate_execution_trace", num_cols = TRACE_WIDTH, steps = field::Empty) + .in_scope(|| { + let trace = prover.build_trace(&self.seeds, &self.permuted_seeds, self.result); + tracing::Span::current().record("steps", trace.length()); + trace + }); // generate the proof prover.prove(trace).unwrap() diff --git a/examples/src/vdf/exempt/air.rs b/examples/src/vdf/exempt/air.rs index 74b196109..6f497e151 100644 --- a/examples/src/vdf/exempt/air.rs +++ b/examples/src/vdf/exempt/air.rs @@ -3,7 +3,7 @@ // This source code is licensed under the MIT license found in the // LICENSE file in the root directory of this source tree. -use super::{BaseElement, FieldElement, ProofOptions, ALPHA, FORTY_TWO}; +use super::{BaseElement, FieldElement, ProofOptions, ALPHA, FORTY_TWO, TRACE_WIDTH}; use winterfell::{ math::ToElements, Air, AirContext, Assertion, EvaluationFrame, TraceInfo, TransitionConstraintDegree, @@ -39,6 +39,7 @@ impl Air for VdfAir { fn new(trace_info: TraceInfo, pub_inputs: VdfInputs, options: ProofOptions) -> Self { let degrees = vec![TransitionConstraintDegree::new(3)]; + assert_eq!(TRACE_WIDTH, trace_info.width()); // make sure the last two rows are excluded from transition constraints as we populate // values in the last row with garbage let context = diff --git a/examples/src/vdf/exempt/mod.rs b/examples/src/vdf/exempt/mod.rs index 72f7d9254..66bef4f22 100644 --- a/examples/src/vdf/exempt/mod.rs +++ b/examples/src/vdf/exempt/mod.rs @@ -5,8 +5,8 @@ use crate::{Blake3_192, Blake3_256, Example, ExampleOptions, HashFunction, Sha3_256}; use core::marker::PhantomData; -use log::debug; use std::time::Instant; +use tracing::{field, info_span}; use winterfell::{ crypto::{DefaultRandomCoin, ElementHasher}, math::{fields::f128::BaseElement, FieldElement}, @@ -28,6 +28,7 @@ mod tests; const ALPHA: u64 = 3; const INV_ALPHA: u128 = 226854911280625642308916371969163307691; const FORTY_TWO: BaseElement = BaseElement::new(42); +const TRACE_WIDTH: usize = 1; // VDF EXAMPLE // ================================================================================================ @@ -62,7 +63,7 @@ impl VdfExample { let now = Instant::now(); let seed = BaseElement::new(123); let result = execute_vdf(seed, num_steps); - debug!( + println!( "Executed the VDF function for {} steps in {} ms", num_steps, now.elapsed().as_millis() @@ -86,27 +87,19 @@ where H: ElementHasher, { fn prove(&self) -> StarkProof { - debug!( - "Generating proof for executing a VDF function for {} steps\n\ - ---------------------", - self.num_steps - ); + println!("Generating proof for executing a VDF function for {} steps", self.num_steps); // create a prover let prover = VdfProver::::new(self.options.clone()); // generate execution trace - let now = Instant::now(); - let trace = VdfProver::::build_trace(self.seed, self.num_steps + 1); - - let trace_width = trace.width(); - let trace_length = trace.length(); - debug!( - "Generated execution trace of {} registers and 2^{} steps in {} ms", - trace_width, - trace_length.ilog2(), - now.elapsed().as_millis() - ); + let trace = + info_span!("generate_execution_trace", num_cols = TRACE_WIDTH, steps = field::Empty) + .in_scope(|| { + let trace = VdfProver::::build_trace(self.seed, self.num_steps + 1); + tracing::Span::current().record("steps", trace.length()); + trace + }); // generate the proof prover.prove(trace).unwrap() diff --git a/examples/src/vdf/regular/air.rs b/examples/src/vdf/regular/air.rs index dfbb00944..280fef023 100644 --- a/examples/src/vdf/regular/air.rs +++ b/examples/src/vdf/regular/air.rs @@ -3,7 +3,7 @@ // This source code is licensed under the MIT license found in the // LICENSE file in the root directory of this source tree. -use super::{BaseElement, FieldElement, ProofOptions, ALPHA, FORTY_TWO}; +use super::{BaseElement, FieldElement, ProofOptions, ALPHA, FORTY_TWO, TRACE_WIDTH}; use winterfell::{ math::ToElements, Air, AirContext, Assertion, EvaluationFrame, TraceInfo, TransitionConstraintDegree, @@ -39,6 +39,7 @@ impl Air for VdfAir { fn new(trace_info: TraceInfo, pub_inputs: VdfInputs, options: ProofOptions) -> Self { let degrees = vec![TransitionConstraintDegree::new(3)]; + assert_eq!(TRACE_WIDTH, trace_info.width()); Self { context: AirContext::new(trace_info, degrees, 2, options), seed: pub_inputs.seed, diff --git a/examples/src/vdf/regular/mod.rs b/examples/src/vdf/regular/mod.rs index f5f2df7ab..8b8ffb08c 100644 --- a/examples/src/vdf/regular/mod.rs +++ b/examples/src/vdf/regular/mod.rs @@ -5,8 +5,8 @@ use crate::{Blake3_192, Blake3_256, Example, ExampleOptions, HashFunction, Sha3_256}; use core::marker::PhantomData; -use log::debug; use std::time::Instant; +use tracing::{field, info_span}; use winterfell::{ crypto::{DefaultRandomCoin, ElementHasher}, math::{fields::f128::BaseElement, FieldElement}, @@ -28,6 +28,7 @@ mod tests; const ALPHA: u64 = 3; const INV_ALPHA: u128 = 226854911280625642308916371969163307691; const FORTY_TWO: BaseElement = BaseElement::new(42); +const TRACE_WIDTH: usize = 1; // VDF EXAMPLE // ================================================================================================ @@ -59,7 +60,7 @@ impl VdfExample { let now = Instant::now(); let seed = BaseElement::new(123); let result = execute_vdf(seed, num_steps); - debug!( + println!( "Executed the VDF function for {} steps in {} ms", num_steps, now.elapsed().as_millis() @@ -83,27 +84,19 @@ where H: ElementHasher, { fn prove(&self) -> StarkProof { - debug!( - "Generating proof for executing a VDF function for {} steps\n\ - ---------------------", - self.num_steps - ); + println!("Generating proof for executing a VDF function for {} steps", self.num_steps); // create a prover let prover = VdfProver::::new(self.options.clone()); // generate execution trace - let now = Instant::now(); - let trace = VdfProver::::build_trace(self.seed, self.num_steps); - - let trace_width = trace.width(); - let trace_length = trace.length(); - debug!( - "Generated execution trace of {} registers and 2^{} steps in {} ms", - trace_width, - trace_length.ilog2(), - now.elapsed().as_millis() - ); + let trace = + info_span!("generate_execution_trace", num_cols = TRACE_WIDTH, steps = field::Empty) + .in_scope(|| { + let trace = VdfProver::::build_trace(self.seed, self.num_steps); + tracing::Span::current().record("steps", trace.length()); + trace + }); // generate the proof prover.prove(trace).unwrap() diff --git a/prover/Cargo.toml b/prover/Cargo.toml index 643b712ed..1133153c6 100644 --- a/prover/Cargo.toml +++ b/prover/Cargo.toml @@ -28,8 +28,8 @@ std = ["air/std", "crypto/std", "fri/std", "math/std", "utils/std"] air = { version = "0.7", path = "../air", package = "winter-air", default-features = false } crypto = { version = "0.7", path = "../crypto", package = "winter-crypto", default-features = false } fri = { version = "0.7", path = '../fri', package = "winter-fri", default-features = false } -log = { version = "0.4", default-features = false } math = { version = "0.7", path = "../math", package = "winter-math", default-features = false } +tracing = { version = "0.1", default-features = false } utils = { version = "0.7", path = "../utils/core", package = "winter-utils", default-features = false } [dev-dependencies] diff --git a/prover/src/lib.rs b/prover/src/lib.rs index 39043f440..18c187cb1 100644 --- a/prover/src/lib.rs +++ b/prover/src/lib.rs @@ -49,6 +49,7 @@ pub use air::{ DeepCompositionCoefficients, EvaluationFrame, FieldExtension, ProofOptions, TraceInfo, TraceLayout, TransitionConstraintDegree, }; +use tracing::{event, info_span, Level}; pub use utils::{ iterators, ByteReader, ByteWriter, Deserializable, DeserializationError, Serializable, SliceReader, @@ -67,11 +68,6 @@ use math::{ pub use crypto; use crypto::{ElementHasher, RandomCoin}; -#[cfg(feature = "std")] -use log::debug; -#[cfg(feature = "std")] -use std::time::Instant; - mod domain; pub use domain::StarkDomain; @@ -206,7 +202,8 @@ pub trait Prover { /// [Self::get_pub_inputs()](Prover::get_pub_inputs) for the provided trace. fn prove(&self, trace: Self::Trace) -> Result { // figure out which version of the generic proof generation procedure to run. this is a sort - // of static dispatch for selecting two generic parameter: extension field and hash function. + // of static dispatch for selecting two generic parameter: extension field and hash + // function. match self.options().field_extension() { FieldExtension::None => self.generate_proof::(trace), FieldExtension::Quadratic => { @@ -257,57 +254,68 @@ pub trait Prover { // 1 ----- Commit to the execution trace -------------------------------------------------- // build computation domain; this is used later for polynomial evaluations - #[cfg(feature = "std")] - let now = Instant::now(); - let domain = StarkDomain::new(&air); - #[cfg(feature = "std")] - debug!( - "Built domain of 2^{} elements in {} ms", - domain.lde_domain_size().ilog2(), - now.elapsed().as_millis() - ); - - // extend the main execution trace and build a Merkle tree from the extended trace - let (mut trace_lde, mut trace_polys): (Self::TraceLde, TracePolyTable) = - self.new_trace_lde(&trace.get_info(), trace.main_segment(), &domain); - - // get the commitment to the main trace segment LDE - let main_trace_root = trace_lde.get_main_trace_commitment(); - - // commit to the LDE of the main trace by writing the root of its Merkle tree into - // the channel - channel.commit_trace(main_trace_root); + let lde_domain_size = air.lde_domain_size(); + let trace_length = air.trace_length(); + let domain = info_span!("build_domain", lde_domain_size, trace_length) + .in_scope(|| StarkDomain::new(&air)); + assert_eq!(domain.lde_domain_size(), lde_domain_size); + assert_eq!(domain.trace_length(), trace_length); + + // commit to the main trace segment + let (mut trace_lde, mut trace_polys) = { + // extend the main execution trace and build a Merkle tree from the extended trace + let span = info_span!("commit_to_main_trace_segment").entered(); + let (trace_lde, trace_polys) = + self.new_trace_lde(&trace.get_info(), trace.main_segment(), &domain); + + // get the commitment to the main trace segment LDE + let main_trace_root = trace_lde.get_main_trace_commitment(); + + // commit to the LDE of the main trace by writing the root of its Merkle tree into + // the channel + channel.commit_trace(main_trace_root); + + drop(span); + (trace_lde, trace_polys) + }; // build auxiliary trace segments (if any), and append the resulting segments to trace // commitment and trace polynomial table structs let mut aux_trace_segments = Vec::new(); let mut aux_trace_rand_elements = AuxTraceRandElements::new(); for i in 0..trace.layout().num_aux_segments() { - #[cfg(feature = "std")] - let now = Instant::now(); - - // draw a set of random elements required to build an auxiliary trace segment - let rand_elements = channel.get_aux_trace_segment_rand_elements(i); - - // build the trace segment - let aux_segment = trace - .build_aux_segment(&aux_trace_segments, &rand_elements) - .expect("failed build auxiliary trace segment"); - #[cfg(feature = "std")] - debug!( - "Built auxiliary trace segment of {} columns and 2^{} steps in {} ms", - aux_segment.num_cols(), - aux_segment.num_rows().ilog2(), - now.elapsed().as_millis() - ); - - // extend the auxiliary trace segment and build a Merkle tree from the extended trace - let (aux_segment_polys, aux_segment_root) = - trace_lde.add_aux_segment(&aux_segment, &domain); - - // commit to the LDE of the extended auxiliary trace segment by writing the root of - // its Merkle tree into the channel - channel.commit_trace(aux_segment_root); + let num_columns = trace.layout().get_aux_segment_width(i); + let (aux_segment, rand_elements) = { + let _ = info_span!("build_aux_trace_segment", num_columns).entered(); + + // draw a set of random elements required to build an auxiliary trace segment + let rand_elements = channel.get_aux_trace_segment_rand_elements(i); + + // build the trace segment + let aux_segment = trace + .build_aux_segment(&aux_trace_segments, &rand_elements) + .expect("failed build auxiliary trace segment"); + + (aux_segment, rand_elements) + }; + assert_eq!(aux_segment.num_cols(), num_columns); + assert_eq!(aux_segment.num_rows(), air.trace_length()); + + // commit to the auxiliary trace segment + let aux_segment_polys = { + // extend the auxiliary trace segment and build a Merkle tree from the extended + // trace + let span = info_span!("commit_to_aux_trace_segment").entered(); + let (aux_segment_polys, aux_segment_root) = + trace_lde.add_aux_segment(&aux_segment, &domain); + + // commit to the LDE of the extended auxiliary trace segment by writing the root of + // its Merkle tree into the channel + channel.commit_trace(aux_segment_root); + + drop(span); + aux_segment_polys + }; trace_polys.add_aux_segment(aux_segment_polys); aux_trace_rand_elements.add_segment_elements(rand_elements); @@ -328,147 +336,151 @@ pub trait Prover { // evaluate constraints specified by the AIR over the constraint evaluation domain, and // compute random linear combinations of these evaluations using coefficients drawn from // the channel - #[cfg(feature = "std")] - let now = Instant::now(); - let constraint_coeffs = channel.get_constraint_composition_coeffs(); - let evaluator = self.new_evaluator(&air, aux_trace_rand_elements, constraint_coeffs); - let composition_poly_trace = evaluator.evaluate(&trace_lde, &domain); - #[cfg(feature = "std")] - debug!( - "Evaluated constraints over domain of 2^{} elements in {} ms", - composition_poly_trace.num_rows().ilog2(), - now.elapsed().as_millis() - ); + let ce_domain_size = air.ce_domain_size(); + let composition_poly_trace = { + let span = info_span!("evaluate_constraints", ce_domain_size).entered(); + let composition_poly_trace = self + .new_evaluator( + &air, + aux_trace_rand_elements, + channel.get_constraint_composition_coeffs(), + ) + .evaluate(&trace_lde, &domain); + drop(span); + + composition_poly_trace + }; + assert_eq!(composition_poly_trace.num_rows(), ce_domain_size); // 3 ----- commit to constraint evaluations ----------------------------------------------- // first, build a commitment to the evaluations of the constraint composition polynomial // columns - let (constraint_commitment, composition_poly) = self.build_constraint_commitment::( - composition_poly_trace, - air.context().num_constraint_composition_columns(), - &domain, - ); + let (constraint_commitment, composition_poly) = + info_span!("commit_to_constraint_evaluations").in_scope(|| { + self.build_constraint_commitment::( + composition_poly_trace, + air.context().num_constraint_composition_columns(), + &domain, + ) + }); // then, commit to the evaluations of constraints by writing the root of the constraint // Merkle tree into the channel channel.commit_constraints(constraint_commitment.root()); // 4 ----- build DEEP composition polynomial ---------------------------------------------- - #[cfg(feature = "std")] - let now = Instant::now(); - - // draw an out-of-domain point z. Depending on the type of E, the point is drawn either - // from the base field or from an extension field defined by E. - // - // The purpose of sampling from the extension field here (instead of the base field) is to - // increase security. Soundness is limited by the size of the field that the random point - // is drawn from, and we can potentially save on performance by only drawing this point - // from an extension field, rather than increasing the size of the field overall. - let z = channel.get_ood_point(); - - // evaluate trace and constraint polynomials at the OOD point z, and send the results to - // the verifier. the trace polynomials are actually evaluated over two points: z and z * g, - // where g is the generator of the trace domain. - let ood_trace_states = trace_polys.get_ood_frame(z); - channel.send_ood_trace_states(&ood_trace_states); - - let ood_evaluations = composition_poly.evaluate_at(z); - channel.send_ood_constraint_evaluations(&ood_evaluations); - - // draw random coefficients to use during DEEP polynomial composition, and use them to - // initialize the DEEP composition polynomial - let deep_coefficients = channel.get_deep_composition_coeffs(); - let mut deep_composition_poly = DeepCompositionPoly::new(z, deep_coefficients); - - // combine all trace polynomials together and merge them into the DEEP composition - // polynomial - deep_composition_poly.add_trace_polys(trace_polys, ood_trace_states); - - // merge columns of constraint composition polynomial into the DEEP composition polynomial; - deep_composition_poly.add_composition_poly(composition_poly, ood_evaluations); - - #[cfg(feature = "std")] - debug!( - "Built DEEP composition polynomial of degree {} in {} ms", - deep_composition_poly.degree(), - now.elapsed().as_millis() - ); + let deep_composition_poly = { + let span = info_span!("build_deep_composition_poly").entered(); + // draw an out-of-domain point z. Depending on the type of E, the point is drawn either + // from the base field or from an extension field defined by E. + // + // The purpose of sampling from the extension field here (instead of the base field) is + // to increase security. Soundness is limited by the size of the field that the random + // point is drawn from, and we can potentially save on performance by only drawing this + // point from an extension field, rather than increasing the size of the field overall. + let z = channel.get_ood_point(); + + // evaluate trace and constraint polynomials at the OOD point z, and send the results to + // the verifier. the trace polynomials are actually evaluated over two points: z and + // z * g, where g is the generator of the trace domain. + let ood_trace_states = trace_polys.get_ood_frame(z); + channel.send_ood_trace_states(&ood_trace_states); + + let ood_evaluations = composition_poly.evaluate_at(z); + channel.send_ood_constraint_evaluations(&ood_evaluations); + + // draw random coefficients to use during DEEP polynomial composition, and use them to + // initialize the DEEP composition polynomial + let deep_coefficients = channel.get_deep_composition_coeffs(); + let mut deep_composition_poly = DeepCompositionPoly::new(z, deep_coefficients); + + // combine all trace polynomials together and merge them into the DEEP composition + // polynomial + deep_composition_poly.add_trace_polys(trace_polys, ood_trace_states); + + // merge columns of constraint composition polynomial into the DEEP composition + // polynomial + deep_composition_poly.add_composition_poly(composition_poly, ood_evaluations); + + event!(Level::DEBUG, "degree: {}", deep_composition_poly.degree()); + + drop(span); + deep_composition_poly + }; // make sure the degree of the DEEP composition polynomial is equal to trace polynomial // degree minus 1. assert_eq!(domain.trace_length() - 2, deep_composition_poly.degree()); // 5 ----- evaluate DEEP composition polynomial over LDE domain --------------------------- - #[cfg(feature = "std")] - let now = Instant::now(); - let deep_evaluations = deep_composition_poly.evaluate(&domain); - // we check the following condition in debug mode only because infer_degree is an expensive - // operation - debug_assert_eq!( - domain.trace_length() - 2, - infer_degree(&deep_evaluations, domain.offset()) - ); - #[cfg(feature = "std")] - debug!( - "Evaluated DEEP composition polynomial over LDE domain (2^{} elements) in {} ms", - domain.lde_domain_size().ilog2(), - now.elapsed().as_millis() - ); + let deep_evaluations = { + let span = info_span!("evaluate_deep_composition_poly").entered(); + let deep_evaluations = deep_composition_poly.evaluate(&domain); + // we check the following condition in debug mode only because infer_degree is an + // expensive operation + debug_assert_eq!( + domain.trace_length() - 2, + infer_degree(&deep_evaluations, domain.offset()) + ); + + drop(span); + deep_evaluations + }; // 6 ----- compute FRI layers for the composition polynomial ------------------------------ - #[cfg(feature = "std")] - let now = Instant::now(); - let mut fri_prover = FriProver::new(air.options().to_fri_options()); - fri_prover.build_layers(&mut channel, deep_evaluations); - #[cfg(feature = "std")] - debug!( - "Computed {} FRI layers from composition polynomial evaluations in {} ms", - fri_prover.num_layers(), - now.elapsed().as_millis() - ); + let fri_options = air.options().to_fri_options(); + let num_layers = fri_options.num_fri_layers(air.lde_domain_size()); + let mut fri_prover = FriProver::new(fri_options); + info_span!("compute_fri_layers", num_layers) + .in_scope(|| fri_prover.build_layers(&mut channel, deep_evaluations)); // 7 ----- determine query positions ------------------------------------------------------ - #[cfg(feature = "std")] - let now = Instant::now(); - - // apply proof-of-work to the query seed - channel.grind_query_seed(); - - // generate pseudo-random query positions - let query_positions = channel.get_query_positions(); - #[cfg(feature = "std")] - debug!( - "Determined {} unique query positions in {} ms", - query_positions.len(), - now.elapsed().as_millis() - ); + let query_positions = { + let span = info_span!( + "determine_query_positions", + num_positions = air.options().num_queries(), + grinding_factor = air.options().grinding_factor() + ) + .entered(); + // apply proof-of-work to the query seed + channel.grind_query_seed(); + + // generate pseudo-random query positions + let query_positions = channel.get_query_positions(); + event!(Level::DEBUG, "query_positions_len: {}", query_positions.len()); + + drop(span); + query_positions + }; // 8 ----- build proof object ------------------------------------------------------------- - #[cfg(feature = "std")] - let now = Instant::now(); - - // generate FRI proof - let fri_proof = fri_prover.build_proof(&query_positions); - - // query the execution trace at the selected position; for each query, we need the - // state of the trace at that position + Merkle authentication path - let trace_queries = trace_lde.query(&query_positions); - - // query the constraint commitment at the selected positions; for each query, we need just - // a Merkle authentication path. this is because constraint evaluations for each step are - // merged into a single value and Merkle authentication paths contain these values already - let constraint_queries = constraint_commitment.query(&query_positions); - - // build the proof object - let proof = channel.build_proof( - trace_queries, - constraint_queries, - fri_proof, - query_positions.len(), - ); - #[cfg(feature = "std")] - debug!("Built proof object in {} ms", now.elapsed().as_millis()); + let proof = { + let span = info_span!("build_proof_object").entered(); + // generate FRI proof + let fri_proof = fri_prover.build_proof(&query_positions); + + // query the execution trace at the selected position; for each query, we need the + // state of the trace at that position + Merkle authentication path + let trace_queries = trace_lde.query(&query_positions); + + // query the constraint commitment at the selected positions; for each query, we need + // just a Merkle authentication path. this is because constraint evaluations for each + // step are merged into a single value and Merkle authentication paths contain these + // values already + let constraint_queries = constraint_commitment.query(&query_positions); + + // build the proof object + let proof = channel.build_proof( + trace_queries, + constraint_queries, + fri_proof, + query_positions.len(), + ); + + drop(span); + proof + }; Ok(proof) } @@ -486,7 +498,7 @@ pub trait Prover { fn build_constraint_commitment( &self, composition_poly_trace: CompositionPolyTrace, - num_trace_poly_columns: usize, + num_constraint_composition_columns: usize, domain: &StarkDomain, ) -> (ConstraintCommitment, CompositionPoly) where @@ -496,44 +508,34 @@ pub trait Prover { // - interpolate the trace into a polynomial in coefficient form // - "break" the polynomial into a set of column polynomials each of degree equal to // trace_length - 1 - #[cfg(feature = "std")] - let now = Instant::now(); - let composition_poly = - CompositionPoly::new(composition_poly_trace, domain, num_trace_poly_columns); - #[cfg(feature = "std")] - debug!( - "Converted constraint evaluations into {} composition polynomial columns of degree {} in {} ms", - composition_poly.num_columns(), - composition_poly.column_degree(), - now.elapsed().as_millis() - ); + let composition_poly = info_span!( + "build_composition_poly_columns", + num_columns = num_constraint_composition_columns + ) + .in_scope(|| { + CompositionPoly::new(composition_poly_trace, domain, num_constraint_composition_columns) + }); + assert_eq!(composition_poly.num_columns(), num_constraint_composition_columns); + assert_eq!(composition_poly.column_degree(), domain.trace_length() - 1); // then, evaluate composition polynomial columns over the LDE domain - #[cfg(feature = "std")] - let now = Instant::now(); - let composed_evaluations = RowMatrix::evaluate_polys_over::( - composition_poly.data(), - domain, - ); - #[cfg(feature = "std")] - debug!( - "Evaluated {} composition polynomial columns over LDE domain (2^{} elements) in {} ms", - composed_evaluations.num_cols(), - composed_evaluations.num_rows().ilog2(), - now.elapsed().as_millis() - ); + let domain_size = domain.lde_domain_size(); + let composed_evaluations = info_span!("evaluate_composition_poly_columns").in_scope(|| { + RowMatrix::evaluate_polys_over::(composition_poly.data(), domain) + }); + assert_eq!(composed_evaluations.num_cols(), num_constraint_composition_columns); + assert_eq!(composed_evaluations.num_rows(), domain_size); // finally, build constraint evaluation commitment - #[cfg(feature = "std")] - let now = Instant::now(); - let commitment = composed_evaluations.commit_to_rows(); - let constraint_commitment = ConstraintCommitment::new(composed_evaluations, commitment); - #[cfg(feature = "std")] - debug!( - "Computed constraint evaluation commitment (Merkle tree of depth {}) in {} ms", - constraint_commitment.tree_depth(), - now.elapsed().as_millis() - ); + let constraint_commitment = info_span!( + "compute_constraint_evaluation_commitment", + tree_depth = domain_size.ilog2() + ) + .in_scope(|| { + let commitment = composed_evaluations.commit_to_rows(); + ConstraintCommitment::new(composed_evaluations, commitment) + }); + assert_eq!(constraint_commitment.tree_depth(), domain_size.ilog2() as usize); (constraint_commitment, composition_poly) } diff --git a/prover/src/trace/trace_lde/default/mod.rs b/prover/src/trace/trace_lde/default/mod.rs index c7a5933d1..e742d2dfb 100644 --- a/prover/src/trace/trace_lde/default/mod.rs +++ b/prover/src/trace/trace_lde/default/mod.rs @@ -9,11 +9,7 @@ use super::{ }; use crate::{RowMatrix, DEFAULT_SEGMENT_WIDTH}; use crypto::MerkleTree; - -#[cfg(feature = "std")] -use log::debug; -#[cfg(feature = "std")] -use std::time::Instant; +use tracing::info_span; #[cfg(test)] mod tests; @@ -234,30 +230,29 @@ where H: ElementHasher, { // extend the execution trace - #[cfg(feature = "std")] - let now = Instant::now(); - let trace_polys = trace.interpolate_columns(); - let trace_lde = RowMatrix::evaluate_polys_over::(&trace_polys, domain); - #[cfg(feature = "std")] - debug!( - "Extended execution trace of {} columns from 2^{} to 2^{} steps ({}x blowup) in {} ms", - trace_lde.num_cols(), - trace_polys.num_rows().ilog2(), - trace_lde.num_rows().ilog2(), - domain.trace_to_lde_blowup(), - now.elapsed().as_millis() - ); + let (trace_lde, trace_polys) = { + let span = info_span!( + "extend_execution_trace", + num_cols = trace.num_cols(), + blowup = domain.trace_to_lde_blowup() + ) + .entered(); + let trace_polys = trace.interpolate_columns(); + let trace_lde = + RowMatrix::evaluate_polys_over::(&trace_polys, domain); + drop(span); + + (trace_lde, trace_polys) + }; + assert_eq!(trace_lde.num_cols(), trace.num_cols()); + assert_eq!(trace_polys.num_rows(), trace.num_rows()); + assert_eq!(trace_lde.num_rows(), domain.lde_domain_size()); // build trace commitment - #[cfg(feature = "std")] - let now = Instant::now(); - let trace_tree = trace_lde.commit_to_rows(); - #[cfg(feature = "std")] - debug!( - "Computed execution trace commitment (Merkle tree of depth {}) in {} ms", - trace_tree.depth(), - now.elapsed().as_millis() - ); + let tree_depth = trace_lde.num_rows().ilog2() as usize; + let trace_tree = info_span!("compute_execution_trace_commitment", tree_depth) + .in_scope(|| trace_lde.commit_to_rows()); + assert_eq!(trace_tree.depth(), tree_depth); (trace_lde, trace_tree, trace_polys) } diff --git a/verifier/README.md b/verifier/README.md index ce5001ae8..34d141137 100644 --- a/verifier/README.md +++ b/verifier/README.md @@ -29,8 +29,8 @@ For example, if we have a struct `FibAir` which implements the `Air` trait and d let min_sec = AcceptableOptions::MinConjecturedSecurity(95); let fib_result = BaseElement::new(226333832811148522147755045522163790995); match verifier::verify::>(proof, fib_result, &min_sec) { - Ok(_) => debug!("Proof verified!"), - Err(err) => debug!("Failed to verify proof: {}", err), + Ok(_) => println!("Proof verified!"), + Err(err) => println!("Failed to verify proof: {}", err), } ``` where, `226333832811148522147755045522163790995` is the 1,048,576th term of the Fibonacci sequence when the sequence is computed in a 128-bit field with modulus 2128 - 45 * 240.