From 842d72f9dd53e79784295ee801ab5ead61b24dfb Mon Sep 17 00:00:00 2001 From: TomAFrench Date: Mon, 23 Dec 2024 14:09:48 +0000 Subject: [PATCH 01/19] chore: use logs for benchmarking --- Cargo.lock | 13 ++++++++++ Cargo.toml | 2 +- test_programs/compilation_report.sh | 37 +++++++++++++++++++---------- test_programs/parse_time.sh | 21 ++++++++++++++++ tooling/nargo_cli/src/main.rs | 34 +++++++++++++------------- 5 files changed, 77 insertions(+), 30 deletions(-) create mode 100755 test_programs/parse_time.sh diff --git a/Cargo.lock b/Cargo.lock index 62a513c4cc1..8f8d02af77a 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -5062,6 +5062,16 @@ dependencies = [ "tracing-core", ] +[[package]] +name = "tracing-serde" +version = "0.1.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "bc6b213177105856957181934e4920de57730fc69bf42c37ee5bb664d406d9e1" +dependencies = [ + "serde", + "tracing-core", +] + [[package]] name = "tracing-subscriber" version = "0.3.18" @@ -5072,12 +5082,15 @@ dependencies = [ "nu-ansi-term", "once_cell", "regex", + "serde", + "serde_json", "sharded-slab", "smallvec", "thread_local", "tracing", "tracing-core", "tracing-log", + "tracing-serde", ] [[package]] diff --git a/Cargo.toml b/Cargo.toml index 5e31693b09b..7a73d85d826 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -163,7 +163,7 @@ strum_macros = "0.24" im = { version = "15.1", features = ["serde"] } tracing = "0.1.40" tracing-web = "0.1.3" -tracing-subscriber = { version = "0.3.18", features = ["env-filter"] } +tracing-subscriber = { version = "0.3.18", features = ["env-filter", "json"] } rust-embed = "6.6.0" [profile.dev] diff --git a/test_programs/compilation_report.sh b/test_programs/compilation_report.sh index 360eecd2849..e143bd16046 100755 --- a/test_programs/compilation_report.sh +++ b/test_programs/compilation_report.sh @@ -46,23 +46,34 @@ for dir in ${tests_to_profile[@]}; do fi for ((i = 1; i <= NUM_RUNS; i++)); do - COMPILE_TIME=$((time nargo compile --force --silence-warnings) 2>&1 | grep real | grep -oE '[0-9]+m[0-9]+.[0-9]+s') - # Convert time to seconds and add to total time - TOTAL_TIME=$(echo "$TOTAL_TIME + $(echo $COMPILE_TIME | sed -E 's/([0-9]+)m([0-9.]+)s/\1 * 60 + \2/' | bc)" | bc) + NOIR_LOG=trace NARGO_LOG_DIR=./tmp nargo compile --force --silence-warnings done - AVG_TIME=$(echo "$TOTAL_TIME / $NUM_RUNS" | bc -l) - # Keep only last three decimal points - AVG_TIME=$(awk '{printf "%.3f\n", $1}' <<< "$AVG_TIME") - - echo -e " {\n \"artifact_name\":\"$PACKAGE_NAME\",\n \"time\":\""$AVG_TIME"s\"" >> $current_dir/compilation_report.json - - if (($ITER == $NUM_ARTIFACTS)); then - echo "}" >> $current_dir/compilation_report.json - else - echo "}, " >> $current_dir/compilation_report.json + TIMES=($(jq -r '. | select(.target == "nargo::ops::compile" and .fields.message == "close") | .fields."time.busy"' ./tmp/*)) + + AVG_TIME=$(awk -v RS=" " ' + { + # Times are formatted annoyingly so we need to parse it. + "../../parse_time.sh "$1 | getline current_time + close("../../parse_time.sh "$1) + sum += current_time; + n++; + } + END { + if (n > 0) + printf "%.3f\n", sum / n + else + printf "%.3f\n", 0 + }' <<<"${TIMES[@]}") + + jq -c "{artifact_name: \"$PACKAGE_NAME\", time: \""$AVG_TIME"s\"}" --null-input >> $current_dir/compilation_report.json + + if (($ITER != $NUM_ARTIFACTS)); then + echo "," >> $current_dir/compilation_report.json fi + rm -rf ./tmp + ITER=$(( $ITER + 1 )) done diff --git a/test_programs/parse_time.sh b/test_programs/parse_time.sh new file mode 100755 index 00000000000..2ff5c259cd2 --- /dev/null +++ b/test_programs/parse_time.sh @@ -0,0 +1,21 @@ +#!/usr/bin/env bash +set -e + +# This script accepts a string representing the time spent within a span as outputted by `tracing` +# and standardizes it to be in terms of seconds as `tracing` will report different units depending on the duration. + +DIGITS='([0-9]+(\.[0-9]+)?)' +MICROSECONDS_REGEX=^${DIGITS}µs$ +MILLISECONDS_REGEX=^${DIGITS}ms$ +SECONDS_REGEX=^${DIGITS}s$ + +if [[ $1 =~ $MICROSECONDS_REGEX ]]; then + echo ${BASH_REMATCH[1]} 1000000 | awk '{printf "%.3f\n", $1/$2}' +elif [[ $1 =~ $MILLISECONDS_REGEX ]]; then + echo ${BASH_REMATCH[1]} 1000 | awk '{printf "%.3f\n", $1/$2}' +elif [[ $1 =~ $SECONDS_REGEX ]]; then + echo ${BASH_REMATCH[1]} | awk '{printf "%.3f\n", $1}' +else + echo "Could not parse time: unrecognized format" 1>&2 + exit 1 +fi \ No newline at end of file diff --git a/tooling/nargo_cli/src/main.rs b/tooling/nargo_cli/src/main.rs index a407d467ced..7a23704dac5 100644 --- a/tooling/nargo_cli/src/main.rs +++ b/tooling/nargo_cli/src/main.rs @@ -20,22 +20,7 @@ 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() { - // 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::ENTER | FmtSpan::CLOSE) - .with_writer(debug_file) - .with_ansi(false) - .with_env_filter(EnvFilter::from_default_env()) - .init(); - } else { - tracing_subscriber::fmt() - .with_span_events(FmtSpan::ENTER | FmtSpan::CLOSE) - .with_ansi(true) - .with_env_filter(EnvFilter::from_env("NOIR_LOG")) - .init(); - } + setup_tracing(); // Register a panic hook to display more readable panic messages to end-users let (panic_hook, _) = @@ -47,3 +32,20 @@ fn main() { std::process::exit(1); } } + +fn setup_tracing() { + let subscriber = tracing_subscriber::fmt() + .with_span_events(FmtSpan::ENTER | FmtSpan::CLOSE) + .with_env_filter(EnvFilter::from_env("NOIR_LOG")); + + if let Ok(log_dir) = env::var("NARGO_LOG_DIR") { + let debug_file = rolling::daily(log_dir, "nargo-log"); + subscriber + .with_writer(debug_file) + .with_ansi(false) + .json() + .init(); + } else { + subscriber.with_ansi(true).init(); + } +} From a773cd71cfdcb311febf1c27612f5211f31bcef1 Mon Sep 17 00:00:00 2001 From: TomAFrench Date: Mon, 23 Dec 2024 14:19:18 +0000 Subject: [PATCH 02/19] . --- .github/workflows/reports.yml | 11 +++-------- 1 file changed, 3 insertions(+), 8 deletions(-) diff --git a/.github/workflows/reports.yml b/.github/workflows/reports.yml index f7fe78f6565..d070d410447 100644 --- a/.github/workflows/reports.yml +++ b/.github/workflows/reports.yml @@ -314,13 +314,8 @@ jobs: path: scripts sparse-checkout: | test_programs/compilation_report.sh - sparse-checkout-cone-mode: false - - - uses: actions/checkout@v4 - with: - path: scripts - sparse-checkout: | test_programs/execution_report.sh + test_programs/parse_time.sh sparse-checkout-cone-mode: false - name: Checkout @@ -335,7 +330,7 @@ jobs: if: ${{ !matrix.project.take_average }} run: | mv /home/runner/work/noir/noir/scripts/test_programs/compilation_report.sh ./compilation_report.sh - chmod +x ./compilation_report.sh + mv /home/runner/work/noir/noir/scripts/test_programs/parse_time.sh ./parse_time.sh ./compilation_report.sh 1 - name: Generate compilation report with averages @@ -343,7 +338,7 @@ jobs: if: ${{ matrix.project.take_average }} run: | mv /home/runner/work/noir/noir/scripts/test_programs/compilation_report.sh ./compilation_report.sh - chmod +x ./compilation_report.sh + mv /home/runner/work/noir/noir/scripts/test_programs/parse_time.sh ./parse_time.sh ./compilation_report.sh 1 1 - name: Generate execution report without averages From 0beeca4b7c3ceeef4dc3f7fc36531a75e4b7285a Mon Sep 17 00:00:00 2001 From: TomAFrench Date: Mon, 23 Dec 2024 14:21:50 +0000 Subject: [PATCH 03/19] . --- tooling/nargo_cli/src/main.rs | 6 +----- 1 file changed, 1 insertion(+), 5 deletions(-) diff --git a/tooling/nargo_cli/src/main.rs b/tooling/nargo_cli/src/main.rs index 7a23704dac5..3ea167b7ffa 100644 --- a/tooling/nargo_cli/src/main.rs +++ b/tooling/nargo_cli/src/main.rs @@ -40,11 +40,7 @@ fn setup_tracing() { if let Ok(log_dir) = env::var("NARGO_LOG_DIR") { let debug_file = rolling::daily(log_dir, "nargo-log"); - subscriber - .with_writer(debug_file) - .with_ansi(false) - .json() - .init(); + subscriber.with_writer(debug_file).with_ansi(false).json().init(); } else { subscriber.with_ansi(true).init(); } From c6293609eceff44342a9b04e94220440b37d1a4d Mon Sep 17 00:00:00 2001 From: TomAFrench Date: Mon, 23 Dec 2024 14:25:21 +0000 Subject: [PATCH 04/19] . --- test_programs/compilation_report.sh | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/test_programs/compilation_report.sh b/test_programs/compilation_report.sh index e143bd16046..1a2336c9ae2 100755 --- a/test_programs/compilation_report.sh +++ b/test_programs/compilation_report.sh @@ -54,8 +54,8 @@ for dir in ${tests_to_profile[@]}; do AVG_TIME=$(awk -v RS=" " ' { # Times are formatted annoyingly so we need to parse it. - "../../parse_time.sh "$1 | getline current_time - close("../../parse_time.sh "$1) + "./parse_time.sh "$1 | getline current_time + close("./parse_time.sh "$1) sum += current_time; n++; } From 2d02cf17a05ae44012a11b9da8c22453d0e96afb Mon Sep 17 00:00:00 2001 From: TomAFrench Date: Mon, 23 Dec 2024 14:40:14 +0000 Subject: [PATCH 05/19] . --- test_programs/compilation_report.sh | 7 ++++--- 1 file changed, 4 insertions(+), 3 deletions(-) diff --git a/test_programs/compilation_report.sh b/test_programs/compilation_report.sh index 1a2336c9ae2..64b38355beb 100755 --- a/test_programs/compilation_report.sh +++ b/test_programs/compilation_report.sh @@ -1,6 +1,7 @@ #!/usr/bin/env bash set -e +SCRIPT_DIR=$(dirname "$0") current_dir=$(pwd) base_path="$current_dir/execution_success" @@ -51,11 +52,11 @@ for dir in ${tests_to_profile[@]}; do TIMES=($(jq -r '. | select(.target == "nargo::ops::compile" and .fields.message == "close") | .fields."time.busy"' ./tmp/*)) - AVG_TIME=$(awk -v RS=" " ' + AVG_TIME=$(awk -v RS=" " -v script="$SCRIPT_DIR/parse_time.sh" ' { # Times are formatted annoyingly so we need to parse it. - "./parse_time.sh "$1 | getline current_time - close("./parse_time.sh "$1) + script" "$1 | getline current_time + close(script" "$1) sum += current_time; n++; } From 0b44de6e6dea2f932ddd3cefee48917b29ac3844 Mon Sep 17 00:00:00 2001 From: TomAFrench Date: Mon, 23 Dec 2024 15:03:28 +0000 Subject: [PATCH 06/19] . --- test_programs/compilation_report.sh | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) diff --git a/test_programs/compilation_report.sh b/test_programs/compilation_report.sh index 64b38355beb..75feba75929 100755 --- a/test_programs/compilation_report.sh +++ b/test_programs/compilation_report.sh @@ -1,7 +1,7 @@ #!/usr/bin/env bash set -e -SCRIPT_DIR=$(dirname "$0") +PARSE_TIME=$(realpath "$(dirname "$0")/parse_time.sh") current_dir=$(pwd) base_path="$current_dir/execution_success" @@ -52,11 +52,11 @@ for dir in ${tests_to_profile[@]}; do TIMES=($(jq -r '. | select(.target == "nargo::ops::compile" and .fields.message == "close") | .fields."time.busy"' ./tmp/*)) - AVG_TIME=$(awk -v RS=" " -v script="$SCRIPT_DIR/parse_time.sh" ' + AVG_TIME=$(awk -v RS=" " -v parse_time="$PARSE_TIME" ' { # Times are formatted annoyingly so we need to parse it. - script" "$1 | getline current_time - close(script" "$1) + parse_time" "$1 | getline current_time + close(parse_time" "$1) sum += current_time; n++; } @@ -67,7 +67,7 @@ for dir in ${tests_to_profile[@]}; do printf "%.3f\n", 0 }' <<<"${TIMES[@]}") - jq -c "{artifact_name: \"$PACKAGE_NAME\", time: \""$AVG_TIME"s\"}" --null-input >> $current_dir/compilation_report.json + jq -rc "{artifact_name: \"$PACKAGE_NAME\", time: \""$AVG_TIME"s\"}" --null-input >> $current_dir/compilation_report.json if (($ITER != $NUM_ARTIFACTS)); then echo "," >> $current_dir/compilation_report.json From a2fe907839557d1c11d831b52bc47419cb650f64 Mon Sep 17 00:00:00 2001 From: TomAFrench Date: Mon, 23 Dec 2024 17:07:45 +0000 Subject: [PATCH 07/19] . --- Cargo.lock | 1 + tooling/nargo/src/ops/check.rs | 1 + tooling/nargo_cli/Cargo.toml | 1 + tooling/nargo_cli/src/cli/mod.rs | 1 + 4 files changed, 4 insertions(+) diff --git a/Cargo.lock b/Cargo.lock index 8f8d02af77a..bc1e328554b 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -2857,6 +2857,7 @@ dependencies = [ "tokio-util 0.7.12", "toml 0.7.8", "tower", + "tracing", "tracing-appender", "tracing-subscriber", ] diff --git a/tooling/nargo/src/ops/check.rs b/tooling/nargo/src/ops/check.rs index 707353ccdad..f22def8bd91 100644 --- a/tooling/nargo/src/ops/check.rs +++ b/tooling/nargo/src/ops/check.rs @@ -3,6 +3,7 @@ use noirc_driver::{CompiledProgram, ErrorsAndWarnings}; use noirc_errors::{CustomDiagnostic, FileDiagnostic}; /// Run each function through a circuit simulator to check that they are solvable. +#[tracing::instrument(level = "trace", skip_all)] pub fn check_program(compiled_program: &CompiledProgram) -> Result<(), ErrorsAndWarnings> { for (i, circuit) in compiled_program.program.functions.iter().enumerate() { let mut simulator = CircuitSimulator::default(); diff --git a/tooling/nargo_cli/Cargo.toml b/tooling/nargo_cli/Cargo.toml index 5603b7f4fca..9b52a73ce35 100644 --- a/tooling/nargo_cli/Cargo.toml +++ b/tooling/nargo_cli/Cargo.toml @@ -65,6 +65,7 @@ notify-debouncer-full = "0.3.1" termion = "3.0.0" # Logs +tracing.workspace = true tracing-subscriber.workspace = true tracing-appender = "0.2.3" clap_complete = "4.5.36" diff --git a/tooling/nargo_cli/src/cli/mod.rs b/tooling/nargo_cli/src/cli/mod.rs index cc72092daa1..43e3de9c6d0 100644 --- a/tooling/nargo_cli/src/cli/mod.rs +++ b/tooling/nargo_cli/src/cli/mod.rs @@ -116,6 +116,7 @@ enum NargoCommand { } #[cfg(not(feature = "codegen-docs"))] +#[tracing::instrument(level = "trace")] pub(crate) fn start_cli() -> eyre::Result<()> { let NargoCli { command, mut config } = NargoCli::parse(); From a5a1128cbf2c720b02f7fe0b736c16c274e1b164 Mon Sep 17 00:00:00 2001 From: Maxim Vezenov Date: Thu, 2 Jan 2025 17:42:27 +0000 Subject: [PATCH 08/19] switch to just start_cli --- test_programs/compilation_report.sh | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/test_programs/compilation_report.sh b/test_programs/compilation_report.sh index 75feba75929..fe0abfb2886 100755 --- a/test_programs/compilation_report.sh +++ b/test_programs/compilation_report.sh @@ -50,7 +50,7 @@ for dir in ${tests_to_profile[@]}; do NOIR_LOG=trace NARGO_LOG_DIR=./tmp nargo compile --force --silence-warnings done - TIMES=($(jq -r '. | select(.target == "nargo::ops::compile" and .fields.message == "close") | .fields."time.busy"' ./tmp/*)) + TIMES=($(jq -r '. | select(.target == "nargo::start_cli" and .fields.message == "close") | .fields."time.busy"' ./tmp/*)) AVG_TIME=$(awk -v RS=" " -v parse_time="$PARSE_TIME" ' { From 0dc274e6e586a04bb0e0bdbf828ae6872911e196 Mon Sep 17 00:00:00 2001 From: Maxim Vezenov Date: Thu, 2 Jan 2025 17:45:37 +0000 Subject: [PATCH 09/19] switch over execution report --- test_programs/execution_report.sh | 38 ++++++++++++++++++++----------- 1 file changed, 25 insertions(+), 13 deletions(-) diff --git a/test_programs/execution_report.sh b/test_programs/execution_report.sh index 073871e60f8..b929c367f7d 100755 --- a/test_programs/execution_report.sh +++ b/test_programs/execution_report.sh @@ -1,6 +1,7 @@ #!/usr/bin/env bash set -e +PARSE_TIME=$(realpath "$(dirname "$0")/parse_time.sh") current_dir=$(pwd) base_path="$current_dir/execution_success" @@ -53,23 +54,34 @@ for dir in ${tests_to_profile[@]}; do fi for ((i = 1; i <= NUM_RUNS; i++)); do - EXECUTION_TIME=$((time nargo execute --silence-warnings) 2>&1 | grep real | grep -oE '[0-9]+m[0-9]+.[0-9]+s') - # Convert to seconds and add to total time - TOTAL_TIME=$(echo "$TOTAL_TIME + $(echo $EXECUTION_TIME | sed -E 's/([0-9]+)m([0-9.]+)s/\1 * 60 + \2/' | bc)" | bc) + NOIR_LOG=trace NARGO_LOG_DIR=./tmp nargo execute --silence-warnings done - AVG_TIME=$(echo "$TOTAL_TIME / $NUM_RUNS" | bc -l) - # Keep only last three decimal points - AVG_TIME=$(awk '{printf "%.3f\n", $1}' <<< "$AVG_TIME") - - echo -e " {\n \"artifact_name\":\"$PACKAGE_NAME\",\n \"time\":\""$AVG_TIME"s\"" >> $current_dir/execution_report.json - - if (($ITER == $NUM_ARTIFACTS)); then - echo "}" >> $current_dir/execution_report.json - else - echo "}, " >> $current_dir/execution_report.json + TIMES=($(jq -r '. | select(.target == "nargo::ops::execute" and .fields.message == "close") | .fields."time.busy"' ./tmp/*)) + + AVG_TIME=$(awk -v RS=" " -v parse_time="$PARSE_TIME" ' + { + # Times are formatted annoyingly so we need to parse it. + parse_time" "$1 | getline current_time + close(parse_time" "$1) + sum += current_time; + n++; + } + END { + if (n > 0) + printf "%.3f\n", sum / n + else + printf "%.3f\n", 0 + }' <<<"${TIMES[@]}") + + jq -rc "{artifact_name: \"$PACKAGE_NAME\", time: \""$AVG_TIME"s\"}" --null-input >> $current_dir/execution_report.json + + if (($ITER != $NUM_ARTIFACTS)); then + echo "," >> $current_dir/execution_report.json fi + rm -rf ./tmp + ITER=$(( $ITER + 1 )) done From ccf1e818768cba1ede87deb752095ffa09e1b6dd Mon Sep 17 00:00:00 2001 From: Maxim Vezenov Date: Thu, 2 Jan 2025 17:47:58 +0000 Subject: [PATCH 10/19] update reports.yml git status --- .github/workflows/reports.yml | 2 ++ 1 file changed, 2 insertions(+) diff --git a/.github/workflows/reports.yml b/.github/workflows/reports.yml index d070d410447..059bffa2cf3 100644 --- a/.github/workflows/reports.yml +++ b/.github/workflows/reports.yml @@ -346,6 +346,7 @@ jobs: if: ${{ !matrix.project.is_library && !matrix.project.take_average }} run: | mv /home/runner/work/noir/noir/scripts/test_programs/execution_report.sh ./execution_report.sh + mv /home/runner/work/noir/noir/scripts/test_programs/parse_time.sh ./parse_time.sh ./execution_report.sh 1 - name: Generate execution report with averages @@ -353,6 +354,7 @@ jobs: if: ${{ !matrix.project.is_library && matrix.project.take_average }} run: | mv /home/runner/work/noir/noir/scripts/test_programs/execution_report.sh ./execution_report.sh + mv /home/runner/work/noir/noir/scripts/test_programs/parse_time.sh ./parse_time.sh ./execution_report.sh 1 1 - name: Move compilation report From 98cff4d2891ef59b7b6e44186bbe483fdf700ff2 Mon Sep 17 00:00:00 2001 From: Maxim Vezenov Date: Thu, 2 Jan 2025 18:37:58 +0000 Subject: [PATCH 11/19] cp instead of mv --- .github/workflows/reports.yml | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/.github/workflows/reports.yml b/.github/workflows/reports.yml index 059bffa2cf3..9e617d71be1 100644 --- a/.github/workflows/reports.yml +++ b/.github/workflows/reports.yml @@ -330,7 +330,7 @@ jobs: if: ${{ !matrix.project.take_average }} run: | mv /home/runner/work/noir/noir/scripts/test_programs/compilation_report.sh ./compilation_report.sh - mv /home/runner/work/noir/noir/scripts/test_programs/parse_time.sh ./parse_time.sh + cp /home/runner/work/noir/noir/scripts/test_programs/parse_time.sh ./parse_time.sh ./compilation_report.sh 1 - name: Generate compilation report with averages @@ -338,7 +338,7 @@ jobs: if: ${{ matrix.project.take_average }} run: | mv /home/runner/work/noir/noir/scripts/test_programs/compilation_report.sh ./compilation_report.sh - mv /home/runner/work/noir/noir/scripts/test_programs/parse_time.sh ./parse_time.sh + cp /home/runner/work/noir/noir/scripts/test_programs/parse_time.sh ./parse_time.sh ./compilation_report.sh 1 1 - name: Generate execution report without averages From ca407af99507b7e700fd9e0aad13eda4593c2a33 Mon Sep 17 00:00:00 2001 From: Maxim Vezenov Date: Fri, 3 Jan 2025 01:05:09 +0000 Subject: [PATCH 12/19] remove parity-root --- .github/workflows/reports.yml | 2 -- 1 file changed, 2 deletions(-) diff --git a/.github/workflows/reports.yml b/.github/workflows/reports.yml index 8f38419bde4..49737c17a41 100644 --- a/.github/workflows/reports.yml +++ b/.github/workflows/reports.yml @@ -300,7 +300,6 @@ jobs: matrix: include: - project: { repo: AztecProtocol/aztec-packages, path: noir-projects/noir-contracts, is_library: true } - - project: { repo: AztecProtocol/aztec-packages, path: noir-projects/noir-protocol-circuits/crates/parity-root, take_average: true } - project: { repo: AztecProtocol/aztec-packages, path: noir-projects/noir-protocol-circuits/crates/private-kernel-inner, take_average: true } - project: { repo: AztecProtocol/aztec-packages, path: noir-projects/noir-protocol-circuits/crates/private-kernel-tail, take_average: true } - project: { repo: AztecProtocol/aztec-packages, path: noir-projects/noir-protocol-circuits/crates/private-kernel-reset, take_average: true } @@ -463,7 +462,6 @@ jobs: include: # TODO: Bring this report back under a flag. The `noir-contracts` report takes just under 30 minutes. # - project: { repo: AztecProtocol/aztec-packages, path: noir-projects/noir-contracts } - - project: { repo: AztecProtocol/aztec-packages, path: noir-projects/noir-protocol-circuits/crates/parity-root } - project: { repo: AztecProtocol/aztec-packages, path: noir-projects/noir-protocol-circuits/crates/private-kernel-inner } - project: { repo: AztecProtocol/aztec-packages, path: noir-projects/noir-protocol-circuits/crates/private-kernel-reset } - project: { repo: AztecProtocol/aztec-packages, path: noir-projects/noir-protocol-circuits/crates/private-kernel-tail } From 4abd4b9ce00d7c9bb95b5f43bdbf3cdfde874b66 Mon Sep 17 00:00:00 2001 From: Maxim Vezenov Date: Fri, 3 Jan 2025 04:36:21 +0000 Subject: [PATCH 13/19] fix target in compilation report --- test_programs/compilation_report.sh | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/test_programs/compilation_report.sh b/test_programs/compilation_report.sh index fe0abfb2886..df15ef00008 100755 --- a/test_programs/compilation_report.sh +++ b/test_programs/compilation_report.sh @@ -50,7 +50,7 @@ for dir in ${tests_to_profile[@]}; do NOIR_LOG=trace NARGO_LOG_DIR=./tmp nargo compile --force --silence-warnings done - TIMES=($(jq -r '. | select(.target == "nargo::start_cli" and .fields.message == "close") | .fields."time.busy"' ./tmp/*)) + TIMES=($(jq -r '. | select(.target == "nargo::cli" and .fields.message == "close") | .fields."time.busy"' ./tmp/*)) AVG_TIME=$(awk -v RS=" " -v parse_time="$PARSE_TIME" ' { From e17d04d0a0746c48bf3c8966a36dd7bbc2cdbd14 Mon Sep 17 00:00:00 2001 From: Maxim Vezenov Date: Fri, 3 Jan 2025 05:21:33 +0000 Subject: [PATCH 14/19] touch file --- .github/workflows/reports.yml | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/.github/workflows/reports.yml b/.github/workflows/reports.yml index 49737c17a41..8caf925d542 100644 --- a/.github/workflows/reports.yml +++ b/.github/workflows/reports.yml @@ -346,6 +346,8 @@ jobs: if: ${{ !matrix.project.take_average }} run: | mv /home/runner/work/noir/noir/scripts/test_programs/compilation_report.sh ./compilation_report.sh + cat compilation_report.json + touch parse_time.sh cp /home/runner/work/noir/noir/scripts/test_programs/parse_time.sh ./parse_time.sh ./compilation_report.sh 1 @@ -354,6 +356,8 @@ jobs: if: ${{ matrix.project.take_average }} run: | mv /home/runner/work/noir/noir/scripts/test_programs/compilation_report.sh ./compilation_report.sh + cat compilation_report.json + touch parse_time.sh cp /home/runner/work/noir/noir/scripts/test_programs/parse_time.sh ./parse_time.sh ./compilation_report.sh 1 1 From d3c8cab151b03e16214569bb5c38f1d8a80d25d5 Mon Sep 17 00:00:00 2001 From: Maxim Vezenov Date: Fri, 3 Jan 2025 16:15:10 +0000 Subject: [PATCH 15/19] move cat to actually after calling the script --- .github/workflows/reports.yml | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/.github/workflows/reports.yml b/.github/workflows/reports.yml index 8caf925d542..1034c4f6c12 100644 --- a/.github/workflows/reports.yml +++ b/.github/workflows/reports.yml @@ -346,20 +346,20 @@ jobs: if: ${{ !matrix.project.take_average }} run: | mv /home/runner/work/noir/noir/scripts/test_programs/compilation_report.sh ./compilation_report.sh - cat compilation_report.json touch parse_time.sh cp /home/runner/work/noir/noir/scripts/test_programs/parse_time.sh ./parse_time.sh ./compilation_report.sh 1 + cat compilation_report.json - name: Generate compilation report with averages working-directory: ./test-repo/${{ matrix.project.path }} if: ${{ matrix.project.take_average }} run: | mv /home/runner/work/noir/noir/scripts/test_programs/compilation_report.sh ./compilation_report.sh - cat compilation_report.json touch parse_time.sh cp /home/runner/work/noir/noir/scripts/test_programs/parse_time.sh ./parse_time.sh ./compilation_report.sh 1 1 + cat compilation_report.json - name: Generate execution report without averages working-directory: ./test-repo/${{ matrix.project.path }} From a726016c47d00b0e44f49a3b09fa451214a0f3f7 Mon Sep 17 00:00:00 2001 From: Maxim Vezenov Date: Fri, 3 Jan 2025 16:24:29 +0000 Subject: [PATCH 16/19] chmod new file --- .github/workflows/reports.yml | 2 ++ 1 file changed, 2 insertions(+) diff --git a/.github/workflows/reports.yml b/.github/workflows/reports.yml index 1034c4f6c12..344ba33f6ef 100644 --- a/.github/workflows/reports.yml +++ b/.github/workflows/reports.yml @@ -347,6 +347,7 @@ jobs: run: | mv /home/runner/work/noir/noir/scripts/test_programs/compilation_report.sh ./compilation_report.sh touch parse_time.sh + chmod +x parse_time.sh cp /home/runner/work/noir/noir/scripts/test_programs/parse_time.sh ./parse_time.sh ./compilation_report.sh 1 cat compilation_report.json @@ -357,6 +358,7 @@ jobs: run: | mv /home/runner/work/noir/noir/scripts/test_programs/compilation_report.sh ./compilation_report.sh touch parse_time.sh + chmod +x parse_time.sh cp /home/runner/work/noir/noir/scripts/test_programs/parse_time.sh ./parse_time.sh ./compilation_report.sh 1 1 cat compilation_report.json From 5d04d443a944e15fda27d6fa7d0b4817473a344f Mon Sep 17 00:00:00 2001 From: Maxim Vezenov Date: Fri, 3 Jan 2025 12:21:46 -0500 Subject: [PATCH 17/19] Update .github/workflows/reports.yml --- .github/workflows/reports.yml | 1 - 1 file changed, 1 deletion(-) diff --git a/.github/workflows/reports.yml b/.github/workflows/reports.yml index 344ba33f6ef..429ce23b5f1 100644 --- a/.github/workflows/reports.yml +++ b/.github/workflows/reports.yml @@ -350,7 +350,6 @@ jobs: chmod +x parse_time.sh cp /home/runner/work/noir/noir/scripts/test_programs/parse_time.sh ./parse_time.sh ./compilation_report.sh 1 - cat compilation_report.json - name: Generate compilation report with averages working-directory: ./test-repo/${{ matrix.project.path }} From 7cbbc3add0d3f44c29691ee65594c185deee12cc Mon Sep 17 00:00:00 2001 From: Maxim Vezenov Date: Fri, 3 Jan 2025 12:21:59 -0500 Subject: [PATCH 18/19] Update .github/workflows/reports.yml --- .github/workflows/reports.yml | 1 - 1 file changed, 1 deletion(-) diff --git a/.github/workflows/reports.yml b/.github/workflows/reports.yml index 429ce23b5f1..049d731b51c 100644 --- a/.github/workflows/reports.yml +++ b/.github/workflows/reports.yml @@ -360,7 +360,6 @@ jobs: chmod +x parse_time.sh cp /home/runner/work/noir/noir/scripts/test_programs/parse_time.sh ./parse_time.sh ./compilation_report.sh 1 1 - cat compilation_report.json - name: Generate execution report without averages working-directory: ./test-repo/${{ matrix.project.path }} From 90693191a3467a3888c0ae170d80ffda485fa604 Mon Sep 17 00:00:00 2001 From: Maxim Vezenov Date: Fri, 3 Jan 2025 18:34:04 +0000 Subject: [PATCH 19/19] add tracing for prepare_package and read_program_from_file --- tooling/nargo/src/lib.rs | 1 + tooling/nargo_cli/src/cli/fs/program.rs | 1 + 2 files changed, 2 insertions(+) diff --git a/tooling/nargo/src/lib.rs b/tooling/nargo/src/lib.rs index de032ca55ae..30f25356e41 100644 --- a/tooling/nargo/src/lib.rs +++ b/tooling/nargo/src/lib.rs @@ -172,6 +172,7 @@ pub fn parse_all(file_manager: &FileManager) -> ParsedFiles { .collect() } +#[tracing::instrument(level = "trace", skip_all)] pub fn prepare_package<'file_manager, 'parsed_files>( file_manager: &'file_manager FileManager, parsed_files: &'parsed_files ParsedFiles, diff --git a/tooling/nargo_cli/src/cli/fs/program.rs b/tooling/nargo_cli/src/cli/fs/program.rs index 0b30d23db2b..87783e4573a 100644 --- a/tooling/nargo_cli/src/cli/fs/program.rs +++ b/tooling/nargo_cli/src/cli/fs/program.rs @@ -36,6 +36,7 @@ fn save_build_artifact_to_file, T: ?Sized + serde::Serialize>( circuit_path } +#[tracing::instrument(level = "trace", skip_all)] pub(crate) fn read_program_from_file>( circuit_path: P, ) -> Result {