chore: improve tracing of compiler execution (#3893)

# Description

## Problem\*

Resolves <!-- Link to GitHub Issue -->

## Summary\*

This PR adds more comprehensive tracing through the compiler as well as
allowing us to monitor how long proving/verification takes.

## Additional Context



## Documentation\*

Check one:
- [ ] No documentation needed.
- [ ] Documentation included in this PR.
- [ ] **[Exceptional Case]** Documentation to be submitted in a separate
PR.

# PR Checklist\*

- [ ] I have tested the changes locally.
- [ ] I have formatted the changes with [Prettier](https://prettier.io/)
and/or `cargo fmt` on default settings.

acvm-repo/acvm/src/compiler/optimizers/mod.rs

@@ -6,6 +6,7 @@ mod unused_memory;
 
 pub(crate) use general::GeneralOptimizer;
 pub(crate) use redundant_range::RangeOptimizer;
+use tracing::info;
 
 use self::unused_memory::UnusedMemoryOptimizer;
 
@@ -25,6 +26,8 @@ pub fn optimize(acir: Circuit) -> (Circuit, AcirTransformationMap) {
 /// Applies [`ProofSystemCompiler`][crate::ProofSystemCompiler] independent optimizations to a [`Circuit`].
 #[tracing::instrument(level = "trace", name = "optimize_acir" skip(acir))]
 pub(super) fn optimize_internal(acir: Circuit) -> (Circuit, Vec<usize>) {
+    info!("Number of opcodes before: {}", acir.opcodes.len());
+
     // General optimizer pass
     let opcodes: Vec<Opcode> = acir
         .opcodes
@@ -53,5 +56,7 @@ pub(super) fn optimize_internal(acir: Circuit) -> (Circuit, Vec<usize>) {
     let (acir, acir_opcode_positions) =
         range_optimizer.replace_redundant_ranges(acir_opcode_positions);
 
+    info!("Number of opcodes after: {}", acir.opcodes.len());
+
     (acir, acir_opcode_positions)
 }

compiler/noirc_driver/src/lib.rs

@@ -375,6 +375,7 @@ fn compile_contract_inner(
 /// Compile the current crate using `main_function` as the entrypoint.
 ///
 /// This function assumes [`check_crate`] is called beforehand.
+#[tracing::instrument(level = "trace", skip_all, fields(function_name = context.function_name(&main_function)))]
 pub fn compile_no_check(
     context: &Context,
     options: &CompileOptions,

compiler/noirc_evaluator/src/ssa.rs

@@ -83,7 +83,7 @@ pub(crate) fn optimize_into_acir(
 ///
 /// The output ACIR is is backend-agnostic and so must go through a transformation pass before usage in proof generation.
 #[allow(clippy::type_complexity)]
-#[tracing::instrument(level = "trace", skip(program))]
+#[tracing::instrument(level = "trace", skip_all)]
 pub fn create_circuit(
     program: Program,
     enable_ssa_logging: bool,

compiler/noirc_evaluator/src/ssa/opt/array_use.rs

@@ -14,6 +14,7 @@ impl Ssa {
     /// Map arrays with the last instruction that uses it
     /// For this we simply process all the instructions in execution order
     /// and update the map whenever there is a match
+    #[tracing::instrument(level = "trace", skip(self))]
     pub(crate) fn find_last_array_uses(&self) -> HashMap<ValueId, InstructionId> {
         let mut array_use = HashMap::default();
         for func in self.functions.values() {

compiler/noirc_evaluator/src/ssa/opt/assert_constant.rs

@@ -21,6 +21,7 @@ impl Ssa {
     /// seen by loop unrolling. Furthermore, this pass cannot be a part of loop unrolling
     /// since we must go through every instruction to find all references to `assert_constant`
     /// while loop unrolling only touches blocks with loops in them.
+    #[tracing::instrument(level = "trace", skip(self))]
     pub(crate) fn evaluate_assert_constant(mut self) -> Result<Ssa, RuntimeError> {
         for function in self.functions.values_mut() {
             for block in function.reachable_blocks() {

compiler/noirc_evaluator/src/ssa/opt/constant_folding.rs

@@ -40,6 +40,7 @@ impl Ssa {
     /// Performs constant folding on each instruction.
     ///
     /// See [`constant_folding`][self] module for more information.
+    #[tracing::instrument(level = "trace", skip(self))]
     pub(crate) fn fold_constants(mut self) -> Ssa {
         for function in self.functions.values_mut() {
             constant_fold(function);

compiler/noirc_evaluator/src/ssa/opt/defunctionalize.rs

@@ -52,6 +52,7 @@ struct DefunctionalizationContext {
 }
 
 impl Ssa {
+    #[tracing::instrument(level = "trace", skip(self))]
     pub(crate) fn defunctionalize(mut self) -> Ssa {
         // Find all functions used as value that share the same signature
         let variants = find_variants(&self);

compiler/noirc_evaluator/src/ssa/opt/die.rs

@@ -17,6 +17,7 @@ use crate::ssa::{
 impl Ssa {
     /// Performs Dead Instruction Elimination (DIE) to remove any instructions with
     /// unused results.
+    #[tracing::instrument(level = "trace", skip(self))]
     pub(crate) fn dead_instruction_elimination(mut self) -> Ssa {
         for function in self.functions.values_mut() {
             dead_instruction_elimination(function);

compiler/noirc_evaluator/src/ssa/opt/fill_internal_slices.rs

@@ -60,6 +60,7 @@ use acvm::FieldElement;
 use fxhash::FxHashMap as HashMap;
 
 impl Ssa {
+    #[tracing::instrument(level = "trace", skip(self))]
     pub(crate) fn fill_internal_slices(mut self) -> Ssa {
         for function in self.functions.values_mut() {
             // This pass is only necessary for generating ACIR and thus we should not

compiler/noirc_evaluator/src/ssa/opt/flatten_cfg.rs

@@ -163,6 +163,7 @@ impl Ssa {
     /// This pass will modify any instructions with side effects in particular, often multiplying
     /// them by jump conditions to maintain correctness even when all branches of a jmpif are inlined.
     /// For more information, see the module-level comment at the top of this file.
+    #[tracing::instrument(level = "trace", skip(self))]
     pub(crate) fn flatten_cfg(mut self) -> Ssa {
         flatten_function_cfg(self.main_mut());
         self

compiler/noirc_evaluator/src/ssa/opt/inlining.rs

@@ -36,6 +36,7 @@ impl Ssa {
     /// changes. This is because if the function's id later becomes known by a later
     /// pass, we would need to re-run all of inlining anyway to inline it, so we might
     /// as well save the work for later instead of performing it twice.
+    #[tracing::instrument(level = "trace", skip(self))]
     pub(crate) fn inline_functions(mut self) -> Ssa {
         self.functions = btree_map(get_entry_point_functions(&self), |entry_point| {
             let new_function = InlineContext::new(&self, entry_point).inline_all(&self);

compiler/noirc_evaluator/src/ssa/opt/mem2reg.rs

@@ -86,6 +86,7 @@ use self::block::{Block, Expression};
 impl Ssa {
     /// Attempts to remove any load instructions that recover values that are already available in
     /// scope, and attempts to remove stores that are subsequently redundant.
+    #[tracing::instrument(level = "trace", skip(self))]
     pub(crate) fn mem2reg(mut self) -> Ssa {
         for function in self.functions.values_mut() {
             let mut context = PerFunctionContext::new(function);

compiler/noirc_evaluator/src/ssa/opt/simplify_cfg.rs

@@ -29,6 +29,7 @@ impl Ssa {
     ///    only 1 successor then (2) also will be applied.
     ///
     /// Currently, 1 and 4 are unimplemented.
+    #[tracing::instrument(level = "trace", skip(self))]
     pub(crate) fn simplify_cfg(mut self) -> Self {
         for function in self.functions.values_mut() {
             simplify_function(function);

compiler/noirc_evaluator/src/ssa/opt/unrolling.rs

@@ -36,6 +36,7 @@ use fxhash::FxHashMap as HashMap;
 impl Ssa {
     /// Unroll all loops in each SSA function.
     /// If any loop cannot be unrolled, it is left as-is or in a partially unrolled state.
+    #[tracing::instrument(level = "trace", skip(self))]
     pub(crate) fn unroll_loops(mut self) -> Result<Ssa, RuntimeError> {
         for function in self.functions.values_mut() {
             // Loop unrolling in brillig can lead to a code explosion currently. This can

tooling/backend_interface/src/cli/write_vk.rs

@@ -12,6 +12,7 @@ pub(crate) struct WriteVkCommand {
 }
 
 impl WriteVkCommand {
+    #[tracing::instrument(level = "trace", name = "vk_generation", skip_all)]
     pub(crate) fn run(self, binary_path: &Path) -> Result<(), BackendError> {
         let mut command = std::process::Command::new(binary_path);
 

tooling/backend_interface/src/proof_system.rs

@@ -50,6 +50,7 @@ impl Backend {
         }
     }
 
+    #[tracing::instrument(level = "trace", skip_all)]
     pub fn prove(
         &self,
         circuit: &Circuit,
@@ -90,6 +91,7 @@ impl Backend {
         Ok(proof)
     }
 
+    #[tracing::instrument(level = "trace", skip_all)]
     pub fn verify(
         &self,
         proof: &[u8],