From b5949195631be6b9e2eafdafeaa744632ae172c8 Mon Sep 17 00:00:00 2001 From: Koby Hall <102518238+kobyhallx@users.noreply.github.com> Date: Wed, 20 Dec 2023 17:08:36 +0100 Subject: [PATCH] chore: replace `env-logger` with `tracing` (#3878) # Description ## Problem\* While env-logger concerns itself with logging, tracing is drop in replacement to support logging case but also provides more features for profiling. ## Summary\* ## Additional Context ## Documentation\* Check one: - [x] No documentation needed. - [ ] Documentation included in this PR. - [ ] **[Exceptional Case]** Documentation to be submitted in a separate PR. # PR Checklist\* - [x] I have tested the changes locally. - [x] I have formatted the changes with [Prettier](https://prettier.io/) and/or `cargo fmt` on default settings. --------- Co-authored-by: Tom French Co-authored-by: Tom French <15848336+TomAFrench@users.noreply.github.com> --- Cargo.lock | 120 ++++++++---------- Cargo.toml | 3 +- acvm-repo/acvm/Cargo.toml | 2 +- acvm-repo/acvm/src/compiler/optimizers/mod.rs | 5 +- .../acvm/src/compiler/transformers/mod.rs | 5 +- acvm-repo/acvm_js/Cargo.toml | 7 +- acvm-repo/acvm_js/src/lib.rs | 2 +- acvm-repo/acvm_js/src/logging.rs | 31 ++--- compiler/noirc_driver/Cargo.toml | 2 +- compiler/noirc_driver/src/lib.rs | 8 +- compiler/noirc_errors/Cargo.toml | 2 +- compiler/noirc_errors/src/debug_info.rs | 3 +- compiler/noirc_evaluator/Cargo.toml | 2 +- compiler/noirc_evaluator/src/ssa.rs | 17 +-- .../noirc_evaluator/src/ssa/acir_gen/mod.rs | 1 + compiler/noirc_frontend/Cargo.toml | 2 +- .../src/monomorphization/mod.rs | 3 +- compiler/wasm/Cargo.toml | 5 +- compiler/wasm/src/lib.rs | 21 ++- tooling/backend_interface/Cargo.toml | 2 +- tooling/backend_interface/src/lib.rs | 5 +- tooling/backend_interface/src/proof_system.rs | 3 +- tooling/nargo/Cargo.toml | 2 +- tooling/nargo/src/ops/execute.rs | 7 +- tooling/nargo_cli/Cargo.toml | 4 +- tooling/nargo_cli/src/main.rs | 15 ++- 26 files changed, 128 insertions(+), 151 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 223f7eb2152..0c4638f4001 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -43,13 +43,13 @@ dependencies = [ "acvm_blackbox_solver", "brillig_vm", "indexmap 1.9.3", - "log", "num-bigint", "num-traits", "paste", "proptest", "rand", "thiserror", + "tracing", ] [[package]] @@ -77,13 +77,14 @@ dependencies = [ "const-str", "gloo-utils", "js-sys", - "log", "pkg-config", "serde", + "tracing", + "tracing-subscriber", + "tracing-web", "wasm-bindgen", "wasm-bindgen-futures", "wasm-bindgen-test", - "wasm-logger", ] [[package]] @@ -400,17 +401,6 @@ dependencies = [ "waitpid-any", ] -[[package]] -name = "atty" -version = "0.2.14" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "d9b39be18770d11421cdb1b9947a45dd3f37e93092cbf377614828a319d5fee8" -dependencies = [ - "hermit-abi 0.1.19", - "libc", - "winapi", -] - [[package]] name = "autocfg" version = "1.1.0" @@ -435,7 +425,6 @@ dependencies = [ "const_format", "dirs", "flate2", - "log", "reqwest", "serde", "serde_json", @@ -443,6 +432,7 @@ dependencies = [ "tempfile", "test-binary", "thiserror", + "tracing", ] [[package]] @@ -1507,19 +1497,6 @@ dependencies = [ "syn 2.0.26", ] -[[package]] -name = "env_logger" -version = "0.9.3" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "a12e6657c4c97ebab115a42dcee77225f7f482cdd841cf7088c657a42e9e00e7" -dependencies = [ - "atty", - "humantime", - "log", - "regex", - "termcolor", -] - [[package]] name = "equivalent" version = "1.0.1" @@ -1945,15 +1922,6 @@ version = "0.4.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "95505c38b4572b2d910cecb0281560f54b440a19336cbbcb27bf6ce6adc6f5a8" -[[package]] -name = "hermit-abi" -version = "0.1.19" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "62b467343b94ba476dcb2500d242dadbb39557df889310ac77c5d99100aaac33" -dependencies = [ - "libc", -] - [[package]] name = "hermit-abi" version = "0.3.2" @@ -2009,12 +1977,6 @@ version = "1.0.2" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "c4a1e36c821dbe04574f602848a19f742f4fb3c98d40449f11bcad18d6b17421" -[[package]] -name = "humantime" -version = "2.1.0" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "9a3a5bfb195931eeb336b2a7b4d761daec841b97f947d34394601737a7bba5e4" - [[package]] name = "hyper" version = "0.14.27" @@ -2212,7 +2174,7 @@ version = "0.4.9" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "cb0889898416213fab133e1d33a0e5858a48177452750691bde3666d0fdbaf8b" dependencies = [ - "hermit-abi 0.3.2", + "hermit-abi", "rustix", "windows-sys 0.48.0", ] @@ -2356,6 +2318,15 @@ dependencies = [ "libc", ] +[[package]] +name = "matchers" +version = "0.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8263075bb86c5a1b1427b5ae862e8889656f126e9f77c484496e8b47cf5c5558" +dependencies = [ + "regex-automata 0.1.10", +] + [[package]] name = "memchr" version = "2.5.0" @@ -2447,7 +2418,6 @@ dependencies = [ "codespan-reporting", "fm", "iter-extended", - "log", "noirc_abi", "noirc_driver", "noirc_errors", @@ -2459,6 +2429,7 @@ dependencies = [ "serde", "tempfile", "thiserror", + "tracing", ] [[package]] @@ -2479,7 +2450,6 @@ dependencies = [ "criterion", "dap", "dirs", - "env_logger", "fm", "hex", "iai", @@ -2510,7 +2480,6 @@ dependencies = [ "tokio-util", "toml", "tower", - "tracing", "tracing-appender", "tracing-subscriber", ] @@ -2629,14 +2598,14 @@ dependencies = [ "getrandom", "gloo-utils", "js-sys", - "log", "nargo", "noirc_driver", "noirc_errors", "noirc_frontend", "serde", + "tracing-subscriber", + "tracing-web", "wasm-bindgen", - "wasm-logger", ] [[package]] @@ -2684,13 +2653,13 @@ dependencies = [ "fm", "fxhash", "iter-extended", - "log", "noirc_abi", "noirc_errors", "noirc_evaluator", "noirc_frontend", "rust-embed", "serde", + "tracing", ] [[package]] @@ -2702,9 +2671,9 @@ dependencies = [ "codespan", "codespan-reporting", "fm", - "log", "serde", "serde_with", + "tracing", ] [[package]] @@ -2715,12 +2684,12 @@ dependencies = [ "fxhash", "im", "iter-extended", - "log", "noirc_errors", "noirc_frontend", "num-bigint", "serde", "thiserror", + "tracing", ] [[package]] @@ -2732,7 +2701,6 @@ dependencies = [ "chumsky", "fm", "iter-extended", - "log", "noirc_errors", "noirc_printable_type", "regex", @@ -2745,6 +2713,7 @@ dependencies = [ "strum_macros", "tempfile", "thiserror", + "tracing", ] [[package]] @@ -2822,7 +2791,7 @@ version = "1.16.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "4161fcb6d602d4d2081af7c3a45852d875a03dd337a6bfdd6e06407b61342a43" dependencies = [ - "hermit-abi 0.3.2", + "hermit-abi", "libc", ] @@ -3142,7 +3111,7 @@ dependencies = [ "rand", "rand_chacha", "rand_xorshift", - "regex-syntax", + "regex-syntax 0.7.4", "rusty-fork", "tempfile", "unarray", @@ -3326,7 +3295,7 @@ dependencies = [ "aho-corasick", "memchr", "regex-automata 0.3.3", - "regex-syntax", + "regex-syntax 0.7.4", ] [[package]] @@ -3334,6 +3303,9 @@ name = "regex-automata" version = "0.1.10" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "6c230d73fb8d8c1b9c0b3135c5142a8acee3a0558fb8db5cf1cb65f8d7862132" +dependencies = [ + "regex-syntax 0.6.29", +] [[package]] name = "regex-automata" @@ -3343,9 +3315,15 @@ checksum = "39354c10dd07468c2e73926b23bb9c2caca74c5501e38a35da70406f1d923310" dependencies = [ "aho-corasick", "memchr", - "regex-syntax", + "regex-syntax 0.7.4", ] +[[package]] +name = "regex-syntax" +version = "0.6.29" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f162c6dd7b008981e4d40210aca20b4bd0f9b60ca9271061b07f78537722f2e1" + [[package]] name = "regex-syntax" version = "0.7.4" @@ -4522,14 +4500,31 @@ version = "0.3.18" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "ad0f048c97dbd9faa9b7df56362b8ebcaa52adb06b498c050d2f4e32f90a7a8b" dependencies = [ + "matchers", "nu-ansi-term", + "once_cell", + "regex", "sharded-slab", "smallvec", "thread_local", + "tracing", "tracing-core", "tracing-log", ] +[[package]] +name = "tracing-web" +version = "0.1.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b9e6a141feebd51f8d91ebfd785af50fca223c570b86852166caa3b141defe7c" +dependencies = [ + "js-sys", + "tracing-core", + "tracing-subscriber", + "wasm-bindgen", + "web-sys", +] + [[package]] name = "trie-rs" version = "0.1.1" @@ -4812,17 +4807,6 @@ dependencies = [ "leb128", ] -[[package]] -name = "wasm-logger" -version = "0.2.0" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "074649a66bb306c8f2068c9016395fa65d8e08d2affcbf95acf3c24c3ab19718" -dependencies = [ - "log", - "wasm-bindgen", - "web-sys", -] - [[package]] name = "wasmer" version = "4.2.3" diff --git a/Cargo.toml b/Cargo.toml index 59d2af2fab3..7dda111c1a5 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -121,10 +121,11 @@ const_format = "0.2.30" num-bigint = "0.4" num-traits = "0.2" similar-asserts = "1.5.0" -log = "0.4.17" tempfile = "3.6.0" tracing = "0.1.40" +tracing-web = "0.1.3" +tracing-subscriber = { version = "0.3.18", features = ["env-filter"] } [profile.dev] # This is required to be able to run `cargo test` in acvm_js due to the `locals exceeds maximum` error. diff --git a/acvm-repo/acvm/Cargo.toml b/acvm-repo/acvm/Cargo.toml index 5fdf44cbd5e..f5819d6fa34 100644 --- a/acvm-repo/acvm/Cargo.toml +++ b/acvm-repo/acvm/Cargo.toml @@ -16,7 +16,7 @@ repository.workspace = true num-bigint.workspace = true num-traits.workspace = true thiserror.workspace = true -log.workspace = true +tracing.workspace = true acir.workspace = true brillig_vm.workspace = true diff --git a/acvm-repo/acvm/src/compiler/optimizers/mod.rs b/acvm-repo/acvm/src/compiler/optimizers/mod.rs index dd27c0bb937..952bec2f7af 100644 --- a/acvm-repo/acvm/src/compiler/optimizers/mod.rs +++ b/acvm-repo/acvm/src/compiler/optimizers/mod.rs @@ -23,9 +23,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) { - log::trace!("Start circuit optimization"); - // General optimizer pass let opcodes: Vec = acir .opcodes @@ -54,7 +53,5 @@ pub(super) fn optimize_internal(acir: Circuit) -> (Circuit, Vec) { let (acir, acir_opcode_positions) = range_optimizer.replace_redundant_ranges(acir_opcode_positions); - log::trace!("Finish circuit optimization"); - (acir, acir_opcode_positions) } diff --git a/acvm-repo/acvm/src/compiler/transformers/mod.rs b/acvm-repo/acvm/src/compiler/transformers/mod.rs index eef8d7bee44..c9bc91b02c7 100644 --- a/acvm-repo/acvm/src/compiler/transformers/mod.rs +++ b/acvm-repo/acvm/src/compiler/transformers/mod.rs @@ -37,13 +37,12 @@ pub fn transform( /// Applies [`ProofSystemCompiler`][crate::ProofSystemCompiler] specific optimizations to a [`Circuit`]. /// /// Accepts an injected `acir_opcode_positions` to allow transformations to be applied directly after optimizations. +#[tracing::instrument(level = "trace", name = "transform_acir", skip(acir, acir_opcode_positions))] pub(super) fn transform_internal( acir: Circuit, expression_width: ExpressionWidth, acir_opcode_positions: Vec, ) -> (Circuit, Vec) { - log::trace!("Start circuit transformation"); - let mut transformer = match &expression_width { crate::ExpressionWidth::Unbounded => { let transformer = R1CSTransformer::new(acir); @@ -209,7 +208,5 @@ pub(super) fn transform_internal( ..acir }; - log::trace!("Finish circuit transformation"); - (acir, new_acir_opcode_positions) } diff --git a/acvm-repo/acvm_js/Cargo.toml b/acvm-repo/acvm_js/Cargo.toml index 06903fec3f5..987006f8e2b 100644 --- a/acvm-repo/acvm_js/Cargo.toml +++ b/acvm-repo/acvm_js/Cargo.toml @@ -25,11 +25,12 @@ wasm-bindgen.workspace = true wasm-bindgen-futures.workspace = true console_error_panic_hook.workspace = true gloo-utils.workspace = true -js-sys.workspace = true -log.workspace = true +js-sys.workspace = true +tracing.workspace = true +tracing-subscriber.workspace = true +tracing-web.workspace = true serde = { version = "1.0.136", features = ["derive"] } -wasm-logger = "0.2.0" const-str = "0.5.5" [build-dependencies] diff --git a/acvm-repo/acvm_js/src/lib.rs b/acvm-repo/acvm_js/src/lib.rs index ba2a37bf984..88afd1767c9 100644 --- a/acvm-repo/acvm_js/src/lib.rs +++ b/acvm-repo/acvm_js/src/lib.rs @@ -24,7 +24,7 @@ cfg_if::cfg_if! { pub use compression::{compress_witness, decompress_witness}; pub use execute::{execute_circuit, execute_circuit_with_black_box_solver, create_black_box_solver}; pub use js_witness_map::JsWitnessMap; - pub use logging::{init_log_level, LogLevel}; + pub use logging::init_log_level; pub use public_witness::{get_public_parameters_witness, get_public_witness, get_return_witness}; pub use js_execution_error::JsExecutionError; } diff --git a/acvm-repo/acvm_js/src/logging.rs b/acvm-repo/acvm_js/src/logging.rs index d939c5f8367..f5d71fae067 100644 --- a/acvm-repo/acvm_js/src/logging.rs +++ b/acvm-repo/acvm_js/src/logging.rs @@ -1,31 +1,26 @@ -use js_sys::JsString; -use log::Level; -use std::str::FromStr; +use tracing_subscriber::prelude::*; +use tracing_subscriber::EnvFilter; +use tracing_web::MakeWebConsoleWriter; use wasm_bindgen::prelude::*; -#[wasm_bindgen(typescript_custom_section)] -const LOG_LEVEL: &'static str = r#" -export type LogLevel = "OFF" | "ERROR" | "WARN" | "INFO" | "DEBUG" | "TRACE"; -"#; - -#[wasm_bindgen] -extern "C" { - #[wasm_bindgen(extends = JsString, typescript_type = "LogLevel")] - pub type LogLevel; -} - /// Sets the package's logging level. /// /// @param {LogLevel} level - The maximum level of logging to be emitted. #[wasm_bindgen(js_name = initLogLevel, skip_jsdoc)] -pub fn init_log_level(level: LogLevel) { +pub fn init_log_level(filter: String) { // Set the static variable from Rust use std::sync::Once; - let log_level = level.as_string().unwrap(); - let log_level = Level::from_str(&log_level).unwrap_or(Level::Error); + let filter: EnvFilter = + filter.parse().expect("Could not parse log filter while initializing logger"); + static SET_HOOK: Once = Once::new(); SET_HOOK.call_once(|| { - wasm_logger::init(wasm_logger::Config::new(log_level)); + let fmt_layer = tracing_subscriber::fmt::layer() + .with_ansi(false) + .without_time() + .with_writer(MakeWebConsoleWriter::new()); + + tracing_subscriber::registry().with(fmt_layer.with_filter(filter)).init(); }); } diff --git a/compiler/noirc_driver/Cargo.toml b/compiler/noirc_driver/Cargo.toml index 7f431db4398..32c418b0adb 100644 --- a/compiler/noirc_driver/Cargo.toml +++ b/compiler/noirc_driver/Cargo.toml @@ -22,6 +22,6 @@ fm.workspace = true serde.workspace = true fxhash.workspace = true rust-embed = "6.6.0" -log.workspace = true +tracing.workspace = true aztec_macros = { path = "../../aztec_macros" } diff --git a/compiler/noirc_driver/src/lib.rs b/compiler/noirc_driver/src/lib.rs index 926e541c2f3..3908d16e01d 100644 --- a/compiler/noirc_driver/src/lib.rs +++ b/compiler/noirc_driver/src/lib.rs @@ -18,6 +18,7 @@ use noirc_frontend::monomorphization::monomorphize; use noirc_frontend::node_interner::FuncId; use serde::{Deserialize, Serialize}; use std::path::Path; +use tracing::info; mod abi_gen; mod contract; @@ -160,14 +161,13 @@ pub fn add_dep( /// /// This returns a (possibly empty) vector of any warnings found on success. /// On error, this returns a non-empty vector of warnings and error messages, with at least one error. +#[tracing::instrument(level = "trace", skip(context))] pub fn check_crate( context: &mut Context, crate_id: CrateId, deny_warnings: bool, disable_macros: bool, ) -> CompilationResult<()> { - log::trace!("Start checking crate"); - let macros: Vec<&dyn MacroProcessor> = if disable_macros { vec![] } else { @@ -181,8 +181,6 @@ pub fn check_crate( diagnostic.in_file(file_id) })); - log::trace!("Finish checking crate"); - if has_errors(&errors, deny_warnings) { Err(errors) } else { @@ -395,7 +393,7 @@ pub fn compile_no_check( force_compile || options.print_acir || options.show_brillig || options.show_ssa; if !force_compile && hashes_match { - log::info!("Program matches existing artifact, returning early"); + info!("Program matches existing artifact, returning early"); return Ok(cached_program.expect("cache must exist for hashes to match")); } let visibility = program.return_visibility; diff --git a/compiler/noirc_errors/Cargo.toml b/compiler/noirc_errors/Cargo.toml index 812a507550c..02e97b2c670 100644 --- a/compiler/noirc_errors/Cargo.toml +++ b/compiler/noirc_errors/Cargo.toml @@ -15,4 +15,4 @@ fm.workspace = true chumsky.workspace = true serde.workspace = true serde_with = "3.2.0" -log.workspace = true +tracing.workspace = true \ No newline at end of file diff --git a/compiler/noirc_errors/src/debug_info.rs b/compiler/noirc_errors/src/debug_info.rs index 3ae5c193e39..ee40ced19bf 100644 --- a/compiler/noirc_errors/src/debug_info.rs +++ b/compiler/noirc_errors/src/debug_info.rs @@ -38,8 +38,8 @@ impl DebugInfo { /// The [`OpcodeLocation`]s are generated with the ACIR, but passing the ACIR through a transformation step /// renders the old `OpcodeLocation`s invalid. The AcirTransformationMap is able to map the old `OpcodeLocation` to the new ones. /// Note: One old `OpcodeLocation` might have transformed into more than one new `OpcodeLocation`. + #[tracing::instrument(level = "trace", skip(self, update_map))] pub fn update_acir(&mut self, update_map: AcirTransformationMap) { - log::trace!("Start debug info update"); let old_locations = mem::take(&mut self.locations); for (old_opcode_location, source_locations) in old_locations { @@ -47,7 +47,6 @@ impl DebugInfo { self.locations.insert(new_opcode_location, source_locations.clone()); }); } - log::trace!("Finish debug info update"); } pub fn opcode_location(&self, loc: &OpcodeLocation) -> Option> { diff --git a/compiler/noirc_evaluator/Cargo.toml b/compiler/noirc_evaluator/Cargo.toml index 6e7152c6d71..a8f0e8d83a9 100644 --- a/compiler/noirc_evaluator/Cargo.toml +++ b/compiler/noirc_evaluator/Cargo.toml @@ -17,4 +17,4 @@ thiserror.workspace = true num-bigint = "0.4" im = { version = "15.1", features = ["serde"] } serde.workspace = true -log.workspace = true +tracing.workspace = true \ No newline at end of file diff --git a/compiler/noirc_evaluator/src/ssa.rs b/compiler/noirc_evaluator/src/ssa.rs index 6a02a5f6edc..3c814c04eb2 100644 --- a/compiler/noirc_evaluator/src/ssa.rs +++ b/compiler/noirc_evaluator/src/ssa.rs @@ -23,6 +23,7 @@ use noirc_errors::debug_info::DebugInfo; use noirc_frontend::{ hir_def::function::FunctionSignature, monomorphization::ast::Program, Visibility, }; +use tracing::{span, Level}; use self::{acir_gen::GeneratedAcir, ssa_gen::Ssa}; @@ -42,7 +43,8 @@ pub(crate) fn optimize_into_acir( ) -> Result { let abi_distinctness = program.return_distinctness; - log::trace!("Start SSA generation"); + let ssa_gen_span = span!(Level::TRACE, "ssa_generation"); + let ssa_gen_span_guard = ssa_gen_span.enter(); let ssa_builder = SsaBuilder::new(program, print_ssa_passes)? .run_pass(Ssa::defunctionalize, "After Defunctionalization:") .run_pass(Ssa::inline_functions, "After Inlining:") @@ -70,28 +72,23 @@ pub(crate) fn optimize_into_acir( let ssa = ssa_builder .run_pass(Ssa::fill_internal_slices, "After Fill Internal Slice Dummy Data:") .finish(); - log::trace!("Finish SSA generation"); + drop(ssa_gen_span_guard); let last_array_uses = ssa.find_last_array_uses(); - log::trace!("Start ACIR generation"); - let acir = ssa.into_acir(brillig, abi_distinctness, &last_array_uses); - log::trace!("Finish ACIR generation"); - - acir + ssa.into_acir(brillig, abi_distinctness, &last_array_uses) } /// Compiles the [`Program`] into [`ACIR`][acvm::acir::circuit::Circuit]. /// /// 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))] pub fn create_circuit( program: Program, enable_ssa_logging: bool, enable_brillig_logging: bool, ) -> Result<(Circuit, DebugInfo, Vec, Vec, Vec), RuntimeError> { - log::trace!("Start circuit generation"); - let func_sig = program.main_function_signature.clone(); let mut generated_acir = optimize_into_acir(program, enable_ssa_logging, enable_brillig_logging)?; @@ -133,8 +130,6 @@ pub fn create_circuit( let (optimized_circuit, transformation_map) = acvm::compiler::optimize(circuit); debug_info.update_acir(transformation_map); - log::trace!("Finish circuit generation"); - Ok((optimized_circuit, debug_info, input_witnesses, return_witnesses, warnings)) } diff --git a/compiler/noirc_evaluator/src/ssa/acir_gen/mod.rs b/compiler/noirc_evaluator/src/ssa/acir_gen/mod.rs index 01056355915..6a48dadaf30 100644 --- a/compiler/noirc_evaluator/src/ssa/acir_gen/mod.rs +++ b/compiler/noirc_evaluator/src/ssa/acir_gen/mod.rs @@ -156,6 +156,7 @@ impl AcirValue { } impl Ssa { + #[tracing::instrument(level = "trace", skip_all)] pub(crate) fn into_acir( self, brillig: Brillig, diff --git a/compiler/noirc_frontend/Cargo.toml b/compiler/noirc_frontend/Cargo.toml index aa3a8e9f6b8..80d767f7f2c 100644 --- a/compiler/noirc_frontend/Cargo.toml +++ b/compiler/noirc_frontend/Cargo.toml @@ -22,7 +22,7 @@ serde.workspace = true rustc-hash = "1.1.0" small-ord-set = "0.1.3" regex = "1.9.1" -log.workspace = true +tracing.workspace = true [dev-dependencies] strum = "0.24" diff --git a/compiler/noirc_frontend/src/monomorphization/mod.rs b/compiler/noirc_frontend/src/monomorphization/mod.rs index 52b8d5bfd79..39b05dcd5ac 100644 --- a/compiler/noirc_frontend/src/monomorphization/mod.rs +++ b/compiler/noirc_frontend/src/monomorphization/mod.rs @@ -91,8 +91,8 @@ type HirType = crate::Type; /// Note that there is no requirement on the `main` function that can be passed into /// this function. Typically, this is the function named "main" in the source project, /// but it can also be, for example, an arbitrary test function for running `nargo test`. +#[tracing::instrument(level = "trace", skip(main, interner))] pub fn monomorphize(main: node_interner::FuncId, interner: &NodeInterner) -> Program { - log::trace!("Start monomorphization"); let mut monomorphizer = Monomorphizer::new(interner); let function_sig = monomorphizer.compile_main(main); @@ -108,7 +108,6 @@ pub fn monomorphize(main: node_interner::FuncId, interner: &NodeInterner) -> Pro let functions = vecmap(monomorphizer.finished_functions, |(_, f)| f); let FuncMeta { return_distinctness, return_visibility, .. } = interner.function_meta(&main); - log::trace!("Finish monomorphization"); Program::new( functions, function_sig, diff --git a/compiler/wasm/Cargo.toml b/compiler/wasm/Cargo.toml index 58ad7764fdc..7ea138b60a4 100644 --- a/compiler/wasm/Cargo.toml +++ b/compiler/wasm/Cargo.toml @@ -23,9 +23,8 @@ serde.workspace = true js-sys.workspace = true console_error_panic_hook.workspace = true gloo-utils.workspace = true -log.workspace = true - -wasm-logger = "0.2.0" +tracing-subscriber.workspace = true +tracing-web.workspace = true # This is an unused dependency, we are adding it # so that we can enable the js feature in getrandom. diff --git a/compiler/wasm/src/lib.rs b/compiler/wasm/src/lib.rs index d0394589578..e10b992a00e 100644 --- a/compiler/wasm/src/lib.rs +++ b/compiler/wasm/src/lib.rs @@ -6,11 +6,12 @@ use getrandom as _; use gloo_utils::format::JsValueSerdeExt; -use log::Level; + use noirc_driver::{GIT_COMMIT, GIT_DIRTY, NOIRC_VERSION}; use serde::{Deserialize, Serialize}; -use std::str::FromStr; -use wasm_bindgen::prelude::*; +use tracing_subscriber::prelude::*; +use tracing_subscriber::EnvFilter; +use tracing_web::MakeWebConsoleWriter; mod compile; mod compile_new; @@ -20,6 +21,7 @@ pub use compile::compile; // Expose the new Context-Centric API pub use compile_new::{compile_, CompilerContext, CrateIDWrapper}; +use wasm_bindgen::{prelude::wasm_bindgen, JsValue}; #[derive(Serialize, Deserialize)] pub struct BuildInfo { @@ -29,14 +31,21 @@ pub struct BuildInfo { } #[wasm_bindgen] -pub fn init_log_level(level: String) { +pub fn init_log_level(filter: String) { // Set the static variable from Rust use std::sync::Once; - let log_level = Level::from_str(&level).unwrap_or(Level::Error); + let filter: EnvFilter = + filter.parse().expect("Could not parse log filter while initializing logger"); + static SET_HOOK: Once = Once::new(); SET_HOOK.call_once(|| { - wasm_logger::init(wasm_logger::Config::new(log_level)); + let fmt_layer = tracing_subscriber::fmt::layer() + .with_ansi(false) + .without_time() + .with_writer(MakeWebConsoleWriter::new()); + + tracing_subscriber::registry().with(fmt_layer.with_filter(filter)).init(); }); } diff --git a/tooling/backend_interface/Cargo.toml b/tooling/backend_interface/Cargo.toml index 32c5d28e3b0..2d991f9ae6c 100644 --- a/tooling/backend_interface/Cargo.toml +++ b/tooling/backend_interface/Cargo.toml @@ -16,7 +16,7 @@ thiserror.workspace = true serde.workspace = true serde_json.workspace = true bb_abstraction_leaks.workspace = true -log.workspace = true +tracing.workspace = true tempfile.workspace = true diff --git a/tooling/backend_interface/src/lib.rs b/tooling/backend_interface/src/lib.rs index 8ed164fc217..c15383086eb 100644 --- a/tooling/backend_interface/src/lib.rs +++ b/tooling/backend_interface/src/lib.rs @@ -12,6 +12,7 @@ pub use bb_abstraction_leaks::ACVM_BACKEND_BARRETENBERG; use bb_abstraction_leaks::BB_VERSION; use cli::VersionCommand; pub use download::download_backend; +use tracing::warn; const BACKENDS_DIR: &str = ".nargo/backends"; @@ -115,7 +116,7 @@ impl Backend { // If version doesn't match then download the correct version. Ok(version_string) => { - log::warn!("`{ACVM_BACKEND_BARRETENBERG}` version `{version_string}` is different from expected `{BB_VERSION}`. Downloading expected version..."); + warn!("`{ACVM_BACKEND_BARRETENBERG}` version `{version_string}` is different from expected `{BB_VERSION}`. Downloading expected version..."); let bb_url = std::env::var("BB_BINARY_URL") .unwrap_or_else(|_| bb_abstraction_leaks::BB_DOWNLOAD_URL.to_owned()); download_backend(&bb_url, binary_path)?; @@ -123,7 +124,7 @@ impl Backend { // If `bb` fails to report its version, then attempt to fix it by re-downloading the binary. Err(_) => { - log::warn!("Could not determine version of `{ACVM_BACKEND_BARRETENBERG}`. Downloading expected version..."); + warn!("Could not determine version of `{ACVM_BACKEND_BARRETENBERG}`. Downloading expected version..."); let bb_url = std::env::var("BB_BINARY_URL") .unwrap_or_else(|_| bb_abstraction_leaks::BB_DOWNLOAD_URL.to_owned()); download_backend(&bb_url, binary_path)?; diff --git a/tooling/backend_interface/src/proof_system.rs b/tooling/backend_interface/src/proof_system.rs index 01842a81da9..6eee7c890c8 100644 --- a/tooling/backend_interface/src/proof_system.rs +++ b/tooling/backend_interface/src/proof_system.rs @@ -6,6 +6,7 @@ use acvm::acir::{circuit::Circuit, native_types::WitnessMap}; use acvm::ExpressionWidth; use acvm::FieldElement; use tempfile::tempdir; +use tracing::warn; use crate::cli::{ GatesCommand, InfoCommand, ProofAsFieldsCommand, ProveCommand, VerifyCommand, @@ -42,7 +43,7 @@ impl Backend { if let Ok(expression_width) = self.get_backend_info() { expression_width } else { - log::warn!( + warn!( "No valid backend found, ExpressionWidth defaulting to Bounded with a width of 3" ); ExpressionWidth::Bounded { width: 3 } diff --git a/tooling/nargo/Cargo.toml b/tooling/nargo/Cargo.toml index f0733d7ad44..d60f9d3ea28 100644 --- a/tooling/nargo/Cargo.toml +++ b/tooling/nargo/Cargo.toml @@ -24,7 +24,7 @@ iter-extended.workspace = true serde.workspace = true thiserror.workspace = true codespan-reporting.workspace = true -log.workspace = true +tracing.workspace = true rayon = "1.8.0" [dev-dependencies] diff --git a/tooling/nargo/src/ops/execute.rs b/tooling/nargo/src/ops/execute.rs index 2ac85781410..4fc7f7b599f 100644 --- a/tooling/nargo/src/ops/execute.rs +++ b/tooling/nargo/src/ops/execute.rs @@ -7,13 +7,13 @@ use crate::NargoError; use super::foreign_calls::ForeignCallExecutor; +#[tracing::instrument(level = "trace", skip_all)] pub fn execute_circuit( circuit: &Circuit, initial_witness: WitnessMap, blackbox_solver: &B, foreign_call_executor: &mut F, ) -> Result { - log::trace!("Start circuit execution"); let mut acvm = ACVM::new(blackbox_solver, &circuit.opcodes, initial_witness); loop { @@ -55,8 +55,5 @@ pub fn execute_circuit( } } - let solved_witness = acvm.finalize(); - - log::trace!("Finish circuit execution"); - Ok(solved_witness) + Ok(acvm.finalize()) } diff --git a/tooling/nargo_cli/Cargo.toml b/tooling/nargo_cli/Cargo.toml index 65d3599bf35..f280682e15c 100644 --- a/tooling/nargo_cli/Cargo.toml +++ b/tooling/nargo_cli/Cargo.toml @@ -46,7 +46,6 @@ hex.workspace = true similar-asserts.workspace = true termcolor = "1.1.2" color-eyre = "0.6.2" -env_logger = "0.9.0" tokio = { version = "1.0", features = ["io-std"] } dap.workspace = true @@ -55,8 +54,7 @@ backend-interface = { path = "../backend_interface" } bb_abstraction_leaks.workspace = true # Logs -tracing.workspace = true -tracing-subscriber = "0.3.18" +tracing-subscriber.workspace = true tracing-appender = "0.2.3" [target.'cfg(not(unix))'.dependencies] diff --git a/tooling/nargo_cli/src/main.rs b/tooling/nargo_cli/src/main.rs index 7eeca2ab2b0..3f797b0bf0c 100644 --- a/tooling/nargo_cli/src/main.rs +++ b/tooling/nargo_cli/src/main.rs @@ -14,22 +14,27 @@ mod errors; use std::env; use color_eyre::config::HookBuilder; -use env_logger::{Builder, Env}; + use tracing_appender::rolling; +use tracing_subscriber::{fmt::format::FmtSpan, EnvFilter}; const PANIC_MESSAGE: &str = "This is a bug. We may have already fixed this in newer versions of Nargo so try searching for similar issues at https://github.com/noir-lang/noir/issues/.\nIf there isn't an open issue for this bug, consider opening one at https://github.com/noir-lang/noir/issues/new?labels=bug&template=bug_report.yml"; fn main() { - let env = Env::default().filter_or("NOIR_LOG", "error"); // Default to 'error' if NOIR_LOG is not set - Builder::from_env(env).init(); - // Setup tracing if let Ok(log_dir) = env::var("NARGO_LOG_DIR") { let debug_file = rolling::daily(log_dir, "nargo-log"); tracing_subscriber::fmt() + .with_span_events(FmtSpan::ACTIVE) .with_writer(debug_file) .with_ansi(false) - .with_max_level(tracing::Level::TRACE) + .with_env_filter(EnvFilter::from_default_env()) + .init(); + } else { + tracing_subscriber::fmt() + .with_span_events(FmtSpan::ACTIVE) + .with_ansi(true) + .with_env_filter(EnvFilter::from_env("NOIR_LOG")) .init(); }