Reduce noise in FRI logging (#129)

* Reduce noise in FRI logging

Previously, all logs related to gate counts were at the `Debug` log level. This PR gives us more flexibility to adjust the log levels of particular scopes.

In particular, our circuit checks 40 FRI queries, and we log a bunch of steps for each query, creating a lot of noise. With this change, we log just a single FRI query at the `Debug` level, and demote others to the `Trace` level.

With `RUST_LOG=debug`, our logs now look like

```
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] 17631 gates to root
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | 8 gates to observe proof and generates challenges
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | 4150 gates to evaluate the vanishing polynomial at our challenge point, zeta.
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | 3184 gates to evaluate gate constraints
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | | 227 gates to evaluate InterpolationGate { num_points: 4, _phantom: PhantomData }<D=4> constraints
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | | 867 gates to evaluate <R=101> GMiMCGate { ... } constraints
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | | 576 gates to evaluate BaseSumGate { num_limbs: 63 } + Base: 2 constraints
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | | 78 gates to evaluate ArithmeticExtensionGate constraints
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | | 288 gates to evaluate BaseSumGate { num_limbs: 31 } + Base: 2 constraints
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | | 115 gates to evaluate InsertionGate { vec_size: 3, _phantom: PhantomData }<D=4> constraints
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | | 26 gates to evaluate BaseSumGate { num_limbs: 2 } + Base: 2 constraints
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | | 633 gates to evaluate ReducingGate { num_coeffs: 21 } constraints
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | | 4 gates to evaluate ConstantGate constraints
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | | 11 gates to evaluate PublicInputGate constraints
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | | 2 gates to evaluate NoopGate constraints
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | 16 gates to check vanishing and quotient polynomials.
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | 13336 gates to verify FRI proof
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | 6 gates to recover the random betas used in the FRI reductions.
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | 4 gates to check PoW
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | 104 gates to precompute reduced evaluations
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | 330 gates to verify one (of 40) query rounds
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | | 95 gates to check FRI initial proof
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | | | 22 gates to verify 0'th initial Merkle proof
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | | | 33 gates to verify 1'th initial Merkle proof
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | | | 20 gates to verify 2'th initial Merkle proof
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | | | 20 gates to verify 3'th initial Merkle proof
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | | 34 gates to compute x from its index
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | | 32 gates to combine initial oracles
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | | 17 gates to verify FRI round Merkle proof.
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | | 10 gates to infer evaluation using interpolation
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | | 15 gates to verify FRI round Merkle proof.
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | | 10 gates to infer evaluation using interpolation
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | | 13 gates to verify FRI round Merkle proof.
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | | 10 gates to infer evaluation using interpolation
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | | 11 gates to verify FRI round Merkle proof.
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | | 10 gates to infer evaluation using interpolation
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | | 9 gates to verify FRI round Merkle proof.
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | | 10 gates to infer evaluation using interpolation
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | | 7 gates to verify FRI round Merkle proof.
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | | 10 gates to infer final evaluation using interpolation
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | | 8 gates to evaluate final polynomial
```

This bit corresponds to the single FRI query being shown:

```
[2021-07-26T21:07:45Z DEBUG plonky2::context_tree] | | 330 gates to verify one (of 40) query rounds
```

* Minor cleanup

* Address feedback
This commit is contained in:
Daniel Lubarov 2021-07-26 16:21:14 -07:00 committed by GitHub
parent 3fc02c76bc
commit 9081ae7337
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
6 changed files with 63 additions and 32 deletions

View File

@ -301,8 +301,8 @@ impl<F: Extendable<D>, const D: usize> CircuitBuilder<F, D> {
self.targets_to_constants.get(&target).cloned()
}
pub fn push_context(&mut self, ctx: &str) {
self.context_log.push(ctx, self.num_gates());
pub fn push_context(&mut self, level: log::Level, ctx: &str) {
self.context_log.push(ctx, level, self.num_gates());
}
pub fn pop_context(&mut self) {

View File

@ -1,9 +1,11 @@
use log::debug;
use log::{log, Level};
/// The hierarchy of contexts, and the gate count contributed by each one. Useful for debugging.
pub(crate) struct ContextTree {
/// The name of this scope.
name: String,
/// The level at which to log this scope and its children.
level: log::Level,
/// The gate count when this scope was created.
enter_gate_count: usize,
/// The gate count when this scope was destroyed, or None if it has not yet been destroyed.
@ -16,6 +18,7 @@ impl ContextTree {
pub fn new() -> Self {
Self {
name: "root".to_string(),
level: Level::Debug,
enter_gate_count: 0,
exit_gate_count: None,
children: vec![],
@ -43,18 +46,22 @@ impl ContextTree {
}
}
pub fn push(&mut self, ctx: &str, current_gate_count: usize) {
pub fn push(&mut self, ctx: &str, mut level: log::Level, current_gate_count: usize) {
assert!(self.is_open());
// We don't want a scope's log level to be stronger than that of its parent.
level = level.max(self.level);
if let Some(last_child) = self.children.last_mut() {
if last_child.is_open() {
last_child.push(ctx, current_gate_count);
last_child.push(ctx, level, current_gate_count);
return;
}
}
self.children.push(ContextTree {
name: ctx.to_string(),
level,
enter_gate_count: current_gate_count,
exit_gate_count: None,
children: vec![],
@ -83,6 +90,7 @@ impl ContextTree {
pub fn filter(&self, current_gate_count: usize, min_delta: usize) -> Self {
Self {
name: self.name.clone(),
level: self.level,
enter_gate_count: self.enter_gate_count,
exit_gate_count: self.exit_gate_count,
children: self
@ -100,7 +108,8 @@ impl ContextTree {
fn print_helper(&self, current_gate_count: usize, depth: usize) {
let prefix = "| ".repeat(depth);
debug!(
log!(
self.level,
"{}{} gates to {}",
prefix,
self.gate_count_delta(current_gate_count),
@ -114,9 +123,16 @@ impl ContextTree {
/// Creates a named scope; useful for debugging.
#[macro_export]
macro_rules! context {
macro_rules! with_context {
($builder:expr, $level:expr, $ctx:expr, $exp:expr) => {{
$builder.push_context($level, $ctx);
let res = $exp;
$builder.pop_context();
res
}};
// If no context is specified, default to Debug.
($builder:expr, $ctx:expr, $exp:expr) => {{
$builder.push_context($ctx);
$builder.push_context(log::Level::Debug, $ctx);
let res = $exp;
$builder.pop_context();
res

View File

@ -1,6 +1,5 @@
use crate::circuit_builder::CircuitBuilder;
use crate::circuit_data::CommonCircuitData;
use crate::context;
use crate::field::extension_field::target::{flatten_target, ExtensionTarget};
use crate::field::extension_field::Extendable;
use crate::field::field::Field;
@ -13,6 +12,7 @@ use crate::proof::{
use crate::target::Target;
use crate::util::reducing::ReducingFactorTarget;
use crate::util::{log2_strict, reverse_index_bits_in_place};
use crate::with_context;
impl<F: Extendable<D>, const D: usize> CircuitBuilder<F, D> {
/// Computes P'(x^arity) from {P(x*g^i)}_(i=0..arity), where g is a `arity`-th root of unity
@ -93,7 +93,7 @@ impl<F: Extendable<D>, const D: usize> CircuitBuilder<F, D> {
// Size of the LDE domain.
let n = proof.final_poly.len() << (total_arities + config.rate_bits);
let betas = context!(
let betas = with_context!(
self,
"recover the random betas used in the FRI reductions.",
proof
@ -107,7 +107,7 @@ impl<F: Extendable<D>, const D: usize> CircuitBuilder<F, D> {
);
challenger.observe_extension_elements(&proof.final_poly.0);
context!(
with_context!(
self,
"check PoW",
self.fri_verify_proof_of_work(proof, challenger, &config.fri_config)
@ -124,12 +124,27 @@ impl<F: Extendable<D>, const D: usize> CircuitBuilder<F, D> {
"Number of reductions should be non-zero."
);
let precomputed_reduced_evals =
PrecomputedReducedEvalsTarget::from_os_and_alpha(os, alpha, self);
let precomputed_reduced_evals = with_context!(
self,
"precompute reduced evaluations",
PrecomputedReducedEvalsTarget::from_os_and_alpha(os, alpha, self)
);
for (i, round_proof) in proof.query_round_proofs.iter().enumerate() {
context!(
// To minimize noise in our logs, we will only record a context for a single FRI query.
// The very first query will have some extra gates due to constants being registered, so
// the second query is a better representative.
let level = if i == 1 {
log::Level::Debug
} else {
log::Level::Trace
};
let num_queries = proof.query_round_proofs.len();
with_context!(
self,
&format!("verify {}'th FRI query", i),
level,
&format!("verify one (of {}) query rounds", num_queries),
self.fri_verifier_query_round(
zeta,
alpha,
@ -158,7 +173,7 @@ impl<F: Extendable<D>, const D: usize> CircuitBuilder<F, D> {
.zip(initial_merkle_roots)
.enumerate()
{
context!(
with_context!(
self,
&format!("verify {}'th initial Merkle proof", i),
self.verify_merkle_proof(evals.clone(), x_index_bits, root, merkle_proof)
@ -256,7 +271,7 @@ impl<F: Extendable<D>, const D: usize> CircuitBuilder<F, D> {
let x_index = challenger.get_challenge(self);
let mut x_index_bits = self.low_bits(x_index, n_log, 64);
let mut domain_size = n;
context!(
with_context!(
self,
"check FRI initial proof",
self.fri_verify_initial_proof(
@ -268,7 +283,7 @@ impl<F: Extendable<D>, const D: usize> CircuitBuilder<F, D> {
let mut old_x_index_bits = Vec::new();
// `subgroup_x` is `subgroup[x_index]`, i.e., the actual field element in the domain.
let mut subgroup_x = context!(self, "compute x from its index", {
let mut subgroup_x = with_context!(self, "compute x from its index", {
let g = self.constant(F::MULTIPLICATIVE_GROUP_GENERATOR);
let phi = self.constant(F::primitive_root_of_unity(n_log));
@ -280,7 +295,7 @@ impl<F: Extendable<D>, const D: usize> CircuitBuilder<F, D> {
for (i, &arity_bits) in config.reduction_arity_bits.iter().enumerate() {
let next_domain_size = domain_size >> arity_bits;
let e_x = if i == 0 {
context!(
with_context!(
self,
"combine initial oracles",
self.fri_combine_initial(
@ -295,7 +310,7 @@ impl<F: Extendable<D>, const D: usize> CircuitBuilder<F, D> {
} else {
let last_evals = &evaluations[i - 1];
// Infer P(y) from {P(x)}_{x^arity=y}.
context!(
with_context!(
self,
"infer evaluation using interpolation",
self.compute_evaluation(
@ -313,7 +328,7 @@ impl<F: Extendable<D>, const D: usize> CircuitBuilder<F, D> {
old_x_index_bits = x_index_bits;
let low_x_index = self.le_sum(old_x_index_bits.iter());
evals = self.insert(low_x_index, e_x, evals);
context!(
with_context!(
self,
"verify FRI round Merkle proof.",
self.verify_merkle_proof(
@ -335,7 +350,7 @@ impl<F: Extendable<D>, const D: usize> CircuitBuilder<F, D> {
let last_evals = evaluations.last().unwrap();
let final_arity_bits = *config.reduction_arity_bits.last().unwrap();
let purported_eval = context!(
let purported_eval = with_context!(
self,
"infer final evaluation using interpolation",
self.compute_evaluation(
@ -350,7 +365,7 @@ impl<F: Extendable<D>, const D: usize> CircuitBuilder<F, D> {
// Final check of FRI. After all the reductions, we check that the final polynomial is equal
// to the one sent by the prover.
let eval = context!(
let eval = with_context!(
self,
"evaluate final polynomial",
proof.final_poly.eval_scalar(self, subgroup_x)

View File

@ -4,7 +4,6 @@ use serde::{Deserialize, Serialize};
use crate::circuit_builder::CircuitBuilder;
use crate::circuit_data::CommonCircuitData;
use crate::context;
use crate::field::extension_field::target::ExtensionTarget;
use crate::field::extension_field::Extendable;
use crate::field::field::Field;
@ -17,6 +16,7 @@ use crate::proof::{FriProof, FriProofTarget, Hash, HashTarget, OpeningSet, Openi
use crate::timed;
use crate::util::reducing::ReducingFactor;
use crate::util::{log2_ceil, log2_strict, reverse_bits, reverse_index_bits_in_place, transpose};
use crate::with_context;
/// Two (~64 bit) field elements gives ~128 bit security.
pub const SALT_SIZE: usize = 2;
@ -283,7 +283,7 @@ impl<const D: usize> OpeningProofTarget<D> {
let alpha = challenger.get_extension_challenge(builder);
context!(
with_context!(
builder,
"verify FRI proof",
builder.verify_fri_proof(

View File

@ -1,12 +1,12 @@
use crate::circuit_builder::CircuitBuilder;
use crate::circuit_data::{CircuitConfig, CommonCircuitData, VerifierCircuitTarget};
use crate::context;
use crate::field::extension_field::Extendable;
use crate::plonk_challenger::RecursiveChallenger;
use crate::proof::{HashTarget, ProofWithPublicInputsTarget};
use crate::util::reducing::ReducingFactorTarget;
use crate::vanishing_poly::eval_vanishing_poly_recursively;
use crate::vars::EvaluationTargets;
use crate::with_context;
const MIN_WIRES: usize = 120; // TODO: Double check.
const MIN_ROUTED_WIRES: usize = 28; // TODO: Double check.
@ -35,7 +35,7 @@ impl<F: Extendable<D>, const D: usize> CircuitBuilder<F, D> {
let mut challenger = RecursiveChallenger::new(self);
let (betas, gammas, alphas, zeta) =
context!(self, "observe proof and generates challenges", {
with_context!(self, "observe proof and generates challenges", {
// Observe the instance.
let digest = HashTarget::from_vec(
self.constants(&inner_common_data.circuit_digest.elements),
@ -69,7 +69,7 @@ impl<F: Extendable<D>, const D: usize> CircuitBuilder<F, D> {
let partial_products = &proof.openings.partial_products;
let zeta_pow_deg = self.exp_power_of_2_extension(zeta, inner_common_data.degree_bits);
let vanishing_polys_zeta = context!(
let vanishing_polys_zeta = with_context!(
self,
"evaluate the vanishing polynomial at our challenge point, zeta.",
eval_vanishing_poly_recursively(
@ -88,7 +88,7 @@ impl<F: Extendable<D>, const D: usize> CircuitBuilder<F, D> {
)
);
context!(self, "check vanishing and quotient polynomials.", {
with_context!(self, "check vanishing and quotient polynomials.", {
let quotient_polys_zeta = &proof.openings.quotient_polys;
let mut scale = ReducingFactorTarget::new(zeta_pow_deg);
let z_h_zeta = self.sub_extension(zeta_pow_deg, one);

View File

@ -1,6 +1,5 @@
use crate::circuit_builder::CircuitBuilder;
use crate::circuit_data::CommonCircuitData;
use crate::context;
use crate::field::extension_field::target::ExtensionTarget;
use crate::field::extension_field::Extendable;
use crate::field::field::Field;
@ -11,6 +10,7 @@ use crate::target::Target;
use crate::util::partial_products::{check_partial_products, check_partial_products_recursively};
use crate::util::reducing::ReducingFactorTarget;
use crate::vars::{EvaluationTargets, EvaluationVars, EvaluationVarsBase};
use crate::with_context;
/// Evaluate the vanishing polynomial at `x`. In this context, the vanishing polynomial is a random
/// linear combination of gate constraints, plus some other terms relating to the permutation
@ -236,7 +236,7 @@ pub fn evaluate_gate_constraints_recursively<F: Extendable<D>, const D: usize>(
) -> Vec<ExtensionTarget<D>> {
let mut constraints = vec![builder.zero_extension(); num_gate_constraints];
for gate in gates {
let gate_constraints = context!(
let gate_constraints = with_context!(
builder,
&format!("evaluate {} constraints", gate.gate.0.id()),
gate.gate
@ -270,7 +270,7 @@ pub(crate) fn eval_vanishing_poly_recursively<F: Extendable<D>, const D: usize>(
let max_degree = common_data.quotient_degree_factor;
let (num_prods, final_num_prod) = common_data.num_partial_products;
let constraint_terms = context!(
let constraint_terms = with_context!(
builder,
"evaluate gate constraints",
evaluate_gate_constraints_recursively(