Implement reporting unit test timings in CI

Author: meddle0x53

.circleci/config.yml

@@ -149,14 +149,166 @@ commands:
       - checkout
       - setup_environment:
           cache_key: v4.2.0-rust-1.88.0-<< parameters.workspace_member >><< parameters.cache_key_suffix >>-cache
+
+      - run:
+          name: Install cargo-nextest
+          command: |
+            cargo install cargo-nextest --locked || true
+
       - run:
           name: "Run Tests"
           timeout: << parameters.timeout >>
           no_output_timeout: << parameters.no_output_timeout >>
-          command: RUST_MIN_STACK=67108864 cargo test --package=<< parameters.workspace_member >> << parameters.flags >>
+          command: |
+            set -euo pipefail
+            export CARGO_TERM_COLOR=never
+
+            # Create artifact + nextest output directories
+            mkdir -p artifacts target/nextest/ci
+
+            # Create artifact + nextest output directories
+            OUT="artifacts/<< parameters.workspace_member >>-nextest.txt"
+            CSV="artifacts/<< parameters.workspace_member >>-test-times.csv"
+            TOP="artifacts/<< parameters.workspace_member >>-slow-tests-top30.csv"
+            JUNIT="target/nextest/ci/junit.xml"
+
+            # Extract and trim flags from parameters
+            FLAGS_FULL="<< parameters.flags >>"
+            FLAGS_TRIM="$(printf '%s' "$FLAGS_FULL" | sed -e 's/^[[:space:]]*//' -e 's/[[:space:]]*$//')"
+
+            # Split flags into cargo build flags (before --) and libtest args (after --)
+            RIGHT_OF_SEP=""
+            if printf '%s' "$FLAGS_TRIM" | grep -q ' -- '; then
+              BUILD_FLAGS="${FLAGS_TRIM%% -- *}"
+              RIGHT_OF_SEP="${FLAGS_TRIM#* -- }"
+            elif printf '%s' "$FLAGS_TRIM" | grep -Eq '^--[[:space:]]'; then
+              BUILD_FLAGS=""
+              RIGHT_OF_SEP="${FLAGS_TRIM#-- }"
+            else
+              BUILD_FLAGS="$FLAGS_TRIM"
+            fi
+
+            # Remove any --test target flags,they cause nextest build errors
+            BUILD_FLAGS_SANITIZED="$(printf '%s' "$BUILD_FLAGS" \
+              | sed -E "s/(^|[[:space:]])--test[[:space:]]+'[^']*'([[:space:]]|$)/ /g" \
+              | sed -E 's/(^|[[:space:]])--test[[:space:]]+\"[^\"]*\"([[:space:]]|$)/ /g' \
+              | sed -E 's/(^|[[:space:]])--test[[:space:]]+[^[:space:]]+([[:space:]]|$)/ /g' \
+              | tr -s ' ' | sed -E 's/^[[:space:]]+//; s/[[:space:]]+$//' \
+            )"
+
+            # Build nextest filter expression from any --skip <pattern> arguments
+            FILTER_EXPR=""
+            if [ -n "$RIGHT_OF_SEP" ]; then
+              SKIPS="$(printf '%s\n' "$RIGHT_OF_SEP" \
+                | sed -E 's/[[:space:]]+/ /g' \
+                | grep -oE -- '--skip[[:space:]]+(\"[^\"]+\"|'\''[^'\'']+'\''|[^[:space:]]+)' || true)"
+              if [ -n "$SKIPS" ]; then
+                EXPRS=""
+                tmpf="$(mktemp)"
+                printf '%s\n' "$SKIPS" > "$tmpf"
+                while IFS= read -r line; do
+                  pat="${line#--skip }"
+                  pat="${pat%\"}"; pat="${pat#\"}"
+                  pat="${pat%\'}"; pat="${pat#\'}"
+                  pat_rx="${pat//\//\\/}"  # escape forward slashes for regex
+                  if [ -z "$EXPRS" ]; then
+                    EXPRS="test(/$pat_rx/)"
+                  else
+                    EXPRS="$EXPRS or test(/$pat_rx/)"
+                  fi
+                done < "$tmpf"
+                rm -f "$tmpf"
+                if [ -n "$EXPRS" ]; then
+                  FILTER_EXPR="not ($EXPRS)"
+                fi
+              fi
+            fi
+
+            # Detect and extract --test-threads value (used to set JOBS)
+            TEST_THREADS=""
+            if [ -n "$RIGHT_OF_SEP" ]; then
+              # form: --test-threads=8
+              TEST_THREADS="$(printf '%s\n' "$RIGHT_OF_SEP" | sed -nE 's/.*--test-threads=([0-9]+).*/\1/p' | head -n1)"
+              if [ -z "$TEST_THREADS" ]; then
+                # form: --test-threads 8
+                TEST_THREADS="$(printf '%s\n' "$RIGHT_OF_SEP" | sed -nE 's/.*--test-threads[[:space:]]+([0-9]+).*/\1/p' | head -n1)"
+              fi
+            fi
+
+            # Default JOBS, overridden by TEST_THREADS if set
+            JOBS="${NEXTEST_JOBS:-2}"
+            if [ -n "$TEST_THREADS" ]; then
+              JOBS="$TEST_THREADS"
+            fi
+
+            # Create nextest config (disable fail-fast, add slow-timeout + JUnit output)
+            SLOW_PERIOD="${NEXTEST_SLOW_PERIOD:-60s}"
+            CFG_ARGS=()
+            TMPD="$(mktemp -d)"
+            if [ -f ".config/nextest.toml" ]; then
+              CFG_ARGS+=(--config-file ".config/nextest.toml")
+            fi
+            {
+              printf '%s\n' '[profile.ci]'
+              printf '%s\n' 'fail-fast = false'
+              printf '%s\n' "slow-timeout = \"${SLOW_PERIOD}\""
+              printf '%s\n' ''
+              printf '%s\n' '[profile.ci.junit]'
+              printf '%s\n' 'path = "junit.xml"'
+            } > "$TMPD/nextest-override.toml"
+            CFG_ARGS+=(--config-file "$TMPD/nextest-override.toml")
+
+            # Print configuration summary for debugging
+            echo "==> nextest package: << parameters.workspace_member >>"
+            echo "==> build flags (sanitized): '${BUILD_FLAGS_SANITIZED}'"
+            echo "==> filter-expr: ${FILTER_EXPR:-<none>}  (right-of-sep: ${RIGHT_OF_SEP:-<none>})"
+            echo "==> test-threads override: ${TEST_THREADS:-<none>}"
+            echo "==> jobs: ${JOBS}"
+
+            # Use plain cargo test if --no-run was requested
+            # Otherwise, run tests with cargo nextest
+            if printf '%s' " $BUILD_FLAGS_SANITIZED " | grep -q ' --no-run '; then
+              cargo test --package="<< parameters.workspace_member >>" $BUILD_FLAGS_SANITIZED | tee "$OUT"
+              : > "$CSV"; : > "$TOP"
+            else
+              cargo nextest run \
+                -p "<< parameters.workspace_member >>" $BUILD_FLAGS_SANITIZED \
+                --profile ci -j "${JOBS}" "${CFG_ARGS[@]}" \
+                --status-level fail --hide-progress-bar \
+                --no-tests=pass \
+                ${FILTER_EXPR:+--filter-expr "$FILTER_EXPR"} \
+                2>&1 | tee "$OUT"
+
+              # Parse junit.xml to extract test timings
+              if [ -f "$JUNIT" ]; then
+                awk -v RS='<testcase ' '
+                  NR>1 {
+                    name=""; classname=""; time="";
+                    start=index($0,"classname=\""); if(start>0){ start+=11; rest=substr($0,start); end=index(rest,"\""); if(end>0) classname=substr(rest,1,end-1) }
+                    start=index($0,"name=\"");      if(start>0){ start+=6;  rest=substr($0,start); end=index(rest,"\""); if(end>0) name=substr(rest,1,end-1) }
+                    start=index($0,"time=\"");      if(start>0){ start+=6;  rest=substr($0,start); end=index(rest,"\""); if(end>0) time=substr(rest,1,end-1) }
+                    if(name!="" && time!=""){ full=(classname!=""?classname"::"name:name); printf "%s,%s\n", full, time }
+                  }
+                ' "$JUNIT" > "$CSV" || true
+
+                # Sort and store top 30 slowest tests
+                sort -t, -k2,2nr "$CSV" | head -n 30 > "$TOP" || true
+              else
+                echo "WARN: $JUNIT not found; no timings extracted." >&2
+                : > "$CSV"; : > "$TOP"
+              fi
+            fi
+
+      - store_artifacts:
+          path: artifacts
+          destination: test-timings/<< parameters.workspace_member >>
+      - store_test_results:
+          path: target/nextest/ci
+
       - clear_environment:
           cache_key: v4.2.0-rust-1.88.0-<< parameters.workspace_member >><< parameters.cache_key_suffix >>-cache
 
