From 718459ba69633fb88aab92aa668c262b10f91dce Mon Sep 17 00:00:00 2001
From: Georg Wiese <georgwiese@gmail.com>
Date: Wed, 17 Jul 2024 11:38:18 +0200
Subject: [PATCH] `CompositeBackend`: Improve logging (#1581)

This should help us to collect more data and get a better understanding
of the factors that drive proof times and sizes.

Example:
```
$ cargo run pil test_data/asm/block_to_block.asm -o output -f --field bn254 --prove-with halo2-composite
...
Instantiating a composite backend with 2 machines:
* main:
  * Number of witness columns: 3
  * Number of fixed columns: 4
  * Number of identities:
    * Polynomial: 3
* main_arith:
  * Number of witness columns: 4
  * Number of fixed columns: 0
  * Number of identities:
    * Polynomial: 2
== Proving machine: main (size 8)
Starting proof generation...
Generating PK for snark...
Generating proof...
Time taken: 151.890834ms
Proof generation done.
==> Machine proof of 1753 bytes computed in 292.9045ms
== Proving machine: main_arith (size 8)
Starting proof generation...
Generating PK for snark...
Generating proof...
Time taken: 154.678333ms
Proof generation done.
==> Machine proof of 1625 bytes computed in 276.353375ms
Proof generation took 0.5694918s
Proof size: 3402 bytes
Writing output/block_to_block_proof.bin.
```
---
 backend/src/composite/mod.rs | 42 +++++++++++++++++++++++++++++++++++-
 1 file changed, 41 insertions(+), 1 deletion(-)

diff --git a/backend/src/composite/mod.rs b/backend/src/composite/mod.rs
index 0ccbe20d9..e162e2466 100644
--- a/backend/src/composite/mod.rs
+++ b/backend/src/composite/mod.rs
@@ -77,6 +77,30 @@ impl<F: FieldElement, B: BackendFactory<F>> BackendFactory<F> for CompositeBacke
             })
             .verification_keys;
 
+        log::info!(
+            "Instantiating a composite backend with {} machines:",
+            pils.len()
+        );
+        for (machine_name, pil) in pils.iter() {
+            let num_witness_columns = pil.committed_polys_in_source_order().len();
+            let num_fixed_columns = pil.constant_polys_in_source_order().len();
+            let num_identities_by_kind = pil
+                .identities
+                .iter()
+                .map(|i| i.kind)
+                .counts()
+                .into_iter()
+                .collect::<BTreeMap<_, _>>();
+
+            log::info!("* {}:", machine_name);
+            log::info!("  * Number of witness columns: {}", num_witness_columns);
+            log::info!("  * Number of fixed columns: {}", num_fixed_columns);
+            log::info!("  * Number of identities:");
+            for (kind, count) in num_identities_by_kind {
+                log::info!("    * {:?}: {}", kind, count);
+            }
+        }
+
         let machine_data = pils
             .into_iter()
             .zip_eq(verification_keys.into_iter())
@@ -157,9 +181,25 @@ impl<'a, F: FieldElement> Backend<'a, F> for CompositeBackend<'a, F> {
                     log::info!("== Proving machine: {} (size {})", machine, pil.degree());
                     log::debug!("PIL:\n{}", pil);
 
+                    let start = std::time::Instant::now();
+
                     let witness = machine_witness_columns(witness, pil, machine);
 
-                    backend.prove(&witness, None, witgen_callback)
+                    let proof = backend.prove(&witness, None, witgen_callback);
+
+                    match &proof {
+                        Ok(proof) => {
+                            log::info!(
+                                "==> Machine proof of {} bytes computed in {:?}",
+                                proof.len(),
+                                start.elapsed()
+                            );
+                        }
+                        Err(e) => {
+                            log::error!("==> Machine proof failed: {:?}", e);
+                        }
+                    };
+                    proof
                 })
                 .collect::<Result<_, _>>()?,
         };