chore: fix logging (#2157)

Author: ratankaliani

crates/core/machine/src/shape/mod.rs

@@ -114,10 +114,10 @@ impl<F: PrimeField32> CoreShapeConfig<F> {
                     })?;
 
                 let shard = record.shard();
-                tracing::info!("Shard Lifted: Index={}, Cluster={}", shard, cluster_index);
+                tracing::debug!("Shard Lifted: Index={}, Cluster={}", shard, cluster_index);
                 for (air, height) in heights.iter() {
                     if shape.contains(air) {
-                        tracing::info!(
+                        tracing::debug!(
                             "Chip {:<20}: {:<3} -> {:<3}",
                             air,
                             log2_ceil_usize(*height),
@@ -147,11 +147,11 @@ impl<F: PrimeField32> CoreShapeConfig<F> {
                     .ok_or_else(|| CoreShapeError::ShapeError(record.debug_stats()))?;
 
                 let shard = record.shard();
-                tracing::info!("Shard Lifted: Index={}, Cluster={}", shard, cluster_index);
+                tracing::debug!("Shard Lifted: Index={}, Cluster={}", shard, cluster_index);
 
                 for (air, height) in heights.iter() {
                     if shape.contains(air) {
-                        tracing::info!(
+                        tracing::debug!(
                             "Chip {:<20}: {:<3} -> {:<3}",
                             air,
                             log2_ceil_usize(*height),

crates/core/machine/src/utils/prove.rs

@@ -270,7 +270,7 @@ where
                                 // See if any deferred shards are ready to be committed to.
                                 let mut deferred =
                                     deferred.split(done, last_record, opts.split_opts);
-                                tracing::info!("deferred {} records", deferred.len());
+                                tracing::debug!("deferred {} records", deferred.len());
 
                                 // Update the public values & prover state for the shards which do not
                                 // contain "cpu events" before committing to them.
@@ -323,7 +323,7 @@ where
                             if shape_fixed_records.is_none() {
                                 // See if any deferred shards are ready to be committed to.
                                 let mut deferred = deferred.split(done, None, opts.split_opts);
-                                tracing::info!("deferred {} records", deferred.len());
+                                tracing::debug!("deferred {} records", deferred.len());
 
                                 // Update the public values & prover state for the shards which do not
                                 // contain "cpu events" before committing to them.
@@ -523,15 +523,15 @@ where
 
         // Log some of the `ExecutionReport` information.
         let mut report_aggregate = report_aggregate.lock().unwrap();
-        tracing::info!(
+        tracing::debug!(
             "execution report (totals): total_cycles={}, total_syscall_cycles={}, touched_memory_addresses={}",
             report_aggregate.total_instruction_count(),
             report_aggregate.total_syscall_count(),
             report_aggregate.touched_memory_addresses,
         );
         match gas {
             Some(Ok(gas)) => {
-                tracing::info!("execution report (gas): {}", gas);
+                tracing::debug!("execution report (gas): {}", gas);
                 report_aggregate.gas = Some(gas);
             }
             Some(Err(err)) => tracing::error!("Encountered error while calculating gas: {}", err),
@@ -540,21 +540,21 @@ where
 
         // Print the opcode and syscall count tables like `du`: sorted by count (descending) and
         // with the count in the first column.
-        tracing::info!("execution report (opcode counts):");
+        tracing::debug!("execution report (opcode counts):");
         let (width, lines) = sorted_table_lines(report_aggregate.opcode_counts.as_ref());
         for (label, count) in lines {
             if *count > 0 {
-                tracing::info!("  {}", format_table_line(&width, &label, count));
+                tracing::debug!("  {}", format_table_line(&width, &label, count));
             } else {
                 tracing::debug!("  {}", format_table_line(&width, &label, count));
             }
         }
 
-        tracing::info!("execution report (syscall counts):");
+        tracing::debug!("execution report (syscall counts):");
         let (width, lines) = sorted_table_lines(report_aggregate.syscall_counts.as_ref());
         for (label, count) in lines {
             if *count > 0 {
-                tracing::info!("  {}", format_table_line(&width, &label, count));
+                tracing::debug!("  {}", format_table_line(&width, &label, count));
             } else {
                 tracing::debug!("  {}", format_table_line(&width, &label, count));
             }
@@ -564,7 +564,7 @@ where
 
         // Print the summary.
         let proving_time = proving_start.elapsed().as_secs_f64();
-        tracing::info!(
+        tracing::debug!(
             "summary: cycles={}, e2e={}s, khz={:.2}",
             cycles,
             proving_time,

crates/prover/src/lib.rs

@@ -206,7 +206,7 @@ impl<C: SP1ProverComponents> SP1Prover<C> {
 
         let vk_verification =
             env::var("VERIFY_VK").map(|v| v.eq_ignore_ascii_case("true")).unwrap_or(true);
-        tracing::info!("vk verification: {}", vk_verification);
+        tracing::debug!("vk verification: {}", vk_verification);
 
         // Read the shapes from the shapes directory and deserialize them into memory.
         let allowed_vk_map: BTreeMap<[BabyBear; DIGEST_SIZE], usize> = if vk_verification {
@@ -846,7 +846,7 @@ impl<C: SP1ProverComponents> SP1Prover<C> {
                 handle.join().unwrap();
             }
             handle.join().unwrap();
-            tracing::info!("joined handles");
+            tracing::debug!("joined handles");
 
             let (_, _, vk, proof) = proofs_rx.lock().unwrap().recv().unwrap();
             (vk, proof)
@@ -954,7 +954,7 @@ impl<C: SP1ProverComponents> SP1Prover<C> {
         tracing::debug!("wrap proving time: {:?}", elapsed);
         let mut wrap_challenger = self.wrap_prover.config().challenger();
         self.wrap_prover.machine().verify(&wrap_vk, &wrap_proof, &mut wrap_challenger).unwrap();
-        tracing::info!("wrapping successful");
+        tracing::debug!("wrapping successful");
 
         Ok(SP1ReduceProof { vk: wrap_vk, proof: wrap_proof.shard_proofs.pop().unwrap() })
     }

crates/prover/src/shapes.rs

@@ -83,7 +83,7 @@ pub fn check_shapes<C: SP1ProverComponents>(
     )
     .collect::<BTreeSet<SP1ProofShape>>();
     let num_shapes = all_maximal_shapes.len();
-    tracing::info!("number of shapes: {}", num_shapes);
+    tracing::debug!("number of shapes: {}", num_shapes);
 
     // The Merkle tree height.
     let height = num_shapes.next_power_of_two().ilog2() as usize;
@@ -99,7 +99,7 @@ pub fn check_shapes<C: SP1ProverComponents>(
             let panic_tx = panic_tx.clone();
             s.spawn(move || {
                 while let Ok(shape) = shape_rx.lock().unwrap().recv() {
-                    tracing::info!("shape is {:?}", shape);
+                    tracing::debug!("shape is {:?}", shape);
                     let program = catch_unwind(AssertUnwindSafe(|| {
                         // Try to build the recursion program from the given shape.
                         prover.program_from_shape(shape.clone(), None)
@@ -168,7 +168,7 @@ pub fn build_vk_map<C: SP1ProverComponents + 'static>(
         let height = dummy_set.len().next_power_of_two().ilog2() as usize;
         (dummy_set, vec![], height)
     } else {
-        tracing::info!("building vk map");
+        tracing::debug!("building vk map");
 
         // Setup the channels.
         let (vk_tx, vk_rx) = std::sync::mpsc::channel();
@@ -193,7 +193,7 @@ pub fn build_vk_map<C: SP1ProverComponents + 'static>(
         }
 
         let num_shapes = all_shapes.len();
-        tracing::info!("number of shapes: {} in {:?}", num_shapes, start.elapsed());
+        tracing::debug!("number of shapes: {} in {:?}", num_shapes, start.elapsed());
 
         let height = num_shapes.next_power_of_two().ilog2() as usize;
         let chunk_size = indices_set.as_ref().map(|indices| indices.len()).unwrap_or(num_shapes);
@@ -260,7 +260,7 @@ pub fn build_vk_map<C: SP1ProverComponents + 'static>(
                         let vk = vk.unwrap();
 
                         let vk_digest = vk.hash_babybear();
-                        tracing::info!(
+                        tracing::debug!(
                             "program {} = {:?}, {}% done",
                             i,
                             vk_digest,
@@ -296,14 +296,14 @@ pub fn build_vk_map<C: SP1ProverComponents + 'static>(
             let panic_indices = panic_rx.iter().collect::<Vec<_>>();
             for (i, shape) in subset_shapes {
                 if panic_indices.contains(&i) {
-                    tracing::info!("panic shape {}: {:?}", i, shape);
+                    tracing::debug!("panic shape {}: {:?}", i, shape);
                 }
             }
 
             (vk_set, panic_indices, height)
         })
     };
-    tracing::info!("compress vks generated, number of keys: {}", vk_set.len());
+    tracing::debug!("compress vks generated, number of keys: {}", vk_set.len());
     (vk_set, panic_indices, height)
 }