plonky2/src/context_tree.rs
Daniel Lubarov 9081ae7337
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
2021-07-26 16:21:14 -07:00

141 lines
4.2 KiB
Rust

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.
exit_gate_count: Option<usize>,
/// Any child contexts.
children: Vec<ContextTree>,
}
impl ContextTree {
pub fn new() -> Self {
Self {
name: "root".to_string(),
level: Level::Debug,
enter_gate_count: 0,
exit_gate_count: None,
children: vec![],
}
}
/// Whether this context is still in scope.
fn is_open(&self) -> bool {
self.exit_gate_count.is_none()
}
/// A description of the stack of currently-open scopes.
pub fn open_stack(&self) -> String {
let mut stack = Vec::new();
self.open_stack_helper(&mut stack);
stack.join(" > ")
}
fn open_stack_helper(&self, stack: &mut Vec<String>) {
if self.is_open() {
stack.push(self.name.clone());
if let Some(last_child) = self.children.last() {
last_child.open_stack_helper(stack);
}
}
}
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, 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![],
})
}
/// Close the deepest open context from this tree.
pub fn pop(&mut self, current_gate_count: usize) {
assert!(self.is_open());
if let Some(last_child) = self.children.last_mut() {
if last_child.is_open() {
last_child.pop(current_gate_count);
return;
}
}
self.exit_gate_count = Some(current_gate_count);
}
fn gate_count_delta(&self, current_gate_count: usize) -> usize {
self.exit_gate_count.unwrap_or(current_gate_count) - self.enter_gate_count
}
/// Filter out children with a low gate count.
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
.children
.iter()
.filter(|c| c.gate_count_delta(current_gate_count) >= min_delta)
.map(|c| c.filter(current_gate_count, min_delta))
.collect(),
}
}
pub fn print(&self, current_gate_count: usize) {
self.print_helper(current_gate_count, 0);
}
fn print_helper(&self, current_gate_count: usize, depth: usize) {
let prefix = "| ".repeat(depth);
log!(
self.level,
"{}{} gates to {}",
prefix,
self.gate_count_delta(current_gate_count),
self.name
);
for child in &self.children {
child.print_helper(current_gate_count, depth + 1);
}
}
}
/// Creates a named scope; useful for debugging.
#[macro_export]
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(log::Level::Debug, $ctx);
let res = $exp;
$builder.pop_context();
res
}};
}