+
   install_rust_nightly:
     description: "Install Rust nightly toolchain"
     steps:
@@ -446,7 +598,8 @@ jobs:
       - run_test:
           workspace_member: snarkvm-ledger
           flags: --release --features=rocks -- --test-threads=2
-          timeout: 20m
+          no_output_timeout: 20m
+          timeout: 30m
 
   ledger-with-valid-solutions:
     executor: rust-docker
@@ -470,6 +623,8 @@ jobs:
     steps:
       - run_test:
           workspace_member: snarkvm-ledger-block
+          no_output_timeout: 20m
+          timeout: 30m
 
   ledger-committee:
     executor: rust-docker
@@ -593,6 +748,8 @@ jobs:
           workspace_member: snarkvm-parameters
           flags: -- --test-threads=2 --ignored test_load_bytes_mini
           cache_key_suffix: -v-{{ epoch }}
+          no_output_timeout: 20m
+          timeout: 30m
 
   synthesizer:
     executor: rust-docker
@@ -601,11 +758,14 @@ jobs:
       - run_test:
           workspace_member: snarkvm-synthesizer
           flags: --lib --bins
-          timeout: 20m
+          no_output_timeout: 20m
+          timeout: 30m
 
   synthesizer-test:
     executor: rust-docker
     resource_class: << pipeline.parameters.twoxlarge >>
+    environment:
+      NEXTEST_JOBS: "4"
     steps:
       - run_test:
           workspace_member: snarkvm-synthesizer
@@ -631,7 +791,7 @@ jobs:
           # test_vm_execute_and_finalize can take over 10 minutes in the current setup
           no_output_timeout: 20m
           workspace_member: snarkvm-synthesizer
-          flags: --test '*' --features test -- --test-threads=4 
+          flags: --test '*' --features test -- --test-threads=4
           cache_key_suffix: -integration
 
   synthesizer-process:
@@ -662,6 +822,8 @@ jobs:
   synthesizer-program-integration:
     executor: rust-docker
     resource_class: << pipeline.parameters.twoxlarge >>
+    environment:
+      NEXTEST_JOBS: "4"
     steps:
       - run_test:
           workspace_member: snarkvm-synthesizer-program

.gitignore

@@ -14,3 +14,4 @@
 !**/beta-h.usrs
 !**/neg-powers-of-beta.usrs
 **/proptest-regressions/
+artifacts