diff --git a/.github/workflows/bench-inclusion-point.yml b/.github/workflows/bench-inclusion-point.yml new file mode 100644 index 000000000000..3e26f8ea385b --- /dev/null +++ b/.github/workflows/bench-inclusion-point.yml @@ -0,0 +1,62 @@ +name: Bench Inclusion Point + +# Reusable: runs ONE inclusion-sweep TPS point against an ALREADY-DEPLOYED +# network (SKIP_NETWORK_DEPLOY=1). The caller (nightly-bench-inclusion-sweep.yml) +# deploys the network once and calls this for each point (1/5/10 TPS), chaining +# the calls so the points run sequentially on the same network. Deploy / wait / +# teardown are done once by the caller, not here. + +on: + workflow_call: + inputs: + tps: + description: "Target TPS for this point" + required: true + type: string + namespace: + description: "k8s namespace of the already-deployed network" + required: true + type: string + network: + description: "Network env name (environments/.env)" + required: false + type: string + default: bench-inclusion-sweep + docker_image: + description: "Full aztec docker image (already deployed)" + required: true + type: string + source_ref: + description: "Git ref to checkout for the bench scripts" + required: true + type: string + sweep_id: + description: "Shared sweep id so the dashboard groups the points" + required: true + type: string + +jobs: + bench: + runs-on: ubuntu-latest + steps: + - uses: actions/checkout@93cb6efe18208431cddfb8368fd83d5badbf9bfd # v5.0.1 + with: + ref: ${{ inputs.source_ref }} + - name: Run ${{ inputs.tps }} TPS inclusion point + timeout-minutes: 120 + env: + AWS_ACCESS_KEY_ID: ${{ secrets.AWS_ACCESS_KEY_ID }} + AWS_SECRET_ACCESS_KEY: ${{ secrets.AWS_SECRET_ACCESS_KEY }} + GITHUB_TOKEN: ${{ secrets.AZTEC_BOT_GITHUB_TOKEN }} + BUILD_INSTANCE_SSH_KEY: ${{ secrets.BUILD_INSTANCE_SSH_KEY }} + GCP_SA_KEY: ${{ secrets.GCP_SA_KEY }} + GCP_PROJECT_ID: ${{ secrets.GCP_PROJECT_ID }} + SLACK_BOT_TOKEN: ${{ secrets.SLACK_BOT_TOKEN }} + RUN_ID: ${{ github.run_id }} + AWS_SHUTDOWN_TIME: 180 + NO_SPOT: 1 + SKIP_NETWORK_DEPLOY: "1" + TARGET_TPS: ${{ inputs.tps }} + BENCH_SWEEP_ID: ${{ inputs.sweep_id }} + BENCH_SWEEP_LABEL: inclusion-sweep + run: ./.github/ci3.sh network-inclusion-sweep ${{ inputs.network }} ${{ inputs.namespace }} "${{ inputs.docker_image }}" diff --git a/.github/workflows/nightly-bench-10tps.yml b/.github/workflows/nightly-bench-inclusion-sweep.yml similarity index 59% rename from .github/workflows/nightly-bench-10tps.yml rename to .github/workflows/nightly-bench-inclusion-sweep.yml index 9f85e2a7eaed..9a5912db4ac6 100644 --- a/.github/workflows/nightly-bench-10tps.yml +++ b/.github/workflows/nightly-bench-inclusion-sweep.yml @@ -1,8 +1,15 @@ -name: Nightly Bench 10 TPS +name: Nightly Bench Inclusion Sweep + +# Inclusion sweep: deploys ONE network and runs the +# 1/5/10 TPS points SEQUENTIALLY against it, all tagged with a shared sweepId so +# the dashboard groups them. The scraper drains the mempool to zero between +# points. Each point is the reusable bench-inclusion-point.yml workflow +# (SKIP_NETWORK_DEPLOY=1); the next point's call `needs` the previous one so they +# don't overlap. Deploy / wait-for-first-block / teardown happen once. on: schedule: - - cron: "30 6 * * *" + - cron: "30 3 * * *" workflow_dispatch: inputs: docker_image: @@ -19,7 +26,7 @@ on: type: string concurrency: - group: nightly-bench-10tps-${{ github.ref }} + group: nightly-bench-inclusion-sweep-${{ github.ref }} cancel-in-progress: true jobs: @@ -29,6 +36,7 @@ jobs: docker_image: ${{ steps.docker-image.outputs.docker_image }} image_label: ${{ steps.docker-image.outputs.image_label }} source_ref: ${{ steps.docker-image.outputs.source_ref }} + sweep_id: ${{ steps.sweep.outputs.sweep_id }} steps: - name: Checkout uses: actions/checkout@93cb6efe18208431cddfb8368fd83d5badbf9bfd # v5.0.1 @@ -71,18 +79,15 @@ jobs: echo "Using source ref: $source_ref" - name: Verify source git ref - id: verify-source run: | set -euo pipefail source_ref="${{ steps.docker-image.outputs.source_ref }}" git fetch --depth 1 origin "refs/tags/${source_ref}:refs/tags/${source_ref}" - source_sha=$(git rev-parse "${source_ref}^{}") - echo "Nightly source commit: $source_sha" + git rev-parse "${source_ref}^{}" - name: Check if Docker image exists run: | DOCKER_IMAGE="${{ steps.docker-image.outputs.docker_image }}" - echo "Checking if Docker image exists: $DOCKER_IMAGE" if docker manifest inspect "$DOCKER_IMAGE" > /dev/null 2>&1; then echo "Docker image exists: $DOCKER_IMAGE" else @@ -90,59 +95,92 @@ jobs: exit 1 fi - deploy-bench-10tps-network: + - name: Compute shared sweep id + id: sweep + run: | + # Shared across all three points so the dashboard groups the sweep. + echo "sweep_id=incl-$(date -u +%Y%m%d)-${{ github.run_id }}" >> "$GITHUB_OUTPUT" + + # ---- Deploy the single network the whole sweep runs against ---- + deploy: needs: select-image uses: ./.github/workflows/deploy-network.yml with: - network: bench-10tps - namespace: bench-10tps + network: bench-inclusion-sweep + namespace: bench-inclusion-sweep aztec_docker_image: ${{ needs.select-image.outputs.docker_image }} ref: ${{ needs.select-image.outputs.source_ref }} notify_on_failure: false secrets: inherit - wait-for-first-l2-block: - needs: - - select-image - - deploy-bench-10tps-network + wait: + needs: [select-image, deploy] runs-on: ubuntu-latest timeout-minutes: 120 steps: - - name: Checkout - uses: actions/checkout@93cb6efe18208431cddfb8368fd83d5badbf9bfd # v5.0.1 + - uses: actions/checkout@93cb6efe18208431cddfb8368fd83d5badbf9bfd # v5.0.1 with: ref: ${{ needs.select-image.outputs.source_ref }} - - - name: Authenticate to Google Cloud - uses: google-github-actions/auth@7c6bc770dae815cd3e89ee6cdf493a5fab2cc093 # v3.0.0 + - uses: google-github-actions/auth@7c6bc770dae815cd3e89ee6cdf493a5fab2cc093 # v3.0.0 with: credentials_json: ${{ secrets.GCP_SA_KEY }} - - - name: Set up Cloud SDK - uses: google-github-actions/setup-gcloud@aa5489c8933f4cc7a4f7d45035b3b1440c9c10db # v3.0.1 + - uses: google-github-actions/setup-gcloud@aa5489c8933f4cc7a4f7d45035b3b1440c9c10db # v3.0.1 with: install_components: gke-gcloud-auth-plugin - - name: Wait for first L2 block env: GCP_PROJECT_ID: ${{ secrets.GCP_PROJECT_ID }} - run: | - cd spartan - ./bootstrap.sh wait_for_l2_block bench-10tps + NAMESPACE: bench-inclusion-sweep + run: cd spartan && ./bootstrap.sh wait_for_l2_block bench-inclusion-sweep - benchmark: - needs: - - select-image - - wait-for-first-l2-block + # ---- Three points, sequential, on the SAME network ---- + point-1tps: + needs: [select-image, wait] + uses: ./.github/workflows/bench-inclusion-point.yml + with: + tps: "1" + namespace: bench-inclusion-sweep + docker_image: ${{ needs.select-image.outputs.docker_image }} + source_ref: ${{ needs.select-image.outputs.source_ref }} + sweep_id: ${{ needs.select-image.outputs.sweep_id }} + secrets: inherit + + # 5 TPS runs after 1 TPS finishes — gated on the network being up (wait), not + # on the 1 TPS result, so a failed point drops only itself. + point-5tps: + needs: [select-image, wait, point-1tps] + if: ${{ !cancelled() && needs.wait.result == 'success' }} + uses: ./.github/workflows/bench-inclusion-point.yml + with: + tps: "5" + namespace: bench-inclusion-sweep + docker_image: ${{ needs.select-image.outputs.docker_image }} + source_ref: ${{ needs.select-image.outputs.source_ref }} + sweep_id: ${{ needs.select-image.outputs.sweep_id }} + secrets: inherit + + point-10tps: + needs: [select-image, wait, point-5tps] + if: ${{ !cancelled() && needs.wait.result == 'success' }} + uses: ./.github/workflows/bench-inclusion-point.yml + with: + tps: "10" + namespace: bench-inclusion-sweep + docker_image: ${{ needs.select-image.outputs.docker_image }} + source_ref: ${{ needs.select-image.outputs.source_ref }} + sweep_id: ${{ needs.select-image.outputs.sweep_id }} + secrets: inherit + + # ---- Tear the network down once, regardless of point outcomes ---- + cleanup: + if: always() + needs: [select-image, deploy, wait, point-1tps, point-5tps, point-10tps] runs-on: ubuntu-latest steps: - - name: Checkout - uses: actions/checkout@93cb6efe18208431cddfb8368fd83d5badbf9bfd # v5.0.1 + - uses: actions/checkout@93cb6efe18208431cddfb8368fd83d5badbf9bfd # v5.0.1 with: ref: ${{ needs.select-image.outputs.source_ref }} - - - name: Run 10 TPS benchmark - timeout-minutes: 240 + - name: Cleanup network resources env: AWS_ACCESS_KEY_ID: ${{ secrets.AWS_ACCESS_KEY_ID }} AWS_SECRET_ACCESS_KEY: ${{ secrets.AWS_SECRET_ACCESS_KEY }} @@ -150,51 +188,23 @@ jobs: BUILD_INSTANCE_SSH_KEY: ${{ secrets.BUILD_INSTANCE_SSH_KEY }} GCP_SA_KEY: ${{ secrets.GCP_SA_KEY }} GCP_PROJECT_ID: ${{ secrets.GCP_PROJECT_ID }} - SLACK_BOT_TOKEN: ${{ secrets.SLACK_BOT_TOKEN }} - RUN_ID: ${{ github.run_id }} - AWS_SHUTDOWN_TIME: 240 NO_SPOT: 1 - SKIP_NETWORK_DEPLOY: "1" - run: | - ./.github/ci3.sh network-bench-10tps bench-10tps bench-10tps "${{ needs.select-image.outputs.docker_image }}" - - cleanup: - if: always() - needs: - - select-image - - deploy-bench-10tps-network - - wait-for-first-l2-block - - benchmark - runs-on: ubuntu-latest - steps: - - name: Checkout - uses: actions/checkout@93cb6efe18208431cddfb8368fd83d5badbf9bfd # v5.0.1 - with: - ref: ${{ needs.select-image.outputs.source_ref }} - - - name: Cleanup network resources - uses: ./.github/actions/network-teardown - with: - env_file: bench-10tps - namespace: bench-10tps - gcp_sa_key: ${{ secrets.GCP_SA_KEY }} - gcp_project_id: ${{ secrets.GCP_PROJECT_ID }} + run: ./.github/ci3.sh network-teardown bench-inclusion-sweep bench-inclusion-sweep notify-failure: if: ${{ always() && failure() && github.event_name != 'workflow_dispatch' }} needs: - select-image - - deploy-bench-10tps-network - - wait-for-first-l2-block - - benchmark - - cleanup + - deploy + - wait + - point-1tps + - point-5tps + - point-10tps runs-on: ubuntu-latest steps: - - name: Checkout - uses: actions/checkout@93cb6efe18208431cddfb8368fd83d5badbf9bfd # v5.0.1 + - uses: actions/checkout@93cb6efe18208431cddfb8368fd83d5badbf9bfd # v5.0.1 with: ref: ${{ needs.select-image.outputs.source_ref }} - - name: Notify Slack on failure env: SLACK_BOT_TOKEN: ${{ secrets.SLACK_BOT_TOKEN }} @@ -203,6 +213,6 @@ jobs: IMAGE="${{ needs.select-image.outputs.image_label || 'unknown' }}" RUN_URL="https://github.com/${{ github.repository }}/actions/runs/${{ github.run_id }}" ./ci3/slack_notify_with_claudebox_kickoff "#alerts-next-scenario" \ - "Nightly 10 TPS benchmark FAILED (image ${IMAGE}): <${RUN_URL}|View Run> (🤖)" \ - "Nightly 10 TPS benchmark failed (image ${IMAGE}). CI run: ${RUN_URL}. Investigate the benchmark failure and identify the root cause." \ + "Nightly inclusion sweep FAILED (image ${IMAGE}): <${RUN_URL}|View Run> (🤖)" \ + "Nightly inclusion sweep failed (image ${IMAGE}). CI run: ${RUN_URL}. Deploy/wait failures fail the whole sweep; a failed individual point drops only that point." \ --link "$RUN_URL" diff --git a/bootstrap.sh b/bootstrap.sh index 919c1a331448..4f9aa7e096e0 100755 --- a/bootstrap.sh +++ b/bootstrap.sh @@ -936,6 +936,36 @@ case "$cmd" in bench_merge cache_upload spartan-bench-10tps-$(git rev-parse HEAD^{tree}).tar.gz bench-out/bench.json ;; + "ci-network-inclusion-sweep") + # Args: [docker_image] + # Runs one inclusion-sweep point (TARGET_TPS) on the given network. + # The v4 run JSON (tagged BENCH_SWEEP_ID) is uploaded to GCS inside + # bench_inclusion_point; deploy/teardown of each point's namespace is done by + # the workflow, so this is normally called with SKIP_NETWORK_DEPLOY=1. + export CI=1 + env_file="${1:?env_file is required}" + namespace="${2:?namespace is required}" + docker_image="${3:-}" + build + export NAMESPACE="$namespace" + if [ "${SKIP_NETWORK_DEPLOY:-0}" != "1" ]; then + # If no docker image provided, build and push to aztecdev + if [ -z "$docker_image" ]; then + release-image/bootstrap.sh push_pr + docker_image="aztecprotocol/aztecdev:$(git rev-parse HEAD)" + fi + export AZTEC_DOCKER_IMAGE="$docker_image" + spartan/bootstrap.sh network_deploy "${env_file}" + else + echo "SKIP_NETWORK_DEPLOY=1, running inclusion-sweep point (${TARGET_TPS:-10} TPS) against existing network '$namespace'." + fi + # Run one inclusion-sweep point (TARGET_TPS / BENCH_SWEEP_ID from env). + spartan/bootstrap.sh bench_inclusion_point "${env_file}" + rm -rf bench-out + mkdir -p bench-out + bench_merge + cache_upload spartan-bench-inclusion-${TARGET_TPS:-10}tps-$(git rev-parse HEAD^{tree}).tar.gz bench-out/bench.json + ;; "ci-network-teardown") # Args: # Tears down a deployed network. diff --git a/ci.sh b/ci.sh index 01d2e6aeb8b4..70317d31bffa 100755 --- a/ci.sh +++ b/ci.sh @@ -298,6 +298,21 @@ case "$cmd" in [ "${SKIP_NETWORK_DEPLOY:-0}" = "1" ] && skip_network_deploy=1 bootstrap_ec2 "SKIP_NETWORK_DEPLOY=$skip_network_deploy ./bootstrap.sh ci-network-bench-10tps $*" ;; + network-inclusion-sweep) + # Args: [docker_image] + # Runs one inclusion-sweep point at TARGET_TPS against an existing + # network, tagged with BENCH_SWEEP_ID. The workflow deploys/tears down each + # point's namespace separately, so this is normally called with + # SKIP_NETWORK_DEPLOY=1. TARGET_TPS / BENCH_SWEEP_ID / BENCH_SWEEP_LABEL come + # from the caller's env and are threaded into the remote command. + export CI_DASHBOARD="network" + export JOB_ID="x-${2:?namespace is required}-network-inclusion-sweep" CPUS=16 + export AWS_SHUTDOWN_TIME=${AWS_SHUTDOWN_TIME:-180} + export INSTANCE_POSTFIX="n-incl-sweep" + skip_network_deploy=0 + [ "${SKIP_NETWORK_DEPLOY:-0}" = "1" ] && skip_network_deploy=1 + bootstrap_ec2 "TARGET_TPS=${TARGET_TPS:-10} BENCH_SWEEP_ID=${BENCH_SWEEP_ID:-} BENCH_SWEEP_LABEL=${BENCH_SWEEP_LABEL:-inclusion-sweep} SKIP_NETWORK_DEPLOY=$skip_network_deploy ./bootstrap.sh ci-network-inclusion-sweep $*" + ;; network-teardown) # Args: export CI_DASHBOARD="network" diff --git a/spartan/.gitignore b/spartan/.gitignore index da7cd59acdb2..0e2a2e78ade5 100644 --- a/spartan/.gitignore +++ b/spartan/.gitignore @@ -35,5 +35,6 @@ environments/* !environments/alpha-net.env !environments/mbps-pipeline.env !environments/bench-10tps.env +!environments/bench-inclusion-sweep.env *.tfvars !terraform/deploy-external-secrets/*.tfvars diff --git a/spartan/bootstrap.sh b/spartan/bootstrap.sh index 4a4a19db9d69..344ad7ca7d03 100755 --- a/spartan/bootstrap.sh +++ b/spartan/bootstrap.sh @@ -182,18 +182,6 @@ function block_capacity_bench_cmds { echo "$(hash):TIMEOUT=${timeout} BENCH_OUTPUT=bench-out/block_capacity.bench.json $root/yarn-project/end-to-end/scripts/run_test.sh simple block_capacity.test.ts" } -function bench_10tps_cmds { - # Mix: 1 tps of high-value + 9 tps of low-value, total still 10 tps. The - # high-value lane is what we measure for the headline client-observed - # inclusion latency (low-value txs pay near-network-min and are allowed to - # fail fee checks, so they would skew the headline if measured). - local high_value_tps=1 - local low_value_tps=9 - local test_duration=${TEST_DURATION_SECONDS:-600} # 10 mins - local timeout=${BENCH_TIMEOUT_SECONDS:-7200} # account for initial committee formation - echo "$(hash):TIMEOUT=${timeout} BENCH_RUN_ID=${BENCH_RUN_ID:-} BENCH_OUTPUT=bench-out/n_tps.10tps.bench.json BENCH_SCENARIO=10tps LOW_VALUE_TPS=${low_value_tps} HIGH_VALUE_TPS=${high_value_tps} TEST_DURATION_SECONDS=${test_duration} $root/yarn-project/end-to-end/scripts/run_test.sh simple n_tps.test.ts" -} - function network_bench { rm -rf bench-out mkdir -p bench-out @@ -236,41 +224,75 @@ function block_capacity_bench { block_capacity_bench_cmds | parallelize 1 } -function bench_10tps { +# One point of the inclusion sweep: a fixed 1 TPS of high-value txs (the +# measured inclusion lane) plus (TARGET_TPS - 1) TPS of low-value background +# traffic to bring total load to the target. So inclusion latency is always +# measured for a properly-paying user's tx while the network runs at TARGET_TPS. +# Tagged with a shared BENCH_SWEEP_ID so the 1/5/10 points group as one sweep +# (schema v5). Each point runs in its own namespace. +function bench_inclusion_point_cmds { + local tps=${TARGET_TPS:-10} + local high_value_tps=1 + # Low-value lane makes up the difference to the target; clamp at 0 for a 1 TPS + # target. awk handles any fractional TARGET_TPS. + local low_value_tps + low_value_tps=$(awk "BEGIN{l=${tps}-${high_value_tps}; if(l<0)l=0; print l}") + local test_duration=${TEST_DURATION_SECONDS:-600} # 10 mins + local timeout=${BENCH_TIMEOUT_SECONDS:-7200} # account for committee formation + local scenario="incl_${tps/./_}tps" + echo "$(hash):TIMEOUT=${timeout} BENCH_RUN_ID=${BENCH_RUN_ID:-} BENCH_OUTPUT=bench-out/n_tps.${scenario}.bench.json BENCH_SCENARIO=${scenario} LOW_VALUE_TPS=${low_value_tps} HIGH_VALUE_TPS=${high_value_tps} TEST_DURATION_SECONDS=${test_duration} $root/yarn-project/end-to-end/scripts/run_test.sh simple n_tps.test.ts" +} + +function bench_inclusion_point { rm -rf bench-out mkdir -p bench-out local env_file="$1" source_network_env $env_file - echo_header "spartan bench-10tps" + local tps=${TARGET_TPS:-10} + echo_header "spartan inclusion-sweep point (${tps} TPS)" gcp_auth export_admin_api_key export K8S_ENRICHER=${K8S_ENRICHER:-1} - export BENCH_RUN_ID="${BENCH_RUN_ID:-$(date -u +%Y%m%d)-${COMMIT_HASH:0:10}}" - bench_10tps_cmds | parallelize 1 + export BENCH_RUN_ID="${BENCH_RUN_ID:-$(date -u +%Y%m%d)-incl-${tps}tps-${COMMIT_HASH:0:10}}" + # Capture the load-test exit code but do NOT abort: a degraded point (e.g. a + # higher-TPS point that misses its target, or any failed assertion) still + # produced inclusion records worth scraping. We always scrape below, then + # re-surface the failure at the end so the job status still reflects it. + local test_rc=0 + bench_inclusion_point_cmds | parallelize 1 || test_rc=$? + if [[ "$test_rc" -ne 0 ]]; then + echo "[bench_inclusion_point] load test exited ${test_rc}; scraping captured data anyway" + fi local metadata="/tmp/n_tps_timing_data.json" - local run_json="bench-out/bench-10tps-${BENCH_RUN_ID}.json" + local run_json="bench-out/bench-inclusion-${tps}tps-${BENCH_RUN_ID}.json" if [[ -f "$metadata" ]]; then local started=$(jq -r .startedAt < "$metadata") local ended=$(jq -r .endedAt < "$metadata") - echo "Scraping bench-10tps run ${BENCH_RUN_ID} (started=${started} ended=${ended})" + echo "Scraping inclusion-sweep point ${tps} TPS (run ${BENCH_RUN_ID}, started=${started} ended=${ended})" NAMESPACE="$NAMESPACE" GCP_PROJECT_ID="${GCP_PROJECT_ID:-}" ./scripts/bench_10tps/bench_scrape.ts \ --run-id "$BENCH_RUN_ID" \ --started "$started" \ --ended "$ended" \ - --target-tps 10 \ + --target-tps "$tps" \ + --sweep-id "${BENCH_SWEEP_ID:-}" \ + --sweep-label "${BENCH_SWEEP_LABEL:-inclusion-sweep}" \ + --benchmark-type "${BENCH_BENCHMARK_TYPE:-ingress-inclusion}" \ --workload sha256_hash_1024 \ --output "$run_json" \ --inclusion-records "$metadata" \ --wait-for-pending-zero \ --max-pending-wait-seconds "${BENCH_SCRAPE_MAX_PENDING_WAIT_SECONDS:-3600}" \ - || echo "[bench_10tps] scraper failed (non-fatal)" + || echo "[bench_inclusion_point] scraper failed (non-fatal)" network_bench_upload "$run_json" || echo "[network_bench] upload failed (non-fatal)" else - echo "[bench_10tps] no timing metadata at ${metadata}; skipping scraper" + echo "[bench_inclusion_point] no timing metadata at ${metadata}; skipping scraper" fi + + # Re-surface the load-test failure (if any) now that data has been scraped. + return "$test_rc" } function network_bench_upload { @@ -286,12 +308,12 @@ function network_bench_upload { # Reject anything that's not the schema we've designed the index against. local schema=$(jq -r .schemaVersion "$run_json") - if [[ "$schema" != "3" ]]; then - echo "[network_bench] run JSON has schemaVersion '$schema', expected '3'; skipping upload" + if [[ "$schema" != "5" ]]; then + echo "[network_bench] run JSON has schemaVersion '$schema', expected '5'; skipping upload" return 0 fi - local bucket="gs://aztec-testnet/network_bench" + local bucket="${NETWORK_BENCH_BUCKET:-gs://aztec-testnet/network_bench}" local run_id=$(jq -r .run.runId "$run_json") local target="${bucket}/${run_id}.json" @@ -304,6 +326,9 @@ function network_bench_upload { startedAt: .run.startedAt, endedAt: .run.endedAt, targetTps: .run.targetTps, + sweepId: .run.sweepId, + sweepLabel: .run.sweepLabel, + benchmarkType: .run.benchmarkType, workload: .run.workload, testDurationSeconds: .run.testDurationSeconds, namespace: .run.namespace, @@ -326,7 +351,7 @@ function network_bench_upload { gcloud storage cp "${bucket}/index.json" "$idx_local" elif echo "$desc_err" | grep -qiE 'not.?found|matched no objects|404'; then echo "[network_bench] no remote index.json yet; seeding empty" - echo '{"schemaVersion":"1","runs":[]}' > "$idx_local" + echo '{"schemaVersion":"2","runs":[]}' > "$idx_local" else echo "[network_bench] cannot read remote index.json:" echo "$desc_err" | head -5 @@ -334,7 +359,7 @@ function network_bench_upload { fi jq --argjson entry "$entry" --arg ts "$(date -u +%Y-%m-%dT%H:%M:%SZ)" ' - .schemaVersion = "1" + .schemaVersion = "2" | .generatedAt = $ts | .runs = ((.runs // []) | map(select(.runId != $entry.runId)) + [$entry] | sort_by(.endedAt) | reverse) @@ -415,7 +440,7 @@ case "$cmd" in run_network_tests "$1" "$2" ;; - network_tests|network_tests_1|network_tests_2|network_bench|proving_bench|block_capacity_bench|bench_10tps) + network_tests|network_tests_1|network_tests_2|network_bench|proving_bench|block_capacity_bench|bench_inclusion_point) env_file="$1" $cmd "$env_file" ;; @@ -458,6 +483,9 @@ case "$cmd" in "hash") echo $(hash) ;; + "network_bench_upload") + network_bench_upload "$1" + ;; test|test_cmds|gke|build|gcp_auth) $cmd ;; diff --git a/spartan/environments/bench-inclusion-sweep.env b/spartan/environments/bench-inclusion-sweep.env new file mode 100644 index 000000000000..393dadcbf755 --- /dev/null +++ b/spartan/environments/bench-inclusion-sweep.env @@ -0,0 +1,85 @@ +# Inclusion sweep — nightly benchmark network. +NAMESPACE=${NAMESPACE:-bench-inclusion-sweep} +CLUSTER=aztec-gke-private +RESOURCE_PROFILE=prod +GCP_REGION=us-west1-a +DESTROY_NAMESPACE=true +DESTROY_AZTEC_INFRA=true + +CREATE_ETH_DEVNET=true +DESTROY_ETH_DEVNET=true +ETHEREUM_CHAIN_ID=1337 +LABS_INFRA_MNEMONIC="test test test test test test test test test test test junk" +FUNDING_PRIVATE_KEY="0xac0974bec39a17e36ba4a6b4d238ff944bacb478cbed5efcae784d7bf4f2ff80" +CREATE_ROLLUP_CONTRACTS=true +VERIFY_CONTRACTS=false + +AZTEC_EPOCH_DURATION=8 +AZTEC_SLOT_DURATION=72 +AZTEC_PROOF_SUBMISSION_EPOCHS=100 +AZTEC_LAG_IN_EPOCHS_FOR_VALIDATOR_SET=1 +AZTEC_LAG_IN_EPOCHS_FOR_RANDAO=1 +AZTEC_INBOX_LAG=2 + +AZTEC_MANA_TARGET=2000000000 + +SPONSORED_FPC=true + +OTEL_COLLECTOR_ENDPOINT=REPLACE_WITH_GCP_SECRET + +VALIDATOR_REPLICAS=12 +VALIDATORS_PER_NODE=4 +VALIDATOR_PUBLISHERS_PER_REPLICA=4 +VALIDATOR_PUBLISHER_MNEMONIC_START_INDEX=5000 +VALIDATOR_RESOURCE_PROFILE="bench" +VALIDATOR_HA_REPLICAS=0 + +SEQ_BLOCK_DURATION_MS=6000 +SEQ_MAX_TX_PER_CHECKPOINT=800 +P2P_MAX_PENDING_TX_COUNT=20000 +SEQ_MIN_TX_PER_BLOCK=1 +SEQ_BUILD_CHECKPOINT_IF_EMPTY=true + +RPC_REPLICAS=10 +RPC_RESOURCE_PROFILE="bench" +RPC_INGRESS_ENABLED=false + +FULL_NODE_REPLICAS=10 +FULL_NODE_RESOURCE_PROFILE="bench" + +REAL_VERIFIER=false +PROVER_RESOURCE_PROFILE="dev-hi-tps" +PUBLISHERS_PER_PROVER=1 +PROVER_PUBLISHER_MNEMONIC_START_INDEX=8000 +PROVER_AGENT_POLL_INTERVAL_MS=10000 +PROVER_TEST_DELAY_TYPE=fixed +PROVER_TEST_VERIFICATION_DELAY_MS=60 +PROVER_AGENT_KEDA_ENABLED=true +PROVER_AGENT_KEDA_PROMETHEUS_SERVER_ADDRESS=REPLACE_WITH_GCP_SECRET +PROVER_AGENT_KEDA_MIN_REPLICAS=0 +PROVER_AGENT_KEDA_MAX_REPLICAS=10 +PROVER_AGENT_KEDA_SCALING_BANDS='[ + { + queueSize = 0 + replicas = 10 + } +]' + +AZTEC_SLASHING_ROUND_SIZE_IN_EPOCHS=1 +AZTEC_SLASHING_QUORUM=5 +AZTEC_SLASHING_EXECUTION_DELAY_IN_ROUNDS=0 +AZTEC_SLASHING_OFFSET_IN_ROUNDS=1 +AZTEC_LOCAL_EJECTION_THRESHOLD=90000000000000000000 + +DEBUG_P2P_INSTRUMENT_MESSAGES=true +FULL_NODE_INCLUDE_METRICS="aztec.p2p.gossip.agg_" +LOG_LEVEL='info;debug:simulator:public-processor,sequencer:state,sequencer:checkpoint-events' + +VALIDATOR_L1_PRIORITY_FEE_BUMP_PERCENTAGE=0 +VALIDATOR_L1_PRIORITY_FEE_RETRY_BUMP_PERCENTAGE=0 +PROVER_L1_PRIORITY_FEE_BUMP_PERCENTAGE=0 +PROVER_L1_PRIORITY_FEE_RETRY_BUMP_PERCENTAGE=0 + +RUN_TESTS=false + +P2P_TX_POOL_DELETE_TXS_AFTER_REORG=true diff --git a/spartan/environments/prove-n-tps-fake.env b/spartan/environments/prove-n-tps-fake.env index 1808fb482c31..a66544e5c0e6 100644 --- a/spartan/environments/prove-n-tps-fake.env +++ b/spartan/environments/prove-n-tps-fake.env @@ -43,14 +43,14 @@ PROVER_AGENT_KEDA_MAX_REPLICAS=200 PROVER_AGENT_KEDA_SCALING_BANDS='[ { queueSize = 0 - replicas = 4 + replicas = 8 }, { - queueSize = 50 - replicas = 10 + queueSize = 25 + replicas = 75 }, { - queueSize = 200 + queueSize = 100 replicas = 200 } ]' diff --git a/spartan/scripts/bench_10tps/bench_output.schema.json b/spartan/scripts/bench_10tps/bench_output.schema.json index 3685c72960d8..527dc9c10271 100644 --- a/spartan/scripts/bench_10tps/bench_output.schema.json +++ b/spartan/scripts/bench_10tps/bench_output.schema.json @@ -16,8 +16,8 @@ "properties": { "schemaVersion": { "type": "string", - "const": "3", - "description": "Bump when breaking the schema. Old JSONs keep their previous version so the dashboard can render them side-by-side. v3: timeSeries entries carry `series: [{labels, points}]` instead of bare `points` to support per-pod / per-label data." + "const": "5", + "description": "Bump when breaking the schema. Old JSONs keep their previous version so the dashboard can render them side-by-side. v3: timeSeries entries carry `series: [{labels, points}]` instead of bare `points`. v4 (additive): adds optional `provingInfra` (hint-gen + proving-queue-by-job_type series) and `saturation` (per-role ELU/CPU/memory, max + avg) sections, plus `run.sweepId`/`run.sweepLabel` so a night's 1/5/10 TPS points group as one sweep. v5 (additive): adds `run.benchmarkType` so the dashboard can group a day's sweeps by the kind of benchmark (ingress-inclusion, simulated-proving, real-proving, block-capacity). All prior fields retained." }, "run": { "$ref": "#/$defs/runMeta" @@ -30,6 +30,14 @@ "$ref": "#/$defs/timeSeriesSection", "description": "PromQL query_range results. Continuous-sampled metrics keyed by unixEpoch; the dashboard normalises to time-within-run via unixEpoch - run.startedAt at render time so multiple runs can overlay on the same x-axis." }, + "provingInfra": { + "$ref": "#/$defs/metricSeriesMap", + "description": "v4. Proving-path series for the proving-infra view: prover-node hint-gen / tx re-execution (public_processor.* + prover_node.*_processing.duration scoped to the prover-node pod) and proving-queue behaviour broken down by job_type (aztec_proving_job_type label). Optional — empty/absent on inclusion-only runs." + }, + "saturation": { + "$ref": "#/$defs/metricSeriesMap", + "description": "v4. Per-role resource saturation: ELU, CPU, memory, and event-loop delay (mean, raw nanoseconds) for each role (validator / rpc / fullNode / proverNode / broker / agent), each emitted as both the hottest pod (max across pods) and the role average (avg across pods). Never a single hand-picked pod. Optional — absent on older runs." + }, "blocks": { "type": "array", "description": "Per-block records parsed from structured logs (each block emits one `Processed N successful txs and M failed txs ...` info line). Authoritative for per-block facts — Prometheus histograms cannot recover per-block samples.", @@ -60,15 +68,29 @@ } }, "$defs": { + "containerResources": { + "type": "object", + "additionalProperties": false, + "description": "CPU/memory requests and limits of a pod's main aztec container, captured verbatim from the Kubernetes pod spec. Values are Kubernetes quantity strings (e.g. cpu '3500m', memory '12Gi').", + "properties": { + "requests": { + "type": "object", + "additionalProperties": { + "type": "string" + } + }, + "limits": { + "type": "object", + "additionalProperties": { + "type": "string" + } + } + } + }, "runMeta": { "type": "object", "additionalProperties": false, - "required": [ - "runId", - "startedAt", - "endedAt", - "namespace" - ], + "required": ["runId", "startedAt", "endedAt", "namespace"], "properties": { "runId": { "type": "string", @@ -96,9 +118,7 @@ }, "namespace": { "type": "string", - "examples": [ - "bench-10tps" - ] + "examples": ["bench-10tps"] }, "gcpProject": { "type": "string", @@ -120,15 +140,31 @@ "type": "number", "minimum": 0 }, + "sweepId": { + "type": "string", + "description": "v4. Groups the runs of one sweep (e.g. a night's 1/5/10 TPS points) so the dashboard can plot them together. Shared across the points of a sweep; absent for standalone runs." + }, + "sweepLabel": { + "type": "string", + "description": "v4. Human-readable label for the sweep this run belongs to (e.g. 'inclusion-sweep' or 'proving-sweep'). Optional." + }, + "benchmarkType": { + "type": "string", + "enum": [ + "ingress-inclusion", + "simulated-proving", + "real-proving", + "block-capacity" + ], + "description": "v5. The kind of benchmark this run measures. Groups a day's sweeps in the dashboard sidebar (Day -> benchmark type). 'real-proving' typically only runs weekly. Optional; absent runs are treated as 'ingress-inclusion'." + }, "testDurationSeconds": { "type": "integer", "minimum": 0 }, "workload": { "type": "string", - "examples": [ - "sha256_hash_1024" - ] + "examples": ["sha256_hash_1024"] }, "aztecConfig": { "type": "object", @@ -162,16 +198,19 @@ }, "description": "Distinct node pools used by this role, when exposed as node labels." }, + "resourceProfiles": { + "type": "array", + "description": "Distinct CPU/memory request+limit profiles of the role's pods (deduped by content). Normally one entry per role; a second entry indicates pods of this role were sized differently. For the bench profiles request==limit (guaranteed QoS).", + "items": { + "$ref": "#/$defs/containerResources" + } + }, "nodes": { "type": "array", "items": { "type": "object", "additionalProperties": false, - "required": [ - "role", - "podName", - "nodeName" - ], + "required": ["role", "podName", "nodeName"], "properties": { "role": { "type": "string" @@ -187,6 +226,9 @@ }, "nodePool": { "type": "string" + }, + "resources": { + "$ref": "#/$defs/containerResources" } } } @@ -205,9 +247,7 @@ }, "profile": { "type": "string", - "examples": [ - "network-requirements" - ] + "examples": ["network-requirements"] } } }, @@ -239,40 +279,25 @@ "description": "Maximum time the scraper was allowed to wait for validator pending TxPool depth to reach zero." }, "pendingAtScrape": { - "type": [ - "number", - "null" - ], + "type": ["number", "null"], "minimum": 0, "description": "Validator pending TxPool depth observed when scraping started, or null when the pending drain gate was disabled." }, "pendingByRoleAtScrape": { - "type": [ - "object", - "null" - ], + "type": ["object", "null"], "description": "Pending TxPool depth by pod role at scrape start. RPC/full-node pending can remain non-zero after validators drain, which indicates load that did not propagate to proposers before expiry.", "additionalProperties": false, "properties": { "rpc": { - "type": [ - "number", - "null" - ], + "type": ["number", "null"], "minimum": 0 }, "validator": { - "type": [ - "number", - "null" - ], + "type": ["number", "null"], "minimum": 0 }, "fullNode": { - "type": [ - "number", - "null" - ], + "type": ["number", "null"], "minimum": 0 } } @@ -288,119 +313,129 @@ "summary": { "type": "object", "additionalProperties": false, - "required": [ - "headlineKpi", - "inclusionTpsMean", - "targetTps" - ], + "required": ["headlineKpi", "inclusionTpsMean", "targetTps"], "properties": { "headlineKpi": { - "type": [ - "number", - "null" - ], - "description": "inclusionTpsMean / targetTps. The single number on the dashboard top strip." + "type": ["number", "null"], + "description": "inclusionTpsMean / targetTps. The single number on the dashboard top strip. ~1.0 on a healthy run; below 1 only when the network cannot keep up with offered load (warmup/drain no longer dilute it)." }, "targetTps": { "type": "number" }, "inclusionTpsMean": { - "type": [ - "number", - "null" - ], - "description": "Inclusion throughput over the observed inclusion window. Uses exact block-log throughput when block records are available, otherwise falls back to the Prometheus inclusionTps mean." + "type": ["number", "null"], + "description": "Steady-state inclusion throughput from the block log: txs mined between the first block that included txs (warmup ramp trimmed) and load stop (drain tail trimmed), divided by that span. Falls back to inclusionTpsWindowMean when block logs are unavailable." + }, + "inclusionTpsWindowMean": { + "type": ["number", "null"], + "description": "Total txs mined divided by the whole observed window (start to drain end). Diluted by the warmup ramp and post-load drain tail; retained for transparency alongside the steady-state inclusionTpsMean." }, "inclusionTpsPeak": { - "type": [ - "number", - "null" - ], + "type": ["number", "null"], "description": "Peak sampled Prometheus rolling inclusion rate over the observed scrape window." }, "inclusionLatencyP50Ms": { - "type": [ - "number", - "null" - ] + "type": ["number", "null"] }, "inclusionLatencyP95Ms": { - "type": [ - "number", - "null" - ] + "type": ["number", "null"] }, "inclusionLatencyP99Ms": { - "type": [ - "number", - "null" - ] + "type": ["number", "null"] }, "blockBuildDurationP50Ms": { - "type": [ - "number", - "null" - ] + "type": ["number", "null"] }, "blockBuildDurationP95Ms": { - "type": [ - "number", - "null" - ] + "type": ["number", "null"] + }, + "blockBuildAvgTxsPerBlock": { + "type": ["number", "null"], + "description": "Mean successfulCount over non-empty blocks in the inclusion window. Context for the per-tx build figures below." + }, + "blockBuildPerTxMsAggregate": { + "type": ["number", "null"], + "description": "Block build cost per tx: sum(buildDurationMs) / sum(txs) over non-empty blocks. Single headline 'build-ms per tx'." + }, + "blockBuildMarginalMsPerTx": { + "type": ["number", "null"], + "description": "Marginal build cost of one tx: OLS slope of buildDurationMs vs txCount across non-empty blocks (buildMs = fixed + marginal*txCount). Null if < 2 blocks or uniform tx counts." + }, + "blockBuildFixedOverheadMsPerBlock": { + "type": ["number", "null"], + "description": "Fixed per-block build overhead: OLS intercept of buildDurationMs vs txCount. The load-sensitive component independent of tx count." }, "publicProcessorTxDurationP50Ms": { - "type": [ - "number", - "null" - ] + "type": ["number", "null"] }, "publicProcessorTxDurationP95Ms": { - "type": [ - "number", - "null" - ] + "type": ["number", "null"] + }, + "mempoolTxMinedDelayP50Ms": { + "type": ["number", "null"], + "description": "Pool-side pending-to-mined delay (aztec_mempool_tx_mined_delay, now - receivedAt at the mined transition), across all pool txs. Distinct from the client-observed inclusionLatency* (high-value lane only)." + }, + "mempoolTxMinedDelayP95Ms": { + "type": ["number", "null"] + }, + "mempoolTxMinedDelayP99Ms": { + "type": ["number", "null"] + }, + "attestationFailedNodeIssueCount": { + "type": ["number", "null"], + "description": "Total attester-side attestation failures over the observed window (aztec_validator_attestation_failed_node_issue_count: timeout / txs_not_available / parent_block_not_found / etc.). The reorg-diagnostic headline — high values mean attesters could not re-execute proposals in time, dragging the committee below quorum. null if the metric was unavailable." + }, + "attestationFailedBadProposalCount": { + "type": ["number", "null"], + "description": "Total attestations rejected over the window because the proposal was bad (invalid_proposal / state_mismatch / failed_txs / …), distinct from node-side issues." + }, + "attestationSuccessCount": { + "type": ["number", "null"], + "description": "Total successful attestations over the window. Denominator for an attestation failure ratio against the two failure counts above." }, "totalTxsMined": { - "type": [ - "integer", - "null" - ], + "type": ["integer", "null"], "description": "Exact sum from per-block logs. Null when block logs were unavailable and inclusionTpsMean came from Prometheus." }, "totalTxsFailed": { - "type": [ - "integer", - "null" - ], + "type": ["integer", "null"], "description": "Exact sum from per-block logs. Null when block logs were unavailable." }, "totalSilentSkipCount": { - "type": [ - "integer", - "null" - ], + "type": ["integer", "null"], "description": "Sum of per-block silentlySkippedCount. > 0 means the post-process blob-field revert path fired during the run." }, "totalSilentSkipDurationMs": { - "type": [ - "integer", - "null" - ], + "type": ["integer", "null"], "description": "Sum of per-block silentlySkippedDurationMs. Wall-clock 'wasted' on silently-skipped txs across the run." }, "reorgCount": { - "type": [ - "integer", - "null" - ], - "description": "Count of `Chain pruned` events during the run." + "type": ["integer", "null"], + "description": "Number of genuine CHAIN reorgs: `Chain pruned` events where ALL following validators rewound to the same block (event.validatorPruneCount >= validatorCount), i.e. the canonical chain reorged. Prunes reported by only a subset of validators are local divergences and are NOT counted — see nodeLocalPruneCount. Log-derived, so accurate regardless of node image; 0 if the validator fleet size could not be determined." + }, + "nodeLocalPruneCount": { + "type": ["integer", "null"], + "description": "Number of `Chain pruned` events that were NOT chain reorgs: a subset of validators (or non-validator followers) diverged locally and re-synced while the canonical chain held. Informational — does not indicate chain instability or make the headline provisional." + }, + "validatorCount": { + "type": ["integer", "null"], + "description": "Number of validator pods following the chain during the run (distinct validators that logged l2-block-handled). The denominator for chain-reorg detection — a reorg requires all of them to have pruned to the same block." + }, + "prunesByType": { + "type": "object", + "additionalProperties": false, + "description": "Total archiver prunes over the window by cause, summed across pods. 'unproven' is the proven/epoch prune; the rest are pending-chain prunes. From the prune_type-attributed metric; each value is null when that metric was unavailable (older node images).", + "properties": { + "unproven": { "type": ["number", "null"] }, + "uncheckpointed": { "type": ["number", "null"] }, + "l1_conflict": { "type": ["number", "null"] }, + "orphan": { "type": ["number", "null"] }, + "l1_mismatch": { "type": ["number", "null"] } + } }, "deepestReorgBlocks": { - "type": [ - "integer", - "null" - ], - "description": "Max (fromBlock - toBlock) across reorg events. 0 if no reorgs." + "type": ["integer", "null"], + "description": "Max (fromBlock - toBlock) across genuine chain-reorg events (podCount >= 2). 0 when there were no chain reorgs (single-node local prune depths are not counted here; see the chainPruned events for those)." } } }, @@ -417,6 +452,14 @@ "ingressTps": { "$ref": "#/$defs/timeSeries" }, + "throughputTps": { + "$ref": "#/$defs/timeSeries", + "description": "Tx throughput funnel as three labeled series (source = gossip | rpc_receive | mined) for overlaying on one chart: gossip propagation (per-node accepted tx-topic gossipsub, avg across pods), RPC ingress, and mined (avg across archivers)." + }, + "p2pBandwidthBytesPerSec": { + "$ref": "#/$defs/timeSeries", + "description": "Gossipsub P2P wire bandwidth (all topics) as four labeled series (source = recv_avg | recv_max | sent_avg | sent_max): per-pod average and hottest-pod receive/send byte rates. From the gossipsub RPC byte counters (no libp2p-level transport metric is exported)." + }, "mempoolSizeRpc": { "$ref": "#/$defs/timeSeries" }, @@ -490,6 +533,18 @@ "attestationsCollectAllowanceMean": { "$ref": "#/$defs/timeSeries" }, + "attestationFailedNodeIssueByErrorTypeRate": { + "$ref": "#/$defs/timeSeries" + }, + "attestationFailedBadProposalByErrorTypeRate": { + "$ref": "#/$defs/timeSeries" + }, + "attestationSuccessRate": { + "$ref": "#/$defs/timeSeries" + }, + "pruneCountByType": { + "$ref": "#/$defs/timeSeries" + }, "txCollectorTxsFromMempoolRate": { "$ref": "#/$defs/timeSeries" }, @@ -510,14 +565,17 @@ } } }, + "metricSeriesMap": { + "type": "object", + "description": "v4. Open map of slug -> timeSeries, same per-series shape as timeSeriesSection but without a fixed slug list. Used for provingInfra and saturation, whose slugs are generated per role / job_type.", + "additionalProperties": { + "$ref": "#/$defs/timeSeries" + } + }, "timeSeries": { "type": "object", "additionalProperties": false, - "required": [ - "metric", - "source", - "series" - ], + "required": ["metric", "source", "series"], "properties": { "metric": { "type": "string", @@ -525,19 +583,11 @@ }, "unit": { "type": "string", - "examples": [ - "ms", - "tps", - "mana/s", - "count" - ] + "examples": ["ms", "tps", "mana/s", "count"] }, "source": { "type": "string", - "enum": [ - "promql", - "client_observed" - ], + "enum": ["promql", "client_observed"], "description": "Provenance: 'promql' = scraped via PromQL from cluster Prometheus; 'client_observed' = computed in this scraper from per-tx records emitted by n_tps.test.ts (e.g. headline tx_mined_delay)." }, "query": { @@ -560,10 +610,7 @@ "seriesEntry": { "type": "object", "additionalProperties": false, - "required": [ - "labels", - "points" - ], + "required": ["labels", "points"], "properties": { "labels": { "type": "object", @@ -584,20 +631,14 @@ "tsPoint": { "type": "object", "additionalProperties": false, - "required": [ - "unixEpoch", - "value" - ], + "required": ["unixEpoch", "value"], "properties": { "unixEpoch": { "type": "integer", "description": "Seconds since unix epoch for this sample. Dashboards normalise to time-within-run via unixEpoch - run.startedAt at render time." }, "value": { - "type": [ - "number", - "null" - ], + "type": ["number", "null"], "description": "Metric value. null if Prom returned NaN / no data for this step." } } @@ -605,11 +646,7 @@ "blockRecord": { "type": "object", "additionalProperties": false, - "required": [ - "blockNumber", - "blockNumberInTest", - "minedAt" - ], + "required": ["blockNumber", "blockNumberInTest", "minedAt"], "properties": { "blockNumber": { "type": "integer", @@ -671,10 +708,7 @@ "event": { "type": "object", "additionalProperties": false, - "required": [ - "at", - "type" - ], + "required": ["at", "type"], "properties": { "at": { "type": "string", @@ -682,10 +716,7 @@ }, "type": { "type": "string", - "enum": [ - "chainPruned", - "slotSummary" - ] + "enum": ["chainPruned", "slotSummary"] }, "source": { "type": "string", @@ -699,6 +730,10 @@ "type": "integer", "description": "For chainPruned: the post-prune tip." }, + "validatorPruneCount": { + "type": "integer", + "description": "For chainPruned: distinct VALIDATOR pods that logged this prune (same toBlock within the dedupe window). A genuine chain reorg requires this to equal the validator fleet size (summary.validatorCount); fewer means a subset of validators (or non-validator followers) diverged locally and re-synced." + }, "slotNumber": { "type": "integer", "description": "For slotSummary: L2 slot number." @@ -761,13 +796,7 @@ "sequencerStateSlot": { "type": "object", "additionalProperties": false, - "required": [ - "slotNumber", - "startedAt", - "endedAt", - "totalMs", - "states" - ], + "required": ["slotNumber", "startedAt", "endedAt", "totalMs", "states"], "properties": { "slotNumber": { "type": "integer", @@ -803,4 +832,4 @@ } } } -} \ No newline at end of file +} diff --git a/spartan/scripts/bench_10tps/bench_scrape.ts b/spartan/scripts/bench_10tps/bench_scrape.ts index 77d1805d2d53..581a1d6b414c 100755 --- a/spartan/scripts/bench_10tps/bench_scrape.ts +++ b/spartan/scripts/bench_10tps/bench_scrape.ts @@ -1,8 +1,14 @@ #!/usr/bin/env -S node --experimental-strip-types --no-warnings // -// Scrape a completed bench-10tps run into a schema-conformant JSON payload. -// Contract: bench_output.schema.json (v3). Invoked by the bench_10tps function -// in spartan/bootstrap.sh after n_tps.test.ts finishes. +// Scrape a completed inclusion-sweep run into a schema-conformant JSON payload. +// Contract: bench_output.schema.json (v5). Invoked by the bench_inclusion_point +// function in spartan/bootstrap.sh after n_tps.test.ts finishes. +// +// Alongside the inclusion timeSeries the payload carries two PromQL sections: +// - provingInfra: prover-node hint-gen (tx re-execution) + proving-queue +// behaviour broken down by job_type. +// - saturation: per-role ELU/CPU/memory, each as max (hottest pod) + avg. +// Both scrape independently so one failing does not abort the others. // // Two independent scrape paths so one failing does not abort the other: // 1. Prometheus (port-forward to the cluster-shared metrics-prometheus-server) @@ -56,6 +62,9 @@ type Args = { inclusionRecords: string | undefined; waitForPendingZero: boolean; maxPendingWaitSeconds: number; + sweepId: string | undefined; + sweepLabel: string | undefined; + benchmarkType: string | undefined; }; function parseArgs(): Args { @@ -94,6 +103,10 @@ function parseArgs(): Args { String(DEFAULT_MAX_PENDING_WAIT_SECONDS), ), ), + sweepId: get("--sweep-id", env.BENCH_SWEEP_ID ?? "") || undefined, + sweepLabel: get("--sweep-label", env.BENCH_SWEEP_LABEL ?? "") || undefined, + benchmarkType: + get("--benchmark-type", env.BENCH_BENCHMARK_TYPE ?? "") || undefined, }; } @@ -373,6 +386,87 @@ const TIME_SERIES_DEFS: Record = { unit: "tps", query: `sum(rate(aztec_node_receive_tx_count${NS}[1m]))`, }, + // Throughput funnel — tx rate at three stages, as three labeled series (source= + // gossip|rpc_receive|mined) in one entry so the dashboard overlays them on one + // chart. gossip: per-node accepted tx-topic gossipsub messages, avg across pods + // (every node accepts each unique tx once, so avg ~= unique-tx propagation rate; + // sum would overcount by the pod count). rpc_receive: receiveTx on the single + // submission node (= ingressTps). mined: archiver block tx rate, avg across + // archivers (= inclusionTps). + throughputTps: { + metric: + "gossipsub_accepted_messages_total|aztec_node_receive_tx_count|aztec_archiver_block_tx_count_sum", + unit: "tps", + query: + `label_replace(avg(rate(gossipsub_accepted_messages_total{k8s_namespace_name="${NAMESPACE}",topic="tx"}[1m])), "source", "gossip", "", "") or ` + + `label_replace(sum(rate(aztec_node_receive_tx_count${NS}[1m])), "source", "rpc_receive", "", "") or ` + + `label_replace(avg(rate(aztec_archiver_block_tx_count_sum${NS}[1m])), "source", "mined", "", "")`, + }, + // Gossipsub P2P wire bandwidth (all topics), as four labeled series: receive and + // send, each as the per-pod average and the hottest pod (max). Per pod, not + // summed, since the question is whether any node's bandwidth is a wall — the max + // series surfaces gossip load that isn't evenly spread. No libp2p-level transport + // metric is exported, so these gossipsub RPC byte counters are the bandwidth + // signal (they dominate P2P traffic). + p2pBandwidthBytesPerSec: { + metric: "gossipsub_rpc_recv_bytes_total|gossipsub_rpc_sent_bytes_total", + unit: "bytes/sec", + query: + `label_replace(avg(rate(gossipsub_rpc_recv_bytes_total${NS}[1m])), "source", "recv_avg", "", "") or ` + + `label_replace(max(rate(gossipsub_rpc_recv_bytes_total${NS}[1m])), "source", "recv_max", "", "") or ` + + `label_replace(avg(rate(gossipsub_rpc_sent_bytes_total${NS}[1m])), "source", "sent_avg", "", "") or ` + + `label_replace(max(rate(gossipsub_rpc_sent_bytes_total${NS}[1m])), "source", "sent_max", "", "")`, + }, + // Duration of the RPC node's receiveTx handler (aztec.node.receive_tx.duration, + // a histogram). This is the tx-ingest cost on the submission path — the metric + // to watch when RPC ingress is the bottleneck (climbs as the RPC saturates). + ingressTxDurationP50: { + metric: "aztec_node_receive_tx_duration_milliseconds", + unit: "ms", + query: histQuantile( + 0.5, + "aztec_node_receive_tx_duration_milliseconds_bucket", + ), + }, + ingressTxDurationP99: { + metric: "aztec_node_receive_tx_duration_milliseconds", + unit: "ms", + query: histQuantile( + 0.99, + "aztec_node_receive_tx_duration_milliseconds_bucket", + ), + }, + // Pool-side pending->mined delay measured inside the tx pool + // (aztec_mempool_tx_mined_delay, recorded as now - receivedAt at the mined + // transition). This is the node's own view of how long txs sat in the mempool + // before being mined, across ALL pool txs. Distinct from txMinedDelay* below, + // which is the client-observed inclusion latency for the high-value lane only. + // No aztec_pool_name filter needed: the attestation pool uses a different + // metric name (aztec_mempool_attestations_mined_delay). + mempoolTxMinedDelayP50: { + metric: "aztec_mempool_tx_mined_delay_milliseconds", + unit: "ms", + query: histQuantile( + 0.5, + "aztec_mempool_tx_mined_delay_milliseconds_bucket", + ), + }, + mempoolTxMinedDelayP95: { + metric: "aztec_mempool_tx_mined_delay_milliseconds", + unit: "ms", + query: histQuantile( + 0.95, + "aztec_mempool_tx_mined_delay_milliseconds_bucket", + ), + }, + mempoolTxMinedDelayP99: { + metric: "aztec_mempool_tx_mined_delay_milliseconds", + unit: "ms", + query: histQuantile( + 0.99, + "aztec_mempool_tx_mined_delay_milliseconds_bucket", + ), + }, // Pending mempool size sliced by pod role. Three single-series slugs make cross-run // overlay clean: pod names are unstable (replica counts and restart suffixes // change between runs) but role is stable. Each query filters to TxPool to @@ -500,6 +594,40 @@ const TIME_SERIES_DEFS: Record = { // code records attestationTimeAllowed in seconds. query: `avg(aztec_sequencer_attestations_collect_allowance_milliseconds${NS}) * 1000`, }, + // Attester-side attestation failures, broken down by error_type. The + // error_type=timeout slice is the signal that diagnosed the 10 TPS reorgs: an + // attester that could not re-execute the proposed checkpoint in time, dragging + // the committee below quorum. Summed across pods (validators emit this) so the + // series is the network-wide failure rate per cause. + attestationFailedNodeIssueByErrorTypeRate: { + metric: "aztec_validator_attestation_failed_node_issue_count", + unit: "tps", + query: `sum by (aztec_error_type)(rate(aztec_validator_attestation_failed_node_issue_count${NS}[1m]))`, + }, + // Attestations rejected because the proposal itself was bad (invalid_proposal, + // state_mismatch, failed_txs, …) — distinct from the node-side issues above. + attestationFailedBadProposalByErrorTypeRate: { + metric: "aztec_validator_attestation_failed_bad_proposal_count", + unit: "tps", + query: `sum by (aztec_error_type)(rate(aztec_validator_attestation_failed_bad_proposal_count${NS}[1m]))`, + }, + // Successful attestations, the denominator for a failure ratio. + attestationSuccessRate: { + metric: "aztec_validator_attestation_success_count", + unit: "tps", + query: `sum(rate(aztec_validator_attestation_success_count${NS}[1m]))`, + }, + // Archiver prunes broken down by cause (prune_type). 'unproven' is the + // proven/epoch prune; 'uncheckpointed'/'l1_conflict'/'orphan'/'l1_mismatch' are pending-chain + // reorgs that move a node's proposed tip (world-state then logs "Chain pruned"). + // Summed across pods, so a value here is the network-wide prune rate per cause; + // see summary.reorgCount for how many distinct pods diverged. Requires the + // prune_type-attributed metric (new image); empty on older images. + pruneCountByType: { + metric: "aztec_archiver_prune_count", + unit: "tps", + query: `sum by (aztec_archiver_prune_type)(rate(aztec_archiver_prune_count${NS}[1m]))`, + }, checkpointBlockCountMean: { metric: "aztec_sequencer_checkpoint_block_count", unit: "count", @@ -560,12 +688,169 @@ const TIME_SERIES_DEFS: Record = { }, }; -async function scrapeTimeSeries( +// --- v4: per-role resource saturation (ELU / CPU / memory) --- +// Roles are matched by pod-name prefix within the namespace. The proposer +// rotates, so never hand-pick a pod: emit max() (hottest pod) AND avg() per role. +const SATURATION_ROLES: Record = { + validator: `${NAMESPACE}-validator.*`, + rpc: `${NAMESPACE}-rpc.*`, + fullNode: `${NAMESPACE}-full-node.*`, + proverNode: `${NAMESPACE}-prover-node.*`, + broker: `${NAMESPACE}-prover-broker.*`, + agent: `${NAMESPACE}-prover-agent.*`, +}; + +// OTel metric -> Prometheus name. ELU + heap come from +// telemetry-client/src/nodejs_metrics_monitor.ts (nodejs.* prefix, NOT aztec_). +// CPU comes from @opentelemetry/host-metrics (process.cpu.utilization), not the +// nodejs monitor. NOTE: ELU and especially CPU may be telemetry-gated in the +// bench env — if so these series come back empty (verify on the live env and +// adjust the metric name / enable the exporter as needed). +const SATURATION_METRICS: { key: string; metric: string; unit: string }[] = [ + { key: "elu", metric: "nodejs_eventloop_utilization", unit: "ratio" }, + { key: "cpu", metric: "process_cpu_utilization", unit: "ratio" }, + // OTel exports the v8 heap gauge with a `_bytes` unit suffix. + { key: "mem", metric: "nodejs_memory_v8_heap_usage_bytes", unit: "bytes" }, + // Event-loop delay (mean of the per-scrape distribution), raw nanoseconds. The + // max-across-pods series surfaces the role's most event-loop-blocked pod — e.g. + // the prover node, whose synchronous hint-gen blocks its main thread for seconds. + { + key: "eventLoopDelay", + metric: "nodejs_eventloop_delay_mean_nanoseconds", + unit: "ns", + }, +]; + +function buildSaturationDefs(): Record { + const defs: Record = {}; + for (const [role, podPattern] of Object.entries(SATURATION_ROLES)) { + const sel = `{k8s_namespace_name="${NAMESPACE}",k8s_pod_name=~"${podPattern}"}`; + const cap = role.charAt(0).toUpperCase() + role.slice(1); + for (const { key, metric, unit } of SATURATION_METRICS) { + // max() across pods = hottest pod; avg() = role average. Single series each. + defs[`${key}${cap}Max`] = { metric, unit, query: `max(${metric}${sel})` }; + defs[`${key}${cap}Avg`] = { metric, unit, query: `avg(${metric}${sel})` }; + } + } + return defs; +} +const SATURATION_DEFS = buildSaturationDefs(); + +// --- v4: proving-infra (hint-gen on the prover-node + proving-queue by job_type) --- +// "Hint generation" is the prover node re-executing the epoch's txs. There is no +// `aztec.prover_node.execution.duration` metric; the re-execution is instrumented +// as public_processor.* + prover_node.*_processing.duration on the prover-node +// pod. Proving-queue behaviour is broken down by the aztec_proving_job_type label. +const PROVER_NODE_SEL = `{k8s_namespace_name="${NAMESPACE}",k8s_pod_name=~"${NAMESPACE}-prover-node.*"}`; +const JOB_TYPE = "aztec_proving_job_type"; +const proverNodeHist = (q: number, bucket: string) => + `histogram_quantile(${q}, sum by (le)(rate(${bucket}${PROVER_NODE_SEL}[1m])))`; +const queueByJobType = (metric: string) => + `sum by (${JOB_TYPE})(${metric}${NS})`; +const queueRateByJobType = (metric: string) => + `sum by (${JOB_TYPE})(rate(${metric}${NS}[1m]))`; +const queueHistByJobType = (q: number, bucket: string) => + `histogram_quantile(${q}, sum by (le, ${JOB_TYPE})(rate(${bucket}${NS}[1m])))`; + +const PROVING_INFRA_DEFS: Record = { + // Hint-gen: prover-node tx re-execution (the proving bottleneck at high TPS). + hintGenPublicTxDurationP50: { + metric: "aztec_public_processor_tx_duration", + unit: "ms", + query: proverNodeHist( + 0.5, + "aztec_public_processor_tx_duration_milliseconds_bucket", + ), + }, + hintGenPublicTxDurationP99: { + metric: "aztec_public_processor_tx_duration", + unit: "ms", + query: proverNodeHist( + 0.99, + "aztec_public_processor_tx_duration_milliseconds_bucket", + ), + }, + hintGenPublicPhaseDurationP50: { + metric: "aztec_public_processor_phase_duration", + unit: "ms", + query: proverNodeHist( + 0.5, + "aztec_public_processor_phase_duration_milliseconds_bucket", + ), + }, + hintGenBlockProcessingDurationP50: { + metric: "aztec_prover_node_block_processing_duration", + unit: "ms", + query: proverNodeHist( + 0.5, + "aztec_prover_node_block_processing_duration_milliseconds_bucket", + ), + }, + hintGenBlockProcessingDurationP99: { + metric: "aztec_prover_node_block_processing_duration", + unit: "ms", + query: proverNodeHist( + 0.99, + "aztec_prover_node_block_processing_duration_milliseconds_bucket", + ), + }, + hintGenCheckpointProcessingDurationP50: { + metric: "aztec_prover_node_checkpoint_processing_duration", + unit: "ms", + query: proverNodeHist( + 0.5, + "aztec_prover_node_checkpoint_processing_duration_milliseconds_bucket", + ), + }, + // Proving queue, broken down by job_type (one series per job type). + provingQueueSizeByJobType: { + metric: "aztec_proving_queue_size", + unit: "count", + query: queueByJobType("aztec_proving_queue_size"), + }, + provingQueueActiveJobsByJobType: { + metric: "aztec_proving_queue_active_jobs_count", + unit: "count", + query: queueByJobType("aztec_proving_queue_active_jobs_count"), + }, + provingQueueJobDurationP50ByJobType: { + metric: "aztec_proving_queue_job_duration", + unit: "ms", + query: queueHistByJobType( + 0.5, + "aztec_proving_queue_job_duration_milliseconds_bucket", + ), + }, + provingQueueJobDurationP99ByJobType: { + metric: "aztec_proving_queue_job_duration", + unit: "ms", + query: queueHistByJobType( + 0.99, + "aztec_proving_queue_job_duration_milliseconds_bucket", + ), + }, + // Rates of terminal job outcomes — the run #95 stall showed up as timeouts. + provingQueueTimedOutJobsByJobType: { + metric: "aztec_proving_queue_timed_out_jobs_count", + unit: "count", + query: queueRateByJobType("aztec_proving_queue_timed_out_jobs_count"), + }, + provingQueueResolvedJobsByJobType: { + metric: "aztec_proving_queue_resolved_jobs_count", + unit: "count", + query: queueRateByJobType("aztec_proving_queue_resolved_jobs_count"), + }, +}; + +// Scrape a map of slug -> PromQL def via query_range. One failing query emits an +// empty series for that slug rather than aborting the whole section. +async function scrapeDefs( + defs: Record, startedAtEpoch: number, endedAtEpoch: number, ): Promise> { const out: Record = {}; - for (const [slug, def] of Object.entries(TIME_SERIES_DEFS)) { + for (const [slug, def] of Object.entries(defs)) { try { const series = await queryRange(def.query, startedAtEpoch, endedAtEpoch); out[slug] = { @@ -577,7 +862,7 @@ async function scrapeTimeSeries( series, }; } catch (err) { - log(`timeSeries.${slug} scrape failed, emitting empty series`, { + log(`series.${slug} scrape failed, emitting empty series`, { err: err instanceof Error ? err.message : String(err), }); out[slug] = { @@ -593,6 +878,9 @@ async function scrapeTimeSeries( return out; } +const scrapeTimeSeries = (startedAtEpoch: number, endedAtEpoch: number) => + scrapeDefs(TIME_SERIES_DEFS, startedAtEpoch, endedAtEpoch); + // --- gcloud log scrape --- type GcloudEntry = { @@ -645,17 +933,27 @@ const timeFilter = (startedAt: string, endedAt: string) => // --- Run-context capture (image + aztec config env) --- +// CPU/memory requests and limits for a pod's main container, captured verbatim +// from the Kubernetes pod spec (e.g. {cpu: "3500m", memory: "12Gi"}). For the +// bench profiles request==limit (guaranteed QoS), so both are usually equal. +type ContainerResources = { + requests?: Record; + limits?: Record; +}; + type RoleNode = { role: string; podName: string; nodeName: string; instanceType?: string; nodePool?: string; + resources?: ContainerResources; }; type RoleInfrastructure = { instanceTypes: string[]; nodePools: string[]; + resourceProfiles: ContainerResources[]; nodes: RoleNode[]; }; @@ -663,11 +961,15 @@ type Infrastructure = { roles: Record; }; +// Patterns are matched against the pod name with the namespace prefix removed +// and anchored with ^, so the L1 infra pods (eth-validator / eth-execution / +// eth-beacon) are not misread as aztec roles — an unanchored /-validator/ would +// match "-eth-validator-0". const INFRASTRUCTURE_ROLE_PATTERNS = [ - { role: "validator", pattern: /-validator(?:-|$)/ }, - { role: "prover", pattern: /-prover-(?:agent|node|broker)(?:-|$)/ }, - { role: "rpc", pattern: /-rpc(?:-|$)/ }, - { role: "fullNode", pattern: /-full-node(?:-|$)/ }, + { role: "validator", pattern: /^validator(?:-|$)/ }, + { role: "prover", pattern: /^prover-(?:agent|node|broker)(?:-|$)/ }, + { role: "rpc", pattern: /^rpc(?:-|$)/ }, + { role: "fullNode", pattern: /^full-node(?:-|$)/ }, ]; // Curated subset of env vars worth recording per run so the dashboard can @@ -771,7 +1073,13 @@ async function captureInfrastructure(): Promise { const podsJson = JSON.parse(podsOut) as { items?: Array<{ metadata?: { name?: string }; - spec?: { nodeName?: string }; + spec?: { + nodeName?: string; + containers?: Array<{ + name?: string; + resources?: ContainerResources; + }>; + }; }>; }; const nodesJson = JSON.parse(nodesOut) as { @@ -814,6 +1122,7 @@ async function captureInfrastructure(): Promise { nodePool: labels["cloud.google.com/gke-nodepool"] ?? labels["eks.amazonaws.com/nodegroup"], + resources: resourcesForPod(pod.spec?.containers), }; }) .filter((node): node is RoleNode => node !== undefined) @@ -841,15 +1150,50 @@ async function captureInfrastructure(): Promise { } function roleForPodName(podName: string): string | undefined { - if (!podName.startsWith(`${NAMESPACE}-`)) { + const prefix = `${NAMESPACE}-`; + if (!podName.startsWith(prefix)) { return undefined; } + const suffix = podName.slice(prefix.length); return INFRASTRUCTURE_ROLE_PATTERNS.find(({ pattern }) => - pattern.test(podName), + pattern.test(suffix), )?.role; } +// Resource requests/limits of a pod's main "aztec" container (falls back to the +// first container if none is named "aztec"). Returns undefined when the spec +// declares no resources, so a pod without sizing is simply omitted. +function resourcesForPod( + containers: + | Array<{ name?: string; resources?: ContainerResources }> + | undefined, +): ContainerResources | undefined { + const container = + containers?.find((c) => c.name === "aztec") ?? containers?.[0]; + const resources = container?.resources; + if (!resources) { + return undefined; + } + const out: ContainerResources = {}; + if (resources.requests && Object.keys(resources.requests).length > 0) { + out.requests = resources.requests; + } + if (resources.limits && Object.keys(resources.limits).length > 0) { + out.limits = resources.limits; + } + return out.requests || out.limits ? out : undefined; +} + function infrastructureForNodes(nodes: RoleNode[]): RoleInfrastructure { + // Pods of a role normally share one resource profile, but dedupe by content + // so a mid-run resize or a stray pod surfaces as a second distinct profile + // rather than being silently collapsed. + const profilesByKey = new Map(); + for (const node of nodes) { + if (node.resources) { + profilesByKey.set(JSON.stringify(node.resources), node.resources); + } + } return { instanceTypes: Array.from( new Set( @@ -859,6 +1203,7 @@ function infrastructureForNodes(nodes: RoleNode[]): RoleInfrastructure { nodePools: Array.from( new Set(nodes.flatMap((node) => (node.nodePool ? [node.nodePool] : []))), ).sort(), + resourceProfiles: [...profilesByKey.values()], nodes, }; } @@ -1084,6 +1429,11 @@ type ChainPrunedEvent = { source: "log"; fromBlock?: number; toBlock?: number; + // Distinct VALIDATOR pods that logged this prune (same toBlock within the + // dedupe window). Compared against the validator fleet size to decide whether + // the canonical chain reorged: < fleet = some validators diverged locally and + // re-synced; == fleet = every validator rewound, a genuine chain reorg. + validatorPruneCount: number; }; type SlotSummaryEvent = { @@ -1163,10 +1513,12 @@ async function scrapeChainPrunedEvents( at: entry.timestamp, time: Date.parse(entry.timestamp), toBlock: Number(m[1]), + pod: entry.resource?.labels?.pod_name ?? "unknown", }; }) .filter( - (x): x is { at: string; time: number; toBlock: number } => x !== null, + (x): x is { at: string; time: number; toBlock: number; pod: string } => + x !== null, ) .sort((a, b) => a.time - b.time); @@ -1181,6 +1533,23 @@ async function scrapeChainPrunedEvents( } } + // Distinct VALIDATOR pods that pruned to the same toBlock within the dedupe + // window. A genuine chain reorg means every validator rewound; a lone validator + // (or non-validator follower) pruning is a local divergence that self-heals. + const validatorPrefix = `${NAMESPACE}-validator-`; + const validatorPruneCountFor = (toBlock: number, time: number) => + new Set( + parsed + .filter( + (p) => + p.toBlock === toBlock && + p.time >= time && + p.time - time < DEDUPE_WINDOW_MS && + p.pod.startsWith(validatorPrefix), + ) + .map((p) => p.pod), + ).size; + return deduped.map(({ at, time, toBlock }) => { // fromBlock is reconstructed because server_world_state_synchronizer.ts:459 // doesn't log it structurally. Correlate with the latest block we've seen @@ -1194,10 +1563,42 @@ async function scrapeChainPrunedEvents( source: "log" as const, fromBlock: before || undefined, toBlock, + validatorPruneCount: validatorPruneCountFor(toBlock, time), }; }); } +// Number of validator pods actively following the chain — distinct validators +// that logged l2-block-handled in the window. Denominator for chain-reorg +// detection: a genuine reorg requires every following validator to have pruned, +// so down validators are excluded (they can't report and shouldn't gate the +// count). Returns 0 on scrape failure, which disables reorg detection (every +// prune is then treated as node-local) rather than false-positiving. +async function scrapeValidatorFleetSize( + startedAt: string, + endedAt: string, +): Promise { + const filter = [ + `resource.labels.namespace_name="${NAMESPACE}"`, + `resource.labels.pod_name=~"${NAMESPACE}-validator-"`, + `jsonPayload.eventName="l2-block-handled"`, + timeFilter(startedAt, endedAt), + ].join(" AND "); + try { + const entries = await gcloudRead(filter); + return new Set( + entries + .map((e) => e.resource?.labels?.pod_name) + .filter((p): p is string => !!p), + ).size; + } catch (err) { + log("validator fleet-size scrape failed", { + err: err instanceof Error ? err.message : String(err), + }); + return 0; + } +} + async function scrapeSlotSummaryEvents( startedAt: string, endedAt: string, @@ -1527,6 +1928,9 @@ type SummaryArgs = { targetTps: number; startedAtEpoch: number; inclusionEndedAtEpoch: number; + // Load-stop time (when the generator stopped sending), distinct from + // inclusionEndedAtEpoch (the drain end). Bounds the steady-state window. + loadEndedAtEpoch: number; windowSec: number; histogramWindowSec: number; endedAtEpoch: number; @@ -1534,8 +1938,56 @@ type SummaryArgs = { blocks: BlockRecord[]; events: Event[]; inclusionRecords: InclusionRecord[]; + // Number of validator pods following the chain; the denominator for deciding + // whether a prune was a network-wide chain reorg (all validators) vs local. + validatorCount: number; }; +type BlockBuildPerTx = { + blockBuildAvgTxsPerBlock: number | null; + blockBuildPerTxMsAggregate: number | null; + blockBuildMarginalMsPerTx: number | null; + blockBuildFixedOverheadMsPerBlock: number | null; +}; + +// Decomposes block build time into a fixed per-block overhead and a marginal +// per-tx cost via an ordinary least-squares fit of build-ms against tx count +// over non-empty blocks (buildMs = fixed + marginal * txCount). The marginal +// slope is the (load-invariant) cost of adding one tx to a block; the intercept +// is the per-block overhead that grows with block size / system load. The +// aggregate is the simpler sum(buildMs)/sum(tx) — a single "build-ms per tx" +// headline. The OLS slope needs >= 2 blocks with differing tx counts, so +// marginal/fixed are null for a run with too few or uniform-width blocks. +function blockBuildPerTx(blocks: BlockRecord[]): BlockBuildPerTx { + const pts = blocks + .filter( + (b) => b.successfulCount > 0 && Number.isFinite(b.buildDurationSeconds), + ) + .map((b) => ({ x: b.successfulCount, y: b.buildDurationSeconds * 1000 })); + if (pts.length === 0) { + return { + blockBuildAvgTxsPerBlock: null, + blockBuildPerTxMsAggregate: null, + blockBuildMarginalMsPerTx: null, + blockBuildFixedOverheadMsPerBlock: null, + }; + } + const n = pts.length; + const sx = pts.reduce((s, p) => s + p.x, 0); + const sy = pts.reduce((s, p) => s + p.y, 0); + const sxx = pts.reduce((s, p) => s + p.x * p.x, 0); + const sxy = pts.reduce((s, p) => s + p.x * p.y, 0); + const denom = n * sxx - sx * sx; + const marginal = n >= 2 && denom !== 0 ? (n * sxy - sx * sy) / denom : null; + const fixed = marginal !== null ? (sy - marginal * sx) / n : null; + return { + blockBuildAvgTxsPerBlock: sx / n, + blockBuildPerTxMsAggregate: sx > 0 ? sy / sx : null, + blockBuildMarginalMsPerTx: marginal, + blockBuildFixedOverheadMsPerBlock: fixed, + }; +} + async function buildSummary(a: SummaryArgs): Promise> { // inclusionTps is single-series; series[0] holds all points. const inclusionPoints = ( @@ -1557,10 +2009,42 @@ async function buildSummary(a: SummaryArgs): Promise> { ? inclusionBlocks.reduce((s, b) => s + b.successfulCount, 0) : null; const promInclusionTpsMean = meanNonNull(inclusionPoints); - const inclusionTpsMean = + // Whole-observed-window mean: total mined / observed window. Diluted by the + // warmup ramp and the post-load drain tail; kept for transparency. + const inclusionTpsWindowMean = totalTxsMined !== null && a.windowSec > 0 ? totalTxsMined / a.windowSec : promInclusionTpsMean; + // Steady-state rate from the block log: start at the first block that actually + // included txs (trims the warmup ramp) and end at load stop, not the drain end + // (trims the cooldown tail), so the headline reflects sustained-load throughput + // and only drops below target when the network genuinely can't keep up. Falls + // back to the window mean when block logs are unavailable. + const minedBlocks = a.blocks + .map((b) => ({ + epoch: Math.floor(Date.parse(b.minedAt) / 1000), + n: b.successfulCount, + })) + .filter((b) => Number.isFinite(b.epoch)); + const firstInclusionEpoch = minedBlocks + .filter( + (b) => + b.n > 0 && b.epoch >= a.startedAtEpoch && b.epoch <= a.loadEndedAtEpoch, + ) + .reduce((min, b) => Math.min(min, b.epoch), Number.POSITIVE_INFINITY); + const steadySec = Number.isFinite(firstInclusionEpoch) + ? a.loadEndedAtEpoch - firstInclusionEpoch + : 0; + const steadyTxs = Number.isFinite(firstInclusionEpoch) + ? minedBlocks + .filter( + (b) => + b.epoch >= firstInclusionEpoch && b.epoch <= a.loadEndedAtEpoch, + ) + .reduce((s, b) => s + b.n, 0) + : 0; + const inclusionTpsMean = + steadySec > 0 ? steadyTxs / steadySec : inclusionTpsWindowMean; const inclusionTpsPeak = maxNonNull(inclusionPoints); if (!hasInclusionBlockRecords && promInclusionTpsMean !== null) { @@ -1599,7 +2083,18 @@ async function buildSummary(a: SummaryArgs): Promise> { log("No inclusion records loaded; summary.inclusionLatencyP* will be null"); } - const [buildP50, buildP95, ppTxP50, ppTxP95] = await Promise.all([ + const [ + buildP50, + buildP95, + ppTxP50, + ppTxP95, + mempoolMinedP50, + mempoolMinedP95, + mempoolMinedP99, + attestationFailedNodeIssueCount, + attestationFailedBadProposalCount, + attestationSuccessCount, + ] = await Promise.all([ safeInstant( oneShotQuantile( 0.5, @@ -1624,27 +2119,95 @@ async function buildSummary(a: SummaryArgs): Promise> { "aztec_public_processor_tx_duration_milliseconds_bucket", ), ), + // Pool-side pending->mined delay (now - receivedAt at the mined transition), + // across all pool txs. Companion to the time series of the same name; lets + // the dashboard trend it and compare against the client-observed + // inclusionLatency* (high-value lane only). + safeInstant( + oneShotQuantile(0.5, "aztec_mempool_tx_mined_delay_milliseconds_bucket"), + ), + safeInstant( + oneShotQuantile(0.95, "aztec_mempool_tx_mined_delay_milliseconds_bucket"), + ), + safeInstant( + oneShotQuantile(0.99, "aztec_mempool_tx_mined_delay_milliseconds_bucket"), + ), + // Total attestation outcomes over the observed window. The node-issue count + // is the headline reorg-diagnostic number (e.g. the run #95 "184" of failed + // attestations); success gives a denominator for a failure ratio. + safeInstant( + `sum(increase(aztec_validator_attestation_failed_node_issue_count${NS}[${windowSpec}]))`, + ), + safeInstant( + `sum(increase(aztec_validator_attestation_failed_bad_proposal_count${NS}[${windowSpec}]))`, + ), + safeInstant( + `sum(increase(aztec_validator_attestation_success_count${NS}[${windowSpec}]))`, + ), ]); - const reorgs = a.events.filter((e) => e.type === "chainPruned"); - const deepest = reorgs.reduce((max, e) => { - const d = (e.fromBlock ?? 0) - (e.toBlock ?? 0); - return d > max ? d : max; - }, 0); + // A genuine chain reorg requires EVERY following validator to have rewound to + // the same block (validatorPruneCount >= validatorCount). Anything less is a + // local divergence — a subset of validators (or non-validator followers) that + // pruned and re-synced while the canonical chain held — and does not + // destabilise the chain or the headline. If the validator fleet size is + // unknown (scrape failed) no prune is treated as a chain reorg. + const chainPrunes = a.events.filter( + (e): e is ChainPrunedEvent => e.type === "chainPruned", + ); + const chainReorgs = + a.validatorCount > 0 + ? chainPrunes.filter( + (e) => (e.validatorPruneCount ?? 0) >= a.validatorCount, + ) + : []; + const nodeLocalPruneCount = chainPrunes.length - chainReorgs.length; + const deepest = chainReorgs.reduce( + (max, e) => Math.max(max, (e.fromBlock ?? 0) - (e.toBlock ?? 0)), + 0, + ); + + // Prune totals by cause from the prune_type-attributed metric (new image; empty + // on older images). Complements the log-derived reorg classification above. + const pruneTypes = [ + "unproven", + "uncheckpointed", + "l1_conflict", + "orphan", + "l1_mismatch", + ] as const; + const pruneTypeTotals = await Promise.all( + pruneTypes.map((t) => + safeInstant( + `sum(increase(aztec_archiver_prune_count{k8s_namespace_name="${NAMESPACE}",aztec_archiver_prune_type="${t}"}[${windowSpec}]))`, + ), + ), + ); + const prunesByType = Object.fromEntries( + pruneTypes.map((t, i) => [t, pruneTypeTotals[i]]), + ) as Record<(typeof pruneTypes)[number], number | null>; return { headlineKpi: inclusionTpsMean === null ? null : inclusionTpsMean / a.targetTps, targetTps: a.targetTps, inclusionTpsMean, + inclusionTpsWindowMean, inclusionTpsPeak, inclusionLatencyP50Ms: inclLatP50, inclusionLatencyP95Ms: inclLatP95, inclusionLatencyP99Ms: inclLatP99, blockBuildDurationP50Ms: buildP50, blockBuildDurationP95Ms: buildP95, + ...blockBuildPerTx(inclusionBlocks), publicProcessorTxDurationP50Ms: ppTxP50, publicProcessorTxDurationP95Ms: ppTxP95, + mempoolTxMinedDelayP50Ms: mempoolMinedP50, + mempoolTxMinedDelayP95Ms: mempoolMinedP95, + mempoolTxMinedDelayP99Ms: mempoolMinedP99, + attestationFailedNodeIssueCount, + attestationFailedBadProposalCount, + attestationSuccessCount, totalTxsMined, totalTxsFailed: hasInclusionBlockRecords ? inclusionBlocks.reduce((s, b) => s + b.failedCount, 0) @@ -1655,7 +2218,10 @@ async function buildSummary(a: SummaryArgs): Promise> { totalSilentSkipDurationMs: hasInclusionBlockRecords ? inclusionBlocks.reduce((s, b) => s + b.silentlySkippedDurationMs, 0) : null, - reorgCount: reorgs.length, + reorgCount: chainReorgs.length, + nodeLocalPruneCount, + validatorCount: a.validatorCount, + prunesByType, deepestReorgBlocks: deepest, }; } @@ -1668,6 +2234,8 @@ function assertShape(payload: Record): void { "run", "summary", "timeSeries", + "provingInfra", + "saturation", "blocks", "events", ] as const; @@ -1676,9 +2244,9 @@ function assertShape(payload: Record): void { throw new Error(`output missing required top-level key: ${key}`); } } - if (payload.schemaVersion !== "3") { + if (payload.schemaVersion !== "5") { throw new Error( - `schemaVersion must be "3", got ${String(payload.schemaVersion)}`, + `schemaVersion must be "5", got ${String(payload.schemaVersion)}`, ); } const run = payload.run as Record; @@ -1913,6 +2481,22 @@ async function main(): Promise { log("Scraping Prometheus time-series"); const timeSeries = await scrapeTimeSeries(startedAtEpoch, promEndEpoch); + // v4: proving-infra (hint-gen + queue by job_type) and per-role saturation. + // Independent of the inclusion timeSeries scrape so a failure here cannot + // drop inclusion data, and vice versa. + log("Scraping proving-infra series (hint-gen + queue by job_type)"); + const provingInfra = await scrapeDefs( + PROVING_INFRA_DEFS, + startedAtEpoch, + promEndEpoch, + ); + log("Scraping per-role saturation series (ELU/CPU/memory, max + avg)"); + const saturation = await scrapeDefs( + SATURATION_DEFS, + startedAtEpoch, + promEndEpoch, + ); + log("Loading client-observed inclusion records"); const inclusionRecords = await loadInclusionRecords(args.inclusionRecords); // Compute the headline inclusion-latency time series from per-tx records @@ -1966,6 +2550,12 @@ async function main(): Promise { }); } + const validatorCount = await scrapeValidatorFleetSize( + args.startedAt, + logEndedAt, + ); + log(`Chain-following validator fleet size: ${validatorCount}`); + log("Scraping sequencer state transition logs from gcloud"); let sequencerStateSlots: SequencerStateSlot[] = []; try { @@ -1989,6 +2579,7 @@ async function main(): Promise { targetTps: args.targetTps, startedAtEpoch, inclusionEndedAtEpoch: drain.inclusionEndedAtEpoch, + loadEndedAtEpoch: endedAtEpoch, windowSec: observedWindowSec, histogramWindowSec: observedWindowSec, endedAtEpoch: drain.inclusionEndedAtEpoch, @@ -1996,10 +2587,11 @@ async function main(): Promise { blocks, events, inclusionRecords, + validatorCount, }); const payload = { - schemaVersion: "3", + schemaVersion: "5", run: { runId: args.runId, startedAt: args.startedAt, @@ -2014,6 +2606,11 @@ async function main(): Promise { gkeCluster: GKE_CLUSTER, ...(image !== undefined && { image }), targetTps: args.targetTps, + ...(args.sweepId !== undefined && { sweepId: args.sweepId }), + ...(args.sweepLabel !== undefined && { sweepLabel: args.sweepLabel }), + ...(args.benchmarkType !== undefined && { + benchmarkType: args.benchmarkType, + }), testDurationSeconds: windowSec, workload: args.workload, ...(Object.keys(aztecConfig).length > 0 && { aztecConfig }), @@ -2031,6 +2628,8 @@ async function main(): Promise { }, summary, timeSeries, + provingInfra, + saturation, blocks, events, sequencerStateSlots, diff --git a/spartan/terraform/deploy-aztec-infra/values/full-node-resources-bench.yaml b/spartan/terraform/deploy-aztec-infra/values/full-node-resources-bench.yaml new file mode 100644 index 000000000000..194256b5e0f6 --- /dev/null +++ b/spartan/terraform/deploy-aztec-infra/values/full-node-resources-bench.yaml @@ -0,0 +1,61 @@ +# Bench profile: deterministic full-node sizing for benchmarking. +# Full nodes still validate every gossiped tx and apply every block, so at +# 10 TPS they need the same 4-core tier as validators/RPC (request=limit, +# Guaranteed QoS, 3.5 CPU). The `cores: "4"` selector pins them to the dedicated +# 4-core spot pool (cluster/main.tf spot_nodes_4core) — one full node per spot +# box — instead of packing several onto 8-core spot. Spot affinity is REQUIRED +# (as in the prod-spot profile) so full nodes always land on spot; validators / +# RPC / prover stay on-demand so a mid-block spot eviction cannot corrupt the +# inclusion measurement (full nodes are not on the measurement path). +nodeSelector: + local-ssd: "false" + node-type: "network" + pool: "spot" + cores: "4" + +affinity: + nodeAffinity: + requiredDuringSchedulingIgnoredDuringExecution: + nodeSelectorTerms: + - matchExpressions: + - key: cloud.google.com/gke-spot + operator: Exists + +tolerations: + - key: "cloud.google.com/gke-spot" + operator: "Equal" + value: "true" + effect: "NoSchedule" + +replicaCount: 1 + +node: + resources: + requests: + cpu: "3.5" + memory: "8Gi" + limits: + cpu: "3.5" + memory: "8Gi" +persistence: + enabled: true + +statefulSet: + enabled: true + volumeClaimTemplates: + - metadata: + name: data + spec: + accessModes: [ReadWriteOnce] + resources: + requests: + storage: 16Gi + +service: + p2p: + enabled: true + nodePortEnabled: false + admin: + enabled: true + headless: + enabled: false diff --git a/spartan/terraform/deploy-aztec-infra/values/full-node-resources-spot.yaml b/spartan/terraform/deploy-aztec-infra/values/full-node-resources-spot.yaml new file mode 100644 index 000000000000..9f3695af922a --- /dev/null +++ b/spartan/terraform/deploy-aztec-infra/values/full-node-resources-spot.yaml @@ -0,0 +1,57 @@ +# Full-node profile that REQUIRES spot nodes (inclusion sweep). Same shape +# + resources as full-node-resources-prod.yaml, but the +# spot affinity is required (not merely preferred) so full nodes always land on +# spot, copying the pattern from prover-resources-dev.yaml. Only full nodes use +# this profile; validators / RPC / prover stay on-demand so mid-block spot +# eviction cannot corrupt the inclusion measurement. +nodeSelector: + local-ssd: "false" + node-type: "network" + pool: "spot" + +affinity: + nodeAffinity: + requiredDuringSchedulingIgnoredDuringExecution: + nodeSelectorTerms: + - matchExpressions: + - key: cloud.google.com/gke-spot + operator: Exists + +tolerations: + - key: "cloud.google.com/gke-spot" + operator: "Equal" + value: "true" + effect: "NoSchedule" + +replicaCount: 1 + +node: + resources: + requests: + cpu: "0.5" + memory: "2Gi" + limits: + cpu: "1.5" + memory: "6Gi" +persistence: + enabled: true + +statefulSet: + enabled: true + volumeClaimTemplates: + - metadata: + name: data + spec: + accessModes: [ReadWriteOnce] + resources: + requests: + storage: 16Gi + +service: + p2p: + enabled: true + nodePortEnabled: false + admin: + enabled: true + headless: + enabled: false diff --git a/spartan/terraform/deploy-aztec-infra/values/rpc-resources-bench.yaml b/spartan/terraform/deploy-aztec-infra/values/rpc-resources-bench.yaml new file mode 100644 index 000000000000..2024f4c22b37 --- /dev/null +++ b/spartan/terraform/deploy-aztec-infra/values/rpc-resources-bench.yaml @@ -0,0 +1,43 @@ +# Bench profile: deterministic, guaranteed RPC sizing for benchmarking. +# request=limit (Guaranteed QoS) reserves the cores; a >1.93-core request keeps +# RPC off the 2-core pool: one pod per dedicated 4-core node, on-demand. +# +# NOTE: the prod profile carries a `preferredDuringScheduling` affinity for +# cores=2 (so RPC normally favours the small pool). That preference is +# intentionally omitted here — the bench needs RPC on adequately-sized nodes. +nodeSelector: + local-ssd: "false" + node-type: "network" + +replicaCount: 1 + +node: + resources: + requests: + cpu: "3.5" + memory: "8Gi" + limits: + cpu: "3.5" + memory: "8Gi" +persistence: + enabled: true + +statefulSet: + enabled: true + volumeClaimTemplates: + - metadata: + name: data + spec: + accessModes: [ReadWriteOnce] + resources: + requests: + storage: 16Gi + +service: + p2p: + enabled: true + nodePortEnabled: false + admin: + enabled: true + headless: + enabled: false diff --git a/spartan/terraform/deploy-aztec-infra/values/validator-resources-bench.yaml b/spartan/terraform/deploy-aztec-infra/values/validator-resources-bench.yaml new file mode 100644 index 000000000000..d78e266f2f22 --- /dev/null +++ b/spartan/terraform/deploy-aztec-infra/values/validator-resources-bench.yaml @@ -0,0 +1,33 @@ +# Bench profile: deterministic, guaranteed validator sizing for benchmarking. +# The prod profile requests only 0.5 CPU with a node-type=network selector, so +# the scheduler bin-packs validators across the shared cluster's mixed 2-/4-core +# network pools. Pods that land on 2-core nodes run their 4 attesters on too +# little CPU, fall behind on re-execution, and fail to attest ("Timed out +# waiting for block with archive matching checkpoint proposal") — dragging the +# committee below quorum and causing checkpoint prunes at 10 TPS. +# +# Here request=limit (Guaranteed QoS) reserves the cores so nothing is +# contended, and a >1.93-core request keeps validators off the 2-core pool: +# one pod (4 attesters) per dedicated 4-core node. On-demand (no spot) so +# eviction can't corrupt the measurement. +validator: + nodeSelector: + local-ssd: "false" + node-type: "network" + node: + resources: + requests: + cpu: "3.5" + memory: "12Gi" + limits: + cpu: "3.5" + memory: "12Gi" + statefulSet: + volumeClaimTemplates: + - metadata: + name: data + spec: + accessModes: [ReadWriteOnce] + resources: + requests: + storage: 16Gi diff --git a/yarn-project/archiver/src/archiver.ts b/yarn-project/archiver/src/archiver.ts index 332dc52d3a72..501d624da8eb 100644 --- a/yarn-project/archiver/src/archiver.ts +++ b/yarn-project/archiver/src/archiver.ts @@ -523,6 +523,7 @@ export class Archiver extends ArchiverDataSourceBase implements L2BlockSink, Tra const prunedBlocks = await this.updater.removeBlocksWithoutProposedCheckpointAfter(pruneAfterBlockNumber); if (prunedBlocks.length > 0) { + this.instrumentation.recordPrune('orphan'); this.events.emit(L2BlockSourceEvents.L2PruneUncheckpointed, { type: L2BlockSourceEvents.L2PruneUncheckpointed, slotNumber: blockSlot, diff --git a/yarn-project/archiver/src/modules/instrumentation.ts b/yarn-project/archiver/src/modules/instrumentation.ts index 4e031872ca35..20eeff25311e 100644 --- a/yarn-project/archiver/src/modules/instrumentation.ts +++ b/yarn-project/archiver/src/modules/instrumentation.ts @@ -84,7 +84,9 @@ export class ArchiverInstrumentation { this.pruneDuration = meter.createHistogram(Metrics.ARCHIVER_PRUNE_DURATION); - this.pruneCount = createUpDownCounterWithDefault(meter, Metrics.ARCHIVER_PRUNE_COUNT); + this.pruneCount = createUpDownCounterWithDefault(meter, Metrics.ARCHIVER_PRUNE_COUNT, { + [Attributes.PRUNE_TYPE]: ['unproven', 'uncheckpointed', 'l1_conflict', 'orphan', 'l1_mismatch'], + }); this.blockProposalTxTargetCount = createUpDownCounterWithDefault( meter, @@ -150,10 +152,21 @@ export class ArchiverInstrumentation { } public processPrune(duration: number) { - this.pruneCount.add(1); + this.pruneCount.add(1, { [Attributes.PRUNE_TYPE]: 'unproven' }); this.pruneDuration.record(Math.ceil(duration)); } + /** + * Records a pending-chain reorg, where the archiver dropped proposed blocks (and world-state follows by pruning). The + * type distinguishes the cause: 'uncheckpointed' (slot ended without a checkpoint), 'l1_conflict' (proposed blocks + * conflicting with an L1 checkpoint), 'orphan' (no matching proposed checkpoint arrived before the deadline), or + * 'l1_mismatch' (the local checkpointed tip diverged from L1 — an L1 reorg or a pruned/missed-proof checkpoint — so + * already-checkpointed blocks were rewound). + */ + public recordPrune(pruneType: 'uncheckpointed' | 'l1_conflict' | 'orphan' | 'l1_mismatch') { + this.pruneCount.add(1, { [Attributes.PRUNE_TYPE]: pruneType }); + } + public updateLastProvenCheckpoint(checkpoint: CheckpointData) { const lastBlockNumberInCheckpoint = checkpoint.startBlock + checkpoint.blockCount - 1; this.blockHeight.record(lastBlockNumberInCheckpoint, { [Attributes.STATUS]: 'proven' }); diff --git a/yarn-project/archiver/src/modules/l1_synchronizer.ts b/yarn-project/archiver/src/modules/l1_synchronizer.ts index 13e1a5d2b4d1..1739dffccde2 100644 --- a/yarn-project/archiver/src/modules/l1_synchronizer.ts +++ b/yarn-project/archiver/src/modules/l1_synchronizer.ts @@ -314,6 +314,7 @@ export class ArchiverL1Synchronizer implements Traceable { const prunedBlocks = await this.updater.removeUncheckpointedBlocksAfter(lastCheckpointedBlockNumber); if (prunedBlocks.length > 0) { + this.instrumentation.recordPrune('uncheckpointed'); this.events.emit(L2BlockSourceEvents.L2PruneUncheckpointed, { type: L2BlockSourceEvents.L2PruneUncheckpointed, slotNumber: firstUncheckpointedBlockSlot, @@ -796,6 +797,9 @@ export class ArchiverL1Synchronizer implements Traceable { const checkpointsToRemove = localPendingCheckpointNumber - tipAfterUnwind; await this.updater.removeCheckpointsAfter(CheckpointNumber(tipAfterUnwind)); + if (checkpointsToRemove > 0) { + this.instrumentation.recordPrune('l1_mismatch'); + } this.log.warn( `Removed ${count(checkpointsToRemove, 'checkpoint')} after checkpoint ${tipAfterUnwind} ` + @@ -1096,6 +1100,8 @@ export class ArchiverL1Synchronizer implements Traceable { { prunedBlocks: result.prunedBlocks.map(b => b.toBlockInfo()), prunedSlotNumber, prunedCheckpointNumber }, ); + this.instrumentation.recordPrune('l1_conflict'); + // Emit event for listening services to react to the prune. // Note: slotNumber comes from the first pruned block. If pruned blocks theoretically spanned multiple slots, // only one slot number would be reported (though in practice all blocks in a checkpoint span a single slot). diff --git a/yarn-project/end-to-end/src/automine/contracts/state_vars.test.ts b/yarn-project/end-to-end/src/automine/contracts/state_vars.test.ts index b808114e2925..6695d135d630 100644 --- a/yarn-project/end-to-end/src/automine/contracts/state_vars.test.ts +++ b/yarn-project/end-to-end/src/automine/contracts/state_vars.test.ts @@ -406,6 +406,15 @@ describe('automine/contracts/state_vars', () => { } }); + // Drives the chain forward by sending a no-op tx per iteration (rather than warping wall-clock time) + // until the latest block's timestamp reaches `target`. Under the forced 12s slot duration a fixed + // block-count delay cannot count for the schedule, so we poll the real block timestamp instead. + const advanceChainToTimestamp = async (target: bigint) => { + while ((await aztecNode.getBlockData('latest'))!.header.globalVariables.timestamp < target) { + await authContract.methods.get_authorized().send({ from: defaultAccountAddress }); + } + }; + // Changes the authorized delay from 5 slots (360s) to 2 slots, advances the chain past the // scheduled timestamp_of_change by sending no-op txs, then proves the private read and asserts // the expirationTimestamp equals anchorTimestamp + newDelay - 1. @@ -436,11 +445,7 @@ describe('automine/contracts/state_vars', () => { // forces aztecSlotDuration=12s under pipelining (see fixtures/setup.ts), so a fixed // `delay(N blocks)` cannot count for the schedule — block timestamp polling is the // slot-duration-agnostic way to know we have crossed the schedule. - // REFACTOR: hand-rolled loop advancing the chain by sending no-op txs until a target timestamp is - // crossed; a DSL helper like advanceChainToTimestamp(node, timestampOfChange) should replace this. - while ((await aztecNode.getBlockData('latest'))!.header.globalVariables.timestamp < timestampOfChange) { - await authContract.methods.get_authorized().send({ from: defaultAccountAddress }); - } + await advanceChainToTimestamp(timestampOfChange); // We now call our AuthContract to see if the change in expiration timestamp has reflected our delay change. // expirationTimestamp is `anchor.timestamp + effective_minimum_delay`, where the anchor is the diff --git a/yarn-project/end-to-end/src/automine/effects/offchain_payment.parallel.test.ts b/yarn-project/end-to-end/src/automine/effects/offchain_payment.parallel.test.ts index 567d2749e780..6413f8b4318c 100644 --- a/yarn-project/end-to-end/src/automine/effects/offchain_payment.parallel.test.ts +++ b/yarn-project/end-to-end/src/automine/effects/offchain_payment.parallel.test.ts @@ -57,6 +57,20 @@ describe('automine/effects/offchain_payment', () => { logger.info(`Empty block mined. New L2 block: ${await aztecNode.getBlockNumber()}`); } + // Polls the PXE note view until `owner`'s balance equals `expected`. The PXE syncs asynchronously from the + // archiver, so the balance may lag briefly after a block is mined. + function waitForNoteBalance(owner: AztecAddress, expected: bigint) { + return retryUntil( + async () => { + const { result } = await contract.methods.get_balance(owner).simulate({ from: owner }); + return result === expected; + }, + `note balance of ${owner} to reach ${expected}`, + 30, + 0.1, + ); + } + // Reverts the chain to `checkpointBeforeTx`. Pauses the AutomineSequencer first: reverting restores the // un-mined transfer tx to the pending pool, and the sequencer's mempool poller would otherwise re-mine it // within ~50ms, racing the post-reorg balance assertions. Pausing only gates the poller; explicit ops @@ -211,18 +225,7 @@ describe('automine/effects/offchain_payment', () => { await forceEmptyBlock(); // Wait for the PXE to process the re-mined block and update its note view. - // The PXE syncs asynchronously from the archiver, so the balance may lag briefly. - // REFACTOR: hand-rolled poll waiting for PXE to reprocess re-mined offchain notes; a DSL helper - // (e.g. waitForNoteBalance or waitForPXESync) should replace this retryUntil loop. - await retryUntil( - async () => { - const { result } = await contract.methods.get_balance(bob).simulate({ from: bob }); - return result === paymentAmount; - }, - 'Bob balance restored after re-mine', - 30, - 0.1, - ); + await waitForNoteBalance(bob, paymentAmount); // Check that the message was reprocessed and Bob has his payment again. // Notice what we want to test here is that the offchain effects don't need to be re-enqueued diff --git a/yarn-project/end-to-end/src/automine/effects/pruned_blocks.test.ts b/yarn-project/end-to-end/src/automine/effects/pruned_blocks.test.ts index 35c25090df7f..223ccabdf5b6 100644 --- a/yarn-project/end-to-end/src/automine/effects/pruned_blocks.test.ts +++ b/yarn-project/end-to-end/src/automine/effects/pruned_blocks.test.ts @@ -1,8 +1,10 @@ import type { AztecAddress } from '@aztec/aztec.js/addresses'; +import type { Fr } from '@aztec/aztec.js/fields'; import type { Logger } from '@aztec/aztec.js/log'; import { MerkleTreeId } from '@aztec/aztec.js/trees'; import type { Wallet } from '@aztec/aztec.js/wallet'; import { CheatCodes } from '@aztec/aztec/testing'; +import type { BlockNumber } from '@aztec/foundation/branded-types'; import { retryUntil } from '@aztec/foundation/retry'; import { TokenContract } from '@aztec/noir-contracts.js/Token'; import type { AztecNode, AztecNodeDebug } from '@aztec/stdlib/interfaces/client'; @@ -73,6 +75,23 @@ describe('automine/effects/pruned_blocks', () => { } } + // Polls the historical leaf query until it starts throwing "Unable to find leaf", which is how a + // pruned world-state block surfaces to callers once the prune has propagated. + const waitForWorldStatePrune = (blockNumber: BlockNumber, note: Fr) => + retryUntil( + async () => { + try { + await aztecNode.findLeavesIndexes(blockNumber, MerkleTreeId.NOTE_HASH_TREE, [note]); + return false; + } catch (error) { + return (error as Error).message.includes('Unable to find leaf'); + } + }, + 'waiting for pruning', + 60, + 0.5, + ); + // Mints half the token amount (tx1), mines enough empty blocks to make that block eligible for pruning, // calls markAsProven + extra L1 blocks to finalize the prune, polls until the archive query on tx1's // block fails, then mints the other half and transfers the full amount. Asserts final balances. @@ -114,21 +133,7 @@ describe('automine/effects/pruned_blocks', () => { // The same historical query we performed before should now fail since this block is not available anymore. We poll // the node for a bit until it processes the blocks we marked as proven, causing the historical query to fail. logger.warn(`Awaiting 'unable to find leaf' error from node due to pruned history`); - // REFACTOR: hand-rolled poll waiting for world-state prune to propagate; a DSL helper such as - // waitForWorldStatePrune(node, blockNumber) should replace this retryUntil loop. - await retryUntil( - async () => { - try { - await aztecNode.findLeavesIndexes(firstMintReceipt.blockNumber!, MerkleTreeId.NOTE_HASH_TREE, [mintedNote!]); - return false; - } catch (error) { - return (error as Error).message.includes('Unable to find leaf'); - } - }, - 'waiting for pruning', - 60, - 0.5, - ); + await waitForWorldStatePrune(firstMintReceipt.blockNumber!, mintedNote!); // We've completed the setup we were interested in, and can now simply mint the second half of the amount, transfer // the full amount to the recipient (which will require the sender to discover and prove both the old and new notes) diff --git a/yarn-project/end-to-end/src/composed/e2e_token_bridge_tutorial_test.test.ts b/yarn-project/end-to-end/src/composed/e2e_token_bridge_tutorial_test.test.ts index 001b9eb7ca08..764458609c39 100644 --- a/yarn-project/end-to-end/src/composed/e2e_token_bridge_tutorial_test.test.ts +++ b/yarn-project/end-to-end/src/composed/e2e_token_bridge_tutorial_test.test.ts @@ -25,13 +25,19 @@ import { AuthRegistryArtifact, getStandardAuthRegistry } from '@aztec/standard-c import { registerInitialLocalNetworkAccountsInWallet } from '@aztec/wallets/testing'; import { getContract } from 'viem'; +import { mnemonicToAccount } from 'viem/accounts'; import { TestWallet } from '../test-wallet/test_wallet.js'; const MNEMONIC = 'test test test test test test test test test test test junk'; const { ETHEREUM_HOSTS = 'http://localhost:8545' } = process.env; -const l1Client = createExtendedL1Client(ETHEREUM_HOSTS.split(','), MNEMONIC); +// The local-network sequencer publishes its checkpoint txs to L1 from the default mnemonic's account +// 0 (the account viem hands out by default). Sharing that account here would interleave this test's +// L1 txs with the sequencer's on a single nonce sequence, so a deploy/bridge tx can be stranded in +// anvil's pool and never confirm (surfacing as a WaitForTransactionReceiptTimeoutError). Derive this +// client from a different index to give the test an independent L1 nonce space. +const l1Client = createExtendedL1Client(ETHEREUM_HOSTS.split(','), mnemonicToAccount(MNEMONIC, { addressIndex: 1 })); const ownerEthAddress = l1Client.account.address; const MINT_AMOUNT = BigInt(1e15); diff --git a/yarn-project/end-to-end/src/fixtures/setup.ts b/yarn-project/end-to-end/src/fixtures/setup.ts index 54e5139b4064..5c61aaba40dd 100644 --- a/yarn-project/end-to-end/src/fixtures/setup.ts +++ b/yarn-project/end-to-end/src/fixtures/setup.ts @@ -557,31 +557,33 @@ async function setupInner( } logger.trace('Deployed L1 rollup contracts'); - // Use metricsPort-based telemetry if provided, otherwise use the regular telemetry client - const telemetryClient = opts.metricsPort - ? await getEndToEndTestTelemetryClient(opts.metricsPort) - : await getTelemetryClient(opts.telemetryConfig); + // These boot steps are independent and write disjoint config keys, so run them concurrently: + // telemetry returns a client (no config write), shared blob storage writes blobFileStore* keys, + // and the ACVM/BB config resolvers write their own acvm*/bb* keys. + const [telemetryClient, , acvmConfig, bbConfig] = await Promise.all([ + // Use metricsPort-based telemetry if provided, otherwise use the regular telemetry client + opts.metricsPort ? getEndToEndTestTelemetryClient(opts.metricsPort) : getTelemetryClient(opts.telemetryConfig), + setupSharedBlobStorage(config), + getACVMConfig(logger), + getBBConfig(logger), + ]); logger.trace('Created telemetry client'); - - await setupSharedBlobStorage(config); logger.trace('Set up shared blob storage'); - logger.verbose('Creating and synching an aztec node', config); - - const acvmConfig = await getACVMConfig(logger); if (acvmConfig) { config.acvmWorkingDirectory = acvmConfig.acvmWorkingDirectory; config.acvmBinaryPath = acvmConfig.acvmBinaryPath; } logger.trace('Resolved ACVM config'); - const bbConfig = await getBBConfig(logger); if (bbConfig) { config.bbBinaryPath = bbConfig.bbBinaryPath; config.bbWorkingDirectory = bbConfig.bbWorkingDirectory; } logger.trace('Resolved Barretenberg config'); + logger.verbose('Creating and synching an aztec node', config); + let mockGossipSubNetwork: MockGossipSubNetwork | undefined; let p2pClientDeps: P2PClientDeps | undefined = undefined; diff --git a/yarn-project/end-to-end/src/p2p/gossip_network.test.ts b/yarn-project/end-to-end/src/p2p/gossip_network.test.ts index 7bd7bcde8568..1edd171f69eb 100644 --- a/yarn-project/end-to-end/src/p2p/gossip_network.test.ts +++ b/yarn-project/end-to-end/src/p2p/gossip_network.test.ts @@ -177,10 +177,12 @@ describe('e2e_p2p_network', () => { ); t.logger.info('Submitting transactions'); - for (const node of nodes) { - const context = await submitTransactions(t.logger, node, NUM_TXS_PER_NODE, t.fundedAccount); - txsSentViaDifferentNodes.push(context); - } + // Each submitTransactions call builds its own wallet/PXE, so submissions are independent and can run + // concurrently. Promise.all preserves node order, keeping txsSentViaDifferentNodes[i] aligned with nodes[i]. + const submitted = await Promise.all( + nodes.map(node => submitTransactions(t.logger, node, NUM_TXS_PER_NODE, t.fundedAccount)), + ); + txsSentViaDifferentNodes.push(...submitted); t.logger.info('Waiting for transactions to be mined'); // now ensure that all txs were successfully mined diff --git a/yarn-project/end-to-end/src/p2p/preferred_gossip_network.test.ts b/yarn-project/end-to-end/src/p2p/preferred_gossip_network.test.ts index 86d5ddb6f6b9..a3da5c55ff03 100644 --- a/yarn-project/end-to-end/src/p2p/preferred_gossip_network.test.ts +++ b/yarn-project/end-to-end/src/p2p/preferred_gossip_network.test.ts @@ -180,8 +180,6 @@ describe('e2e_p2p_preferred_network', () => { // Creates a 7-node topology (2 regular + 2 preferred + 2 validators + 1 no-discovery validator), // installs gossip monitors to verify no-discovery validators only receive traffic from preferred nodes, // submits txs from regular nodes, and asserts all txs mine with attestations from all validators. - // REFACTOR: peer-count polling loop in waitForNodeToAcquirePeers is hand-rolled; consider - // using t.waitForP2PMeshConnectivity with a peer-count predicate it('should rollup txs from all peers', async () => { // create the bootstrap node for the network if (!t.bootstrapNodeEnr) { @@ -365,10 +363,12 @@ describe('e2e_p2p_preferred_network', () => { // Send the required number of transactions to each node t.logger.info('Submitting transactions'); - for (const node of nodes) { - const txs = await submitTransactions(t.logger, node, NUM_TXS_PER_NODE, t.fundedAccount); - txsSentViaDifferentNodes.push(txs); - } + // Each submitTransactions call builds its own wallet/PXE, so submissions are independent and can run + // concurrently. Promise.all preserves node order, keeping txsSentViaDifferentNodes[i] aligned with nodes[i]. + const submitted = await Promise.all( + nodes.map(node => submitTransactions(t.logger, node, NUM_TXS_PER_NODE, t.fundedAccount)), + ); + txsSentViaDifferentNodes.push(...submitted); t.logger.info('Waiting for transactions to be mined'); // now ensure that all txs were successfully mined diff --git a/yarn-project/end-to-end/src/p2p/rediscovery.test.ts b/yarn-project/end-to-end/src/p2p/rediscovery.test.ts index 39f446176746..3b526dd479d0 100644 --- a/yarn-project/end-to-end/src/p2p/rediscovery.test.ts +++ b/yarn-project/end-to-end/src/p2p/rediscovery.test.ts @@ -58,8 +58,6 @@ describe('e2e_p2p_rediscovery', () => { // Forms an initial 4-node mesh, stops the bootstrap node, then restarts each validator from its data // directory without any bootstrap ENR. Submits txs to each restarted node and asserts they mine, // proving that discv5 peer-store entries are sufficient for re-discovery. - // REFACTOR: sequential sleep(2500) between node restarts is hand-rolled; the delay exists to avoid - // port conflicts but should be replaced with a port-readiness check or staggered createNode calls it('should re-discover stored peers without bootstrap node', async () => { const txsSentViaDifferentNodes: TxHash[][] = []; nodes = await createNodes( @@ -113,10 +111,12 @@ describe('e2e_p2p_rediscovery', () => { await t.waitForP2PMeshConnectivity(newNodes, NUM_VALIDATORS, 120); - for (const node of newNodes) { - const txs = await submitTransactions(t.logger, node, NUM_TXS_PER_NODE, t.fundedAccount); - txsSentViaDifferentNodes.push(txs); - } + // Each submitTransactions call builds its own wallet/PXE, so submissions are independent and can run + // concurrently. Promise.all preserves node order, keeping txsSentViaDifferentNodes[i] aligned with newNodes[i]. + const submitted = await Promise.all( + newNodes.map(node => submitTransactions(t.logger, node, NUM_TXS_PER_NODE, t.fundedAccount)), + ); + txsSentViaDifferentNodes.push(...submitted); // now ensure that all txs were successfully mined await Promise.all( diff --git a/yarn-project/end-to-end/src/shared/submit-transactions.ts b/yarn-project/end-to-end/src/shared/submit-transactions.ts index b8b6c5c1a11e..c6553188a5b9 100644 --- a/yarn-project/end-to-end/src/shared/submit-transactions.ts +++ b/yarn-project/end-to-end/src/shared/submit-transactions.ts @@ -1,9 +1,10 @@ import { AztecAddress } from '@aztec/aztec.js/addresses'; -import { NO_WAIT } from '@aztec/aztec.js/contracts'; -import { Fr, GrumpkinScalar } from '@aztec/aztec.js/fields'; +import { NO_WAIT, getContractInstanceFromInstantiationParams } from '@aztec/aztec.js/contracts'; +import { Fr } from '@aztec/aztec.js/fields'; import type { Logger } from '@aztec/aztec.js/log'; import { TxHash, type TxReceipt, TxStatus } from '@aztec/aztec.js/tx'; import { times } from '@aztec/foundation/collection'; +import { TestContract, TestContractArtifact } from '@aztec/noir-test-contracts.js/Test'; import type { TestWallet } from '../test-wallet/test_wallet.js'; @@ -14,12 +15,19 @@ export const submitTxsTo = async ( numTxs: number, logger: Logger, ): Promise => { + // Register (without deploying) a single TestContract instance to source cheap throwaway txs from. + // emit_nullifier is #[noinitcheck], so it runs on a register-only instance — this avoids a full + // account-contract deployment per tx, which is all these callers were paying for a mined/gossiped tx. + const testContractInstance = await getContractInstanceFromInstantiationParams(TestContractArtifact, { + salt: Fr.random(), + }); + await wallet.registerContract(testContractInstance, TestContractArtifact); + const contract = TestContract.at(testContractInstance.address, wallet); + const txHashes: TxHash[] = []; await Promise.all( times(numTxs, async () => { - const accountManager = await wallet.createSchnorrAccount(Fr.random(), Fr.random(), GrumpkinScalar.random()); - const deployMethod = await accountManager.getDeployMethod(); - const { txHash } = await deployMethod.send({ from: submitter, wait: NO_WAIT }); + const { txHash } = await contract.methods.emit_nullifier(Fr.random()).send({ from: submitter, wait: NO_WAIT }); logger.info(`Tx sent with hash ${txHash}`); const receipt: TxReceipt = await wallet.getTxReceipt(txHash); diff --git a/yarn-project/end-to-end/src/single-node/cross-chain/l1_to_l2.parallel.test.ts b/yarn-project/end-to-end/src/single-node/cross-chain/l1_to_l2.parallel.test.ts index 73ae303a2c83..d9c27d6be37c 100644 --- a/yarn-project/end-to-end/src/single-node/cross-chain/l1_to_l2.parallel.test.ts +++ b/yarn-project/end-to-end/src/single-node/cross-chain/l1_to_l2.parallel.test.ts @@ -134,9 +134,8 @@ describe('single-node/cross-chain/l1_to_l2', () => { } }; - // Waits until the message is fetched by the archiver of the node and returns the msg target checkpoint - // REFACTOR: hand-rolled retryUntil loop that also advances blocks on each retry; replace with a - // waitForL1ToL2MessageIndexed(node, msgHash, advanceBlock) helper in the e2e fixture or harness. + // Waits until the message is fetched by the archiver of the node and returns the msg target checkpoint. + // Advances a block on each retry because an L1->L2 message is only indexed once further L2 blocks build. const waitForMessageFetched = async (msgHash: Fr) => { log.warn(`Waiting until the message is fetched by the node`); return await retryUntil( diff --git a/yarn-project/end-to-end/src/single-node/fees/bridging_race.notest.ts b/yarn-project/end-to-end/src/single-node/fees/bridging_race.notest.ts index 9da3127852d6..c8c0ff7893de 100644 --- a/yarn-project/end-to-end/src/single-node/fees/bridging_race.notest.ts +++ b/yarn-project/end-to-end/src/single-node/fees/bridging_race.notest.ts @@ -54,6 +54,14 @@ describe('single-node/fees/bridging_race', () => { bobsAddress = bobsAccountManager.address; }); + // Sleeps until 500ms before the current L2 slot ends, so the subsequent bridge lands right at the slot + // boundary (this is what reproduces the "message not in state" race the test guards against). + const sleepUntilNearSlotEnd = async () => { + const sleepTime = (Number(t.monitor.checkpointTimestamp) + AZTEC_SLOT_DURATION) * 1000 - Date.now() - 500; + logger.info(`Sleeping for ${sleepTime}ms until near end of L2 slot before sending L1 fee juice to L2 inbox`); + await sleep(sleepTime); + }; + // Reproduces a timing race where an L1→L2 fee-juice bridge message lands just before the end of an // L2 slot, causing the archiver to miss it. The fix was to wait for the archiver to see the message // before waiting for the required two-block confirmation. The sleep injected into approve() simulates @@ -65,11 +73,7 @@ describe('single-node/fees/bridging_race', () => { const origApprove = l1TokenManager.approve.bind(l1TokenManager); l1TokenManager.approve = async (amount: bigint, address: Hex, addressName = '') => { await origApprove(amount, address, addressName); - const sleepTime = (Number(t.monitor.checkpointTimestamp) + AZTEC_SLOT_DURATION) * 1000 - Date.now() - 500; - logger.info(`Sleeping for ${sleepTime}ms until near end of L2 slot before sending L1 fee juice to L2 inbox`); - // REFACTOR: hand-rolled slot-boundary sleep; replace with a timing helper that derives the remaining - // slot time from the chain monitor's slot boundaries rather than computing it inline. - await sleep(sleepTime); + await sleepUntilNearSlotEnd(); }; // Waiting for the archiver to sync the message _before_ waiting for the mandatory 2 L2 blocks to pass fixed it diff --git a/yarn-project/end-to-end/src/single-node/fees/failures.test.ts b/yarn-project/end-to-end/src/single-node/fees/failures.test.ts index 4f44952b04b9..ef9e336ca787 100644 --- a/yarn-project/end-to-end/src/single-node/fees/failures.test.ts +++ b/yarn-project/end-to-end/src/single-node/fees/failures.test.ts @@ -97,10 +97,7 @@ describe('single-node/fees/failures', () => { await expectMapping(t.getGasBalanceFn, [aliceAddress, bananaFPC.address], [initialAliceGas, initialFPCGas]); // We wait until the proven chain is caught up so all previous fees are paid out. - // REFACTOR: manual advanceToNextEpoch + catchUpProvenChain sequence; replace with a single - // waitForEpochProven() helper on FeesTest that encapsulates this pattern. - await t.cheatCodes.rollup.advanceToNextEpoch(); - await t.catchUpProvenChain(); + await t.waitForEpochProven(); const currentSequencerRewards = await t.getCoinbaseSequencerRewards(); const provenCheckpointBefore = await t.rollupContract.getProvenCheckpointNumber(); diff --git a/yarn-project/end-to-end/src/single-node/fees/fee_settings.test.ts b/yarn-project/end-to-end/src/single-node/fees/fee_settings.test.ts index d2bb0c9411a6..333efc4067f3 100644 --- a/yarn-project/end-to-end/src/single-node/fees/fee_settings.test.ts +++ b/yarn-project/end-to-end/src/single-node/fees/fee_settings.test.ts @@ -1,4 +1,5 @@ import type { AztecAddress } from '@aztec/aztec.js/addresses'; +import type { Logger } from '@aztec/aztec.js/log'; import type { AztecNode } from '@aztec/aztec.js/node'; import { CheatCodes } from '@aztec/aztec/testing'; import { BlockNumber, CheckpointNumber } from '@aztec/foundation/branded-types'; @@ -17,6 +18,41 @@ import type { TestWallet } from '../../test-wallet/test_wallet.js'; import { proveInteraction } from '../../test-wallet/utils.js'; import { FeesTest } from './fees_test.js'; +/** + * Repeatedly bumps the L1 base fee, mines an L1 block, and rotates the gas-fee oracle until the node's + * min L2 fee (`feePerL2Gas`) reaches `minRiseTarget`, then returns that fee snapshot. The oracle rotation + * deadband (LIFETIME - LAG = 3 L2 slots between successful rotations, see FeeLib.sol) silently no-ops + * `updateL1GasFeeOracle` until the window opens, so the throw is swallowed and the loop retries. + */ +async function spikeL1BaseFeeUntilMinFee( + cheatCodes: CheatCodes, + aztecNode: AztecNode, + targetL1BaseFee: bigint, + minRiseTarget: bigint, + opts: { timeout?: number; interval?: number; logger?: Logger } = {}, +): Promise { + return await retryUntil( + async () => { + await cheatCodes.eth.setNextBlockBaseFeePerGas(targetL1BaseFee); + await cheatCodes.eth.mine(); + try { + await cheatCodes.rollup.updateL1GasFeeOracle(); + } catch { + // Rotation deadband closed — try again on the next iteration. + } + const after = await aztecNode.getCurrentMinFees(); + opts.logger?.info(`L2 min fees are now ${inspect(after)}`, { + minFeesAfter: after.toInspect(), + minRiseTarget: minRiseTarget.toString(), + }); + return after.feePerL2Gas >= minRiseTarget ? after : undefined; + }, + 'L2 min fee organic increase (L1 base fee bump) above reference', + opts.timeout ?? 90, + opts.interval ?? 1, + ); +} + // Fee oracle and wallet fee-padding behaviour under L1 base-fee spikes and governance fee-config bumps. // Uses FeesTest with a custom timing preset (ethSlot=4s, aztecSlot=12s, inboxLag=2, minTxsPerBlock=0, // aztecProofSubmissionEpochs=640, manaTarget=4M, walletMinFeePadding=30) and fake in-proc prover node. @@ -118,29 +154,9 @@ describe('single-node/fees/fee_settings', () => { const targetL1BaseFee = referenceDerivedL1BaseFee > 0n ? referenceDerivedL1BaseFee : 1n; t.logger.info(`Targeting L1 base fee ${targetL1BaseFee} (current ${currentL1BaseFee})`); - // REFACTOR: hand-rolled retryUntil loop that mines L1 blocks and rotates the oracle; replace with - // a helper on RollupCheatCodes that abstracts the L1-base-fee-spike + oracle-rotation retry. - return await retryUntil( - async () => { - await cheatCodes.eth.setNextBlockBaseFeePerGas(targetL1BaseFee); - await cheatCodes.eth.mine(); - try { - await cheatCodes.rollup.updateL1GasFeeOracle(); - } catch { - // Rotation deadband closed — try again on the next iteration. - } - const after = await aztecNode.getCurrentMinFees(); - t.logger.info(`L2 min fees are now ${inspect(after)}`, { - minFeesBefore: beforeAtCall.toInspect(), - minFeesAfter: after.toInspect(), - minRiseTarget: minRiseTarget.toString(), - }); - return after.feePerL2Gas >= minRiseTarget ? after : undefined; - }, - 'L2 min fee organic increase (L1 base fee bump) above reference', - 90, - 1, - ); + return await spikeL1BaseFeeUntilMinFee(cheatCodes, aztecNode, targetL1BaseFee, minRiseTarget, { + logger: t.logger, + }); }; // Pick a baseline from the post-checkpoint chain state. The prove step itself is diff --git a/yarn-project/end-to-end/src/single-node/fees/fees_test.ts b/yarn-project/end-to-end/src/single-node/fees/fees_test.ts index 4da5003cef30..12ecbe89c029 100644 --- a/yarn-project/end-to-end/src/single-node/fees/fees_test.ts +++ b/yarn-project/end-to-end/src/single-node/fees/fees_test.ts @@ -136,6 +136,12 @@ export class FeesTest extends SingleNodeTestContext { } } + /** Advances to the next epoch and waits for the proven chain to catch up, so all prior fees are paid out. */ + async waitForEpochProven() { + await this.cheatCodes.rollup.advanceToNextEpoch(); + await this.catchUpProvenChain(); + } + async getBlockRewards() { const blockReward = await this.rollupContract.getCheckpointReward(); const rewardConfig = await this.rollupContract.getRewardConfig(); diff --git a/yarn-project/end-to-end/src/single-node/fees/private_payments.parallel.test.ts b/yarn-project/end-to-end/src/single-node/fees/private_payments.parallel.test.ts index 7f530f728b5c..d5773e556ee9 100644 --- a/yarn-project/end-to-end/src/single-node/fees/private_payments.parallel.test.ts +++ b/yarn-project/end-to-end/src/single-node/fees/private_payments.parallel.test.ts @@ -45,8 +45,7 @@ describe('single-node/fees/private_payments', () => { ({ wallet, aliceAddress, bobAddress, sequencerAddress, bananaCoin, bananaFPC, gasSettings, aztecNode } = t); // Prove up until the current state by advancing the epoch and waiting for the prover node. - await t.cheatCodes.rollup.advanceToNextEpoch(); - await t.catchUpProvenChain(); + await t.waitForEpochProven(); }); afterAll(async () => { diff --git a/yarn-project/end-to-end/src/single-node/proving/long_proving_time.test.ts b/yarn-project/end-to-end/src/single-node/proving/long_proving_time.test.ts index 5254deb40cd5..7a50e9a8f006 100644 --- a/yarn-project/end-to-end/src/single-node/proving/long_proving_time.test.ts +++ b/yarn-project/end-to-end/src/single-node/proving/long_proving_time.test.ts @@ -60,6 +60,22 @@ describe('single-node/proving/long_proving_time', () => { await test.teardown(); }); + // Waits until the proven checkpoint reaches `target` while sampling the prover job queue on every + // tick and returning the peak parallelism observed over the whole proving window (the value the + // MAX_JOB_COUNT assertion depends on — a one-shot snapshot could not capture the peak). + const sampleMaxJobCountUntilProven = async (target: number) => { + let maxJobCount = 0; + while (monitor.provenCheckpointNumber === undefined || monitor.provenCheckpointNumber < target) { + const jobs = await test.proverNodes[0].getProverNode()!.getJobs(); + if (jobs.length > maxJobCount) { + maxJobCount = jobs.length; + logger.info(`Updated max job count to ${maxJobCount}`, jobs); + } + await sleep((L1_BLOCK_TIME_IN_S * 1000) / 2); + } + return maxJobCount; + }; + // Polls the prover node's job queue until provenCheckpointNumber reaches targetProvenEpochs. // Asserts that checkpointNumber advanced at least 3× the proven epoch count, confirming proving // lagged behind block production. Asserts maxJobCount stays within MAX_JOB_COUNT (20), confirming @@ -69,19 +85,7 @@ describe('single-node/proving/long_proving_time', () => { const targetProvenBlockNumber = targetProvenEpochs * test.epochDuration; logger.info(`Waiting for ${targetProvenEpochs} epochs to be proven at ${targetProvenBlockNumber} L2 blocks`); - // Wait until we hit the target proven block number, and keep an eye on how many proving jobs are run in parallel. - let maxJobCount = 0; - // REFACTOR: hand-rolled sleep loop polling provenCheckpointNumber; replace with - // test.waitUntilProvenCheckpointNumber(targetProvenBlockNumber, timeout) and check job count - // separately via a one-time snapshot rather than updating inside the loop. - while (monitor.provenCheckpointNumber === undefined || monitor.provenCheckpointNumber < targetProvenBlockNumber) { - const jobs = await test.proverNodes[0].getProverNode()!.getJobs(); - if (jobs.length > maxJobCount) { - maxJobCount = jobs.length; - logger.info(`Updated max job count to ${maxJobCount}`, jobs); - } - await sleep((L1_BLOCK_TIME_IN_S * 1000) / 2); - } + const maxJobCount = await sampleMaxJobCountUntilProven(targetProvenBlockNumber); // At least 3 epochs should have passed after the proven one (though we add a -1 just in case) expect(monitor.checkpointNumber).toBeGreaterThanOrEqual(targetProvenEpochs * test.epochDuration * 3 - 1); diff --git a/yarn-project/end-to-end/src/single-node/proving/optimistic.parallel.test.ts b/yarn-project/end-to-end/src/single-node/proving/optimistic.parallel.test.ts index 704acfdbb7ba..98b9cffe1485 100644 --- a/yarn-project/end-to-end/src/single-node/proving/optimistic.parallel.test.ts +++ b/yarn-project/end-to-end/src/single-node/proving/optimistic.parallel.test.ts @@ -112,8 +112,6 @@ describe('single-node/proving/optimistic', () => { /** epoch -> lowest checkpoint header slot of any CheckpointProver observed for that epoch. */ const lowestProvenSlotByEpoch = new Map(); let stopped = false; - // REFACTOR: hand-rolled setTimeout sampler loop with a `stopped` flag — a polling/observe helper - // (e.g. a sampler that records earliest-observed values per key until disposed) should replace it. const loop = (async () => { while (!stopped) { for (const prover of proverNode.getCheckpointStore().listAll()) { diff --git a/yarn-project/end-to-end/src/single-node/proving/proof_fails.parallel.test.ts b/yarn-project/end-to-end/src/single-node/proving/proof_fails.parallel.test.ts index bfe1b8c699d6..e1670002f7bf 100644 --- a/yarn-project/end-to-end/src/single-node/proving/proof_fails.parallel.test.ts +++ b/yarn-project/end-to-end/src/single-node/proving/proof_fails.parallel.test.ts @@ -7,7 +7,6 @@ import { ChainMonitor } from '@aztec/ethereum/test'; import type { ViemClient } from '@aztec/ethereum/types'; import { CheckpointNumber, EpochNumber } from '@aztec/foundation/branded-types'; import { promiseWithResolvers } from '@aztec/foundation/promise'; -import { retryUntil } from '@aztec/foundation/retry'; import { sleep } from '@aztec/foundation/sleep'; import type { TestProverNode } from '@aztec/prover-node/test'; import type { SequencerEvents } from '@aztec/sequencer-client'; @@ -106,14 +105,18 @@ describe('single-node/proving/proof_fails', () => { // timestamp gate moves with the warp), then releases, reverts past the deadline, and the // post-deadline propose triggers the prune in real time. await test.warpToEpochStart(2); - // REFACTOR: hand-rolled retryUntil polling rollup.getCheckpointNumber for rollback detection; - // a DSL helper like waitForRollback(checkpoint) would make the intent clearer. - await retryUntil( - async () => (await rollup.getCheckpointNumber()) < checkpointBeforeRollback, - 'rollup rolled back', - L2_SLOT_DURATION_IN_S * 4, - 0.2, - ); + + // Wait until the prune is processed and a new checkpoint mined. + const checkpointAfterRollback = await context.cheatCodes.rollup.waitForCheckpointBelow(checkpointBeforeRollback, { + timeout: L2_SLOT_DURATION_IN_S * 4, + interval: 0.2, + }); + + // The post-rollback chain tip should be in epoch 2, since the rollback-triggering propose + // was made during epoch 2, after the deadline. + expect(checkpointAfterRollback).toBeLessThan(checkpointBeforeRollback); + const latestCheckpoint = await rollup.getCheckpoint(checkpointAfterRollback); + expect(getEpochAtSlot(latestCheckpoint.slotNumber, test.constants)).toEqual(EpochNumber(2)); // The prover tx should have been rejected as it was submitted past the deadline const lastProverTxHash = proverDelayer.getSentTxHashes().at(-1); @@ -121,13 +124,6 @@ describe('single-node/proving/proof_fails', () => { const lastProverTxReceipt = await l1Client.getTransactionReceipt({ hash: lastProverTxHash! }); expect(lastProverTxReceipt.status).toEqual('reverted'); - // The post-rollback chain tip should be in epoch 2 (the rollback-triggering propose was made - // during epoch 2, after the deadline) - const checkpointAfterRollback = await rollup.getCheckpointNumber(); - expect(checkpointAfterRollback).toBeLessThan(checkpointBeforeRollback); - const latestCheckpoint = await rollup.getCheckpoint(checkpointAfterRollback); - expect(getEpochAtSlot(latestCheckpoint.slotNumber, test.constants)).toEqual(EpochNumber(2)); - logger.warn(`Test succeeded`); }); diff --git a/yarn-project/end-to-end/src/single-node/sequencer/gov_proposal.parallel.test.ts b/yarn-project/end-to-end/src/single-node/sequencer/gov_proposal.parallel.test.ts index 19b76439fa0b..07c5306c4deb 100644 --- a/yarn-project/end-to-end/src/single-node/sequencer/gov_proposal.parallel.test.ts +++ b/yarn-project/end-to-end/src/single-node/sequencer/gov_proposal.parallel.test.ts @@ -15,7 +15,6 @@ import { Fr } from '@aztec/foundation/curves/bn254'; import { TimeoutError } from '@aztec/foundation/error'; import { EthAddress } from '@aztec/foundation/eth-address'; import type { Logger } from '@aztec/foundation/log'; -import { retryUntil } from '@aztec/foundation/retry'; import { sleep } from '@aztec/foundation/sleep'; import { bufferToHex } from '@aztec/foundation/string'; import type { TestDateProvider } from '@aztec/foundation/timer'; @@ -242,15 +241,9 @@ describe('single-node/sequencer/gov_proposal', () => { // Check that the checkpoint number has indeed increased on L1 so sequencers cant pass the sync check. // Allow another slot for any in-flight L1 propose to mine, since the work loop above hits its wait timeout the // moment the tx misses L2 sync, not the moment the L1 tx lands. - // REFACTOR: retryUntil polling ChainMonitor should be replaced with a ChainMonitor.waitForCheckpoint helper - const checkpointAfterBlobDisable = await retryUntil( - async () => { - const snapshot = await monitor.run(); - return snapshot.checkpointNumber > lastCheckpointOnL1 ? snapshot : undefined; - }, - 'L1 checkpoint to advance after disabling blob client', - AZTEC_SLOT_DURATION + 5, - 1, + const checkpointAfterBlobDisable = await monitor.waitForCheckpoint( + event => event.checkpointNumber > lastCheckpointOnL1, + { timeout: (AZTEC_SLOT_DURATION + 5) * 1000, checkCurrentCheckpoint: true }, ); expect(checkpointAfterBlobDisable.checkpointNumber).toBeGreaterThan(lastCheckpointOnL1); logger.warn(`L1 checkpoint number has increased`, { diff --git a/yarn-project/end-to-end/src/single-node/sequencer/publisher_funding_multi.test.ts b/yarn-project/end-to-end/src/single-node/sequencer/publisher_funding_multi.test.ts index ee3ed2b6ede0..7bb271bea103 100644 --- a/yarn-project/end-to-end/src/single-node/sequencer/publisher_funding_multi.test.ts +++ b/yarn-project/end-to-end/src/single-node/sequencer/publisher_funding_multi.test.ts @@ -123,6 +123,27 @@ describe('single-node/sequencer/publisher_funding_multi', () => { await rm(keyStoreDirectory, { recursive: true, force: true }); }); + // Polls until every address in `accounts` has an L1 balance strictly above `threshold`. + const waitForBalancesAbove = (accounts: EthAddress[], threshold: bigint) => + retryUntil( + async () => { + const balances = await Promise.all(accounts.map(account => ethCheatCodes.getBalance(account))); + return balances.every(balance => balance > threshold) || undefined; + }, + `all balances above ${threshold}`, + 180, + 1, + ); + + // Polls until `funder`'s L1 spend since `before` reaches at least `amount`. + const waitForFunderSpend = (funder: EthAddress, before: bigint, amount: bigint) => + retryUntil( + async () => before - (await ethCheatCodes.getBalance(funder)) >= amount || undefined, + `funder to spend at least ${amount}`, + 180, + 1, + ); + // Sets both publisher L1 balances below the funding threshold via ethCheatCodes, drives the // PublisherManager's funding loop to top them both up (round 1), then drains one publisher again // and drives a second funding round to confirm the loop is still healthy. @@ -156,18 +177,7 @@ describe('single-node/sequencer/publisher_funding_multi', () => { // publishers were topped up. await fundingPromise!.trigger(); - // REFACTOR: hand-rolled poll waiting for PublisherManager funding cycle; a helper like - // waitForPublisherBalancesAbove(publisherManager, threshold) should replace this retryUntil. - await retryUntil( - async () => { - const balance1 = await ethCheatCodes.getBalance(publisher1Address); - const balance2 = await ethCheatCodes.getBalance(publisher2Address); - return balance1 > LOW_BALANCE && balance2 > LOW_BALANCE ? true : undefined; - }, - 'waiting for both publishers to be funded', - 180, - 1, - ); + await waitForBalancesAbove([publisher1Address, publisher2Address], LOW_BALANCE); const publisher1BalanceAfter = await ethCheatCodes.getBalance(publisher1Address); const publisher2BalanceAfter = await ethCheatCodes.getBalance(publisher2Address); @@ -197,17 +207,7 @@ describe('single-node/sequencer/publisher_funding_multi', () => { // Force a second funding cycle rather than waiting for the next 2-minute poll. await fundingPromise!.trigger(); - // REFACTOR: hand-rolled poll waiting for a second PublisherManager funding cycle; same helper - // as above should cover this site. - await retryUntil( - async () => { - const spent = funderBalanceBefore2 - (await ethCheatCodes.getBalance(funderAddress)); - return spent >= FUNDING_AMOUNT ? true : undefined; - }, - 'waiting for second funding round', - 180, - 1, - ); + await waitForFunderSpend(funderAddress, funderBalanceBefore2, FUNDING_AMOUNT); const funderSpent2 = funderBalanceBefore2 - (await ethCheatCodes.getBalance(funderAddress)); logger.info(`Second funding round: funder spent ${funderSpent2} (expected ~${FUNDING_AMOUNT})`); diff --git a/yarn-project/end-to-end/src/single-node/sync/snapshot_sync.test.ts b/yarn-project/end-to-end/src/single-node/sync/snapshot_sync.test.ts index 1296d0c06bb8..5a2ba3a376a3 100644 --- a/yarn-project/end-to-end/src/single-node/sync/snapshot_sync.test.ts +++ b/yarn-project/end-to-end/src/single-node/sync/snapshot_sync.test.ts @@ -75,6 +75,9 @@ describe('e2e_snapshot_sync', () => { ); }; + const waitForSnapshotFiles = (dir: string) => + retryUntil(() => readdir(dir).then(files => files.length > 0), 'snapshot-created', 90, 1); + const expectNodeSyncedToL2Block = async (node: AztecNode, blockNumber: number) => { const tips = await node.getChainTips(); expect(tips.proposed.number).toBeGreaterThanOrEqual(blockNumber); @@ -86,9 +89,7 @@ describe('e2e_snapshot_sync', () => { // enough chain history for the subsequent snapshot tests. it('waits until a few checkpoints have been mined', async () => { log.warn(`Waiting for checkpoints to be mined`); - // REFACTOR: hand-rolled poll on ChainMonitor.checkpointNumber; EpochsTestContext.waitUntilCheckpointNumber - // or a shared helper should replace this retryUntil. - await retryUntil(() => monitor.checkpointNumber > TARGET_CHECKPOINT_NUMBER, 'checkpoints-mined', 90, 1); + await monitor.waitUntilCheckpoint(CheckpointNumber(TARGET_CHECKPOINT_NUMBER + 1)); log.warn(`Checkpoint height is now ${monitor.checkpointNumber}.`); }); @@ -97,9 +98,7 @@ describe('e2e_snapshot_sync', () => { it('creates a snapshot', async () => { log.warn(`Creating snapshot`); await context.aztecNodeAdmin.startSnapshotUpload(snapshotLocation); - // REFACTOR: hand-rolled poll waiting for snapshot files to appear; a helper like - // waitForSnapshotUpload(adminNode, snapshotDir) should replace this. - await retryUntil(() => readdir(snapshotDir).then(files => files.length > 0), 'snapshot-created', 90, 1); + await waitForSnapshotFiles(snapshotDir); log.warn(`Snapshot created`); }); diff --git a/yarn-project/end-to-end/src/spartan/n_tps.test.ts b/yarn-project/end-to-end/src/spartan/n_tps.test.ts index 13d2cd7dabe0..33bee9d5a677 100644 --- a/yarn-project/end-to-end/src/spartan/n_tps.test.ts +++ b/yarn-project/end-to-end/src/spartan/n_tps.test.ts @@ -214,14 +214,25 @@ describe('sustained N TPS test', () => { walletCount: testWallets?.length ?? 0, endpointCount: endpoints?.length ?? 0, }); - for (const { cleanup } of testWallets!) { - await cleanup(); + // Teardown must not fail the suite: the benchmark result is already captured + // by this point, so a cleanup error (dead PXE, missing chaos-mesh CRDs, etc.) + // should be logged, not thrown — otherwise it turns a successful run red. + try { + for (const { cleanup } of testWallets ?? []) { + await cleanup(); + } + } catch (err) { + logger.warn(`Failed to clean up wallets: ${err}`, { err }); } - endpoints.forEach(e => e.process?.kill()); + endpoints?.forEach(e => e.process?.kill()); promProcess?.process?.kill(); - await uninstallChaosMesh(CHAOS_MESH_NAME, config.NAMESPACE, logger); + try { + await uninstallChaosMesh(CHAOS_MESH_NAME, config.NAMESPACE, logger); + } catch (err) { + logger.warn(`Failed to uninstall Chaos Mesh: ${err}`, { err }); + } }); beforeAll(async () => { @@ -669,6 +680,15 @@ describe('sustained N TPS test', () => { await metrics.recordMinedTx(receipt); results.push({ success: true, txHash }); } catch (error) { + // Once a tx has been observed in a block we count it as included, even if + // waitForTx then threw because a reorg dropped it back to pending or the + // pool evicted it. Inclusion is a first-sighting event here; we don't care + // what happens to the tx afterwards. + if (metrics.wasMined(txHash)) { + logger.info(`${txName} was mined (ignoring post-inclusion reorg/drop)`, { txName, txHash }); + results.push({ success: true, txHash }); + return; + } const receipt = await aztecNode.getTxReceipt(TxHash.fromString(txHash)).catch(() => undefined); logger.error(`${txName} was not included`, { txName, @@ -726,13 +746,21 @@ describe('sustained N TPS test', () => { logger.info(`Transaction inclusion summary: ${successCount} succeeded, ${failureCount} failed`); logger.info('Inclusion time stats', inclusionStats); + // A total submission failure (nothing sent when load was requested) is still + // a hard error — it means the run is broken, not just degraded. if (totalHighValueSent === 0 && highValueTps > 0) { throw new Error('No high-value txs were sent; check earlier submission errors'); } - if (successCount !== totalHighValueSent) { - const message = `Only ${successCount}/${totalHighValueSent} high-value txs were included; ${failureCount} failed`; - throw new Error(message); - } + // Otherwise record mined-vs-failed as a metric rather than asserting strict + // 1:1 inclusion. A degraded point (e.g. a TPS target the network can't fully + // include) should report its numbers, not fail the run — the inclusion + // success ratio is itself the headline result we want to track over time. + metrics.recordInclusionOutcome(successCount, failureCount); + logger.info('Recorded inclusion outcome', { + mined: successCount, + failed: failureCount, + sent: totalHighValueSent, + }); }); }); diff --git a/yarn-project/end-to-end/src/spartan/tx_metrics.ts b/yarn-project/end-to-end/src/spartan/tx_metrics.ts index bac38184aac7..d60cc90f128e 100644 --- a/yarn-project/end-to-end/src/spartan/tx_metrics.ts +++ b/yarn-project/end-to-end/src/spartan/tx_metrics.ts @@ -161,6 +161,7 @@ export class TxInclusionMetrics { private mempoolMinedDelay: | { txP50: number; txP95: number; attestationP50: number; attestationP95: number } | undefined; + private inclusionOutcome: { mined: number; failed: number } | undefined; constructor( private aztecNode: AztecNode, @@ -249,6 +250,16 @@ export class TxInclusionMetrics { } } + /** + * Whether this tx was ever observed in a block (by the block-watcher or a mined receipt). + * Idempotent first-sighting semantics: a later reorg / pool eviction never clears it, so callers + * can treat "ever mined" as included regardless of what happens to the tx afterwards. + */ + public wasMined(txHash: string): boolean { + const d = this.data.get(txHash); + return !!d && d.minedAtMs !== -1; + } + /** Per-tx inclusion records for a group. Used to serialise out for downstream tooling. */ getInclusionRecords(group?: string): TxInclusionData[] { const out: TxInclusionData[] = []; @@ -342,6 +353,11 @@ export class TxInclusionMetrics { this.mempoolMinedDelay = { txP50, txP95, attestationP50, attestationP95 }; } + /** Mined vs failed counts for the high-value lane — recorded instead of asserting strict 1:1 inclusion. */ + public recordInclusionOutcome(mined: number, failed: number): void { + this.inclusionOutcome = { mined, failed }; + } + toGithubActionBenchmarkJSON(): Array<{ name: string; unit: string; value: number; range?: number; extra?: string }> { const data: Array<{ name: string; unit: string; value: number; range?: number; extra?: string }> = []; for (const group of this.groups) { @@ -423,6 +439,16 @@ export class TxInclusionMetrics { ); } + if (this.inclusionOutcome) { + const { mined, failed } = this.inclusionOutcome; + const total = mined + failed; + data.push( + { name: 'inclusion/mined_count', unit: 'count', value: mined }, + { name: 'inclusion/failed_count', unit: 'count', value: failed }, + { name: 'inclusion/success_ratio', unit: 'ratio', value: total > 0 ? mined / total : 0 }, + ); + } + const scenario = process.env.BENCH_SCENARIO?.trim(); if (!scenario) { return data; diff --git a/yarn-project/ethereum/src/test/chain_monitor.ts b/yarn-project/ethereum/src/test/chain_monitor.ts index b36f697f09fe..c73e49f85211 100644 --- a/yarn-project/ethereum/src/test/chain_monitor.ts +++ b/yarn-project/ethereum/src/test/chain_monitor.ts @@ -36,9 +36,20 @@ export type ChainMonitorEventMap = { 'l2-fees': [L2FeeData]; }; +/** Options for tuning what the {@link ChainMonitor} polls on each new L1 block. */ +export type ChainMonitorOptions = { + /** + * Whether to fetch L2 fee/oracle data (5 extra rollup reads per new L1 block) and emit `l2-fees`. + * Defaults to `true`. Set to `false` for tests that only care about slot/checkpoint/proven state to + * avoid the extra round-trips. + */ + includeFeeData?: boolean; +}; + /** Utility class that polls the chain on quick intervals and logs new L1 blocks, L2 blocks, and L2 proofs. */ export class ChainMonitor extends EventEmitter { private readonly l1Client: ViemClient; + private readonly includeFeeData: boolean; private inbox: InboxContract | undefined; private handle: NodeJS.Timeout | undefined; // eslint-disable-next-line aztec-custom/no-non-primitive-in-collections @@ -68,9 +79,11 @@ export class ChainMonitor extends EventEmitter { private readonly dateProvider: DateProvider = new DateProvider(), private readonly logger = createLogger('aztecjs:utils:chain_monitor'), private readonly intervalMs = 200, + options: ChainMonitorOptions = {}, ) { super(); this.l1Client = rollup.client; + this.includeFeeData = options.includeFeeData ?? true; } start() { @@ -183,11 +196,13 @@ export class ChainMonitor extends EventEmitter { this.emit('l2-slot', { l2SlotNumber, timestamp }); } - const feeData = await this.fetchFeeData(timestamp); - if (this.hasFeeDataChanged(feeData)) { - msg += ` with L2 min fee ${feeData.minFeePerMana}`; - this.l2FeeData = feeData; - this.emit('l2-fees', feeData); + if (this.includeFeeData) { + const feeData = await this.fetchFeeData(timestamp); + if (this.hasFeeDataChanged(feeData)) { + msg += ` with L2 min fee ${feeData.minFeePerMana}`; + this.l2FeeData = feeData; + this.emit('l2-fees', feeData); + } } this.logger.info(msg, { @@ -278,11 +293,32 @@ export class ChainMonitor extends EventEmitter { * {@link waitUntilCheckpoint} (which waits for a target number), this lets callers wait for an * arbitrary checkpoint property (e.g. one published in the first half of its slot). Rejects after * `opts.timeout` ms if provided; otherwise waits indefinitely. + * + * By default this is purely event-driven and only resolves on the *next* matching checkpoint that + * arrives after the call. Set `checkCurrentCheckpoint` to also test the current checkpoint first (via + * a fresh {@link run} snapshot) and short-circuit if it already satisfies `match`. Use it only for + * latching state predicates (e.g. "checkpoint number has passed N"), where an already-satisfied + * result is valid and you want to avoid missing an advance that landed before the listener attached. + * Do NOT set it when the predicate depends on observing the checkpoint live (e.g. one published + * mid-slot that the caller then times against wall-clock), since it may return a checkpoint whose + * slot has already elapsed. */ - public waitForCheckpoint( + public async waitForCheckpoint( match: (event: ChainMonitorEventMap['checkpoint'][0]) => boolean, - opts: { timeout?: number } = {}, + opts: { timeout?: number; checkCurrentCheckpoint?: boolean } = {}, ): Promise { + if (opts.checkCurrentCheckpoint) { + await this.run(); + const current: ChainMonitorEventMap['checkpoint'][0] = { + checkpointNumber: this.checkpointNumber, + l1BlockNumber: this.l1BlockNumber, + l2SlotNumber: this.l2SlotNumber, + timestamp: this.checkpointTimestamp, + }; + if (match(current)) { + return current; + } + } return new Promise((resolve, reject) => { let timer: NodeJS.Timeout | undefined; const listener = (event: ChainMonitorEventMap['checkpoint'][0]) => { diff --git a/yarn-project/ethereum/src/test/rollup_cheat_codes.ts b/yarn-project/ethereum/src/test/rollup_cheat_codes.ts index ac5d2f33e048..9aa17c44994d 100644 --- a/yarn-project/ethereum/src/test/rollup_cheat_codes.ts +++ b/yarn-project/ethereum/src/test/rollup_cheat_codes.ts @@ -271,6 +271,30 @@ export class RollupCheatCodes { ); } + /** + * Polls the rollup until its pending checkpoint settles below `checkpoint` on a freshly mined, non-zero + * checkpoint, and returns that new pending checkpoint number. Reads the L1 rollup contract directly + * rather than a node, since a rollback lands on L1 first. + * + * A prune can momentarily drop the pending checkpoint to 0 before the post-deadline propose mines its + * replacement, so a caller detecting a rollback wants the new lower checkpoint, not that transient + * empty state — hence the non-zero guard. + */ + public async waitForCheckpointBelow( + checkpoint: CheckpointNumber, + opts: { timeout?: number; interval?: number } = {}, + ): Promise { + return await retryUntil( + async () => { + const { pending } = await this.getTips(); + return pending > 0 && pending < checkpoint ? pending : undefined; + }, + `rollup checkpoint in (0, ${checkpoint})`, + opts.timeout ?? 60, + opts.interval ?? 1, + ); + } + /** * Overrides the inProgress field of the Inbox contract state * @param howMuch - How many checkpoints to move it forward diff --git a/yarn-project/p2p/src/mem_pools/instrumentation.ts b/yarn-project/p2p/src/mem_pools/instrumentation.ts index 57acd5d57f76..df5cebd5ec27 100644 --- a/yarn-project/p2p/src/mem_pools/instrumentation.ts +++ b/yarn-project/p2p/src/mem_pools/instrumentation.ts @@ -1,5 +1,4 @@ import type { Gossipable } from '@aztec/stdlib/p2p'; -import type { Tx } from '@aztec/stdlib/tx'; import { Attributes, type BatchObservableResult, @@ -117,16 +116,6 @@ export class PoolInstrumentation { this.addObjectCounter.add(count); } - public transactionsAdded(transactions: Tx[]) { - transactions.forEach(tx => this.trackMempoolItemAdded(tx.txHash.toBigInt())); - } - - public transactionsRemoved(hashes: Iterable | Iterable) { - for (const hash of hashes) { - this.trackMempoolItemRemoved(BigInt(hash)); - } - } - public trackMempoolItemAdded(key: bigint | string): void { this.mempoolItemAddedTimestamp.set(key, Date.now()); } @@ -142,6 +131,19 @@ export class PoolInstrumentation { } } + /** + * Records a pre-computed pending-to-mined delay directly, bypassing the + * `mempoolItemAddedTimestamp` map. Used by the tx pool, which derives the + * delay from the persisted `receivedAt` on tx metadata at the mined + * transition — more accurate than the add/remove map (which also fires on + * eviction) and resilient to the caller not having tracked the add. + */ + public recordMinedDelay(delayMs: number): void { + if (delayMs > 0) { + this.minedDelay.record(delayMs); + } + } + private observeStats = async (observer: BatchObservableResult) => { const { itemCount } = await this.poolStats(); if (typeof itemCount === 'number') { diff --git a/yarn-project/p2p/src/mem_pools/tx_pool_v2/tx_pool_v2.test.ts b/yarn-project/p2p/src/mem_pools/tx_pool_v2/tx_pool_v2.test.ts index 1c9c8a59ef0b..1a9f2d5e8182 100644 --- a/yarn-project/p2p/src/mem_pools/tx_pool_v2/tx_pool_v2.test.ts +++ b/yarn-project/p2p/src/mem_pools/tx_pool_v2/tx_pool_v2.test.ts @@ -8,7 +8,8 @@ import { import { BlockNumber, CheckpointNumber, IndexWithinCheckpoint, SlotNumber } from '@aztec/foundation/branded-types'; import { timesAsync } from '@aztec/foundation/collection'; import { Fr } from '@aztec/foundation/curves/bn254'; -import { DateProvider } from '@aztec/foundation/timer'; +import { createLogger } from '@aztec/foundation/log'; +import { DateProvider, ManualDateProvider } from '@aztec/foundation/timer'; import type { AztecAsyncMap } from '@aztec/kv-store'; import { openTmpStore } from '@aztec/kv-store/lmdb-v2'; import { RevertCode } from '@aztec/stdlib/avm'; @@ -24,6 +25,7 @@ import { PublicDataTreeLeafPreimage, } from '@aztec/stdlib/trees'; import { BlockHeader, GlobalVariables, Tx, TxEffect, TxHash, type TxValidator } from '@aztec/stdlib/tx'; +import { getTelemetryClient } from '@aztec/telemetry-client'; import { type MockProxy, mock } from 'jest-mock-extended'; @@ -32,6 +34,7 @@ import { GasLimitsValidator, MaxFeePerGasValidator } from '../../msg_validators/ import { AllowedSetupCallsMetaValidator } from '../../msg_validators/tx_validator/phases_validator.js'; import type { TxMetaData } from './tx_metadata.js'; import { AztecKVTxPoolV2 } from './tx_pool_v2.js'; +import { type MinedTxInfo, TxPoolV2Impl } from './tx_pool_v2_impl.js'; // Tx type alias for cleaner type annotations type MockTx = Awaited>; @@ -1545,6 +1548,80 @@ describe('TxPoolV2', () => { expectNoCallbacks(); }); + describe('pending-to-mined delay', () => { + // The wrapper feeds onTxsMined's delays into MEMPOOL_TX_MINED_DELAY. We construct the impl + // directly with a spy callback + controllable clock so we can assert the emitted delay, which + // is the behaviour the histogram records. + const makeImpl = async (onTxsMined: (m: MinedTxInfo[]) => void, dateProvider: DateProvider) => { + const implStore = await openTmpStore('impl-p2p'); + const implArchive = await openTmpStore('impl-archive'); + const impl = new TxPoolV2Impl( + implStore, + implArchive, + { + l2BlockSource: mockL2BlockSource, + worldStateSynchronizer: mockWorldState, + createTxValidator: () => Promise.resolve(alwaysValidValidator), + checkAllowedSetupCalls: () => Promise.resolve(true), + blockMinFeesProvider: { getCurrentMinFees: () => Promise.resolve(GasFees.empty()) }, + }, + { onTxsAdded: () => {}, onTxsRemoved: () => {}, onTxsMined }, + getTelemetryClient(), + {}, + dateProvider, + createLogger('test:tx-pool-mined-delay'), + ); + const cleanup = async () => { + await implStore.delete(); + await implArchive.delete(); + }; + return { impl, cleanup }; + }; + + it('reports now - receivedAt for a tx that was pending in the pool', async () => { + const minedCalls: MinedTxInfo[][] = []; + const dateProvider = new ManualDateProvider(); + const { impl, cleanup } = await makeImpl(m => minedCalls.push(m), dateProvider); + try { + const tx = await mockTx(1); + await impl.addPendingTxs([tx], {}); // receivedAt stamped at "now" + dateProvider.advanceTime(5); // 5s in the pool before it's mined + + await impl.handleMinedBlock(makeBlock([tx], slot1Header)); + + expect(minedCalls).toHaveLength(1); + const minedTxs = minedCalls[0]; + expect(minedTxs).toHaveLength(1); + expect(minedTxs[0].txHash).toBe(hashOf(tx)); + // Frozen clock: the delay is exactly the 5s advance, with no real-time drift. + expect(minedTxs[0].minedDelayMs).toBe(5000); + } finally { + await cleanup(); + } + }); + + it('leaves the delay undefined when receivedAt is unknown (hydrated/restart tx)', async () => { + const minedCalls: MinedTxInfo[][] = []; + const dateProvider = new ManualDateProvider(); + const { impl, cleanup } = await makeImpl(m => minedCalls.push(m), dateProvider); + try { + const tx = await mockTx(1); + await impl.addPendingTxs([tx], {}); + // Simulate a tx whose receive time was lost (e.g. rebuilt from the DB on restart). + impl.getPoolReadAccess().getMetadata(hashOf(tx))!.receivedAt = 0; + + await impl.handleMinedBlock(makeBlock([tx], slot1Header)); + + expect(minedCalls).toHaveLength(1); + const minedTxs = minedCalls[0]; + expect(minedTxs[0].txHash).toBe(hashOf(tx)); + expect(minedTxs[0].minedDelayMs).toBeUndefined(); + } finally { + await cleanup(); + } + }); + }); + it('deletes pending transactions with conflicting nullifiers', async () => { // Create two transactions with the same nullifier const txLow = await mockPublicTx(1, 5); diff --git a/yarn-project/p2p/src/mem_pools/tx_pool_v2/tx_pool_v2.ts b/yarn-project/p2p/src/mem_pools/tx_pool_v2/tx_pool_v2.ts index 2b9b3c2e5c86..b7094ec40b0f 100644 --- a/yarn-project/p2p/src/mem_pools/tx_pool_v2/tx_pool_v2.ts +++ b/yarn-project/p2p/src/mem_pools/tx_pool_v2/tx_pool_v2.ts @@ -20,6 +20,7 @@ import type { TxPoolV2Events, } from './interfaces.js'; import type { TxState } from './tx_metadata.js'; +import type { MinedTxInfo } from './tx_pool_v2_impl.js'; import { TxPoolV2Impl } from './tx_pool_v2_impl.js'; /** @@ -56,17 +57,22 @@ export class AztecKVTxPoolV2 extends (EventEmitter as new () => TypedEventEmitte // Create callbacks that the impl uses to notify us about events and metrics const callbacks = { onTxsAdded: (txs: Tx[], opts: { source?: string }) => { - this.#metrics?.transactionsAdded(txs); this.emit('txs-added', { txs, ...opts }); }, onTxsRemoved: (txHashes: string[] | bigint[]) => { - this.#metrics?.transactionsRemoved(txHashes); // Convert to TxHash objects for the event const hashes = txHashes.map(h => (typeof h === 'string' ? TxHash.fromString(h) : TxHash.fromBigInt(h))); this.emit('txs-removed', { txHashes: hashes }); }, - onTxsMined: (txHashes: string[]) => { - this.#metrics?.transactionsRemoved(txHashes); + onTxsMined: (minedTxs: MinedTxInfo[]) => { + // Pending-to-mined delay is derived from the tx's persisted receivedAt at the mined + // transition (see TxPoolV2Impl.handleMinedBlock), not the add/remove timestamp map — + // so eviction no longer pollutes MEMPOOL_TX_MINED_DELAY. + for (const { minedDelayMs } of minedTxs) { + if (minedDelayMs !== undefined) { + this.#metrics?.recordMinedDelay(minedDelayMs); + } + } }, }; diff --git a/yarn-project/p2p/src/mem_pools/tx_pool_v2/tx_pool_v2_impl.ts b/yarn-project/p2p/src/mem_pools/tx_pool_v2/tx_pool_v2_impl.ts index eb631d12f015..bdc7e3f196a6 100644 --- a/yarn-project/p2p/src/mem_pools/tx_pool_v2/tx_pool_v2_impl.ts +++ b/yarn-project/p2p/src/mem_pools/tx_pool_v2/tx_pool_v2_impl.ts @@ -51,10 +51,18 @@ const FINALIZE_BLOCK_CHUNK_SIZE = 100; /** * Callbacks for the implementation to notify the outer class about events and metrics. */ +/** A tx that has just transitioned to mined, with the time it spent in the pool. */ +export interface MinedTxInfo { + txHash: string; + /** Wall-clock ms from receipt into the pool to being marked mined. Undefined when the + * receive time is unknown (e.g. a tx hydrated from the DB on restart, receivedAt === 0). */ + minedDelayMs?: number; +} + export interface TxPoolV2Callbacks { onTxsAdded: (txs: Tx[], opts: { source?: string }) => void; onTxsRemoved: (txHashes: string[] | bigint[]) => void; - onTxsMined: (txHashes: string[]) => void; + onTxsMined: (minedTxs: MinedTxInfo[]) => void; } /** @@ -560,7 +568,15 @@ export class TxPoolV2Impl { }); if (found.length > 0) { - this.#callbacks.onTxsMined(found.map(m => m.txHash)); + // receivedAt is 0 for txs hydrated from the DB on restart (true receive time lost) — leave + // their delay undefined so the metric isn't polluted by epoch-sized values. + const now = this.#dateProvider.now(); + this.#callbacks.onTxsMined( + found.map(m => ({ + txHash: m.txHash, + minedDelayMs: m.receivedAt > 0 ? now - m.receivedAt : undefined, + })), + ); } this.#log.info(`Marked ${found.length} txs as mined in block ${blockId.number}`); diff --git a/yarn-project/sequencer-client/src/global_variable_builder/fee_predictor.test.ts b/yarn-project/sequencer-client/src/global_variable_builder/fee_predictor.test.ts index 72624b4b0ff1..5c2139fa7b64 100644 --- a/yarn-project/sequencer-client/src/global_variable_builder/fee_predictor.test.ts +++ b/yarn-project/sequencer-client/src/global_variable_builder/fee_predictor.test.ts @@ -9,9 +9,11 @@ import { CheckpointNumber } from '@aztec/foundation/branded-types'; import { Fr } from '@aztec/foundation/curves/bn254'; import { EthAddress } from '@aztec/foundation/eth-address'; import { createLogger } from '@aztec/foundation/log'; +import { promiseWithResolvers } from '@aztec/foundation/promise'; import { DateProvider } from '@aztec/foundation/timer'; import { FEE_ORACLE_LAG, type GasFees, ManaUsageEstimate, computeExcessMana } from '@aztec/stdlib/gas'; +import { jest } from '@jest/globals'; import { foundry } from 'viem/chains'; import { FeePredictor } from './fee_predictor.js'; @@ -352,3 +354,65 @@ describe('FeePredictor', () => { } }, 60_000); }); + +describe('FeePredictor state caching', () => { + it('recovers from a transient L1 read failure without waiting for a new L1 block', async () => { + const blockNumber = 1n; + const getBlockNumber = jest.fn<() => Promise>(() => Promise.resolve(blockNumber)); + const state = { manaTarget: 1n } as unknown; + const fetchState = jest + .fn<() => Promise>() + .mockRejectedValueOnce(new Error('L1 RPC request failed')) + .mockResolvedValue(state); + + const predictor: FeePredictor = Object.create(FeePredictor.prototype); + Reflect.set(predictor, 'publicClient', { getBlockNumber }); + Reflect.set(predictor, 'cachedL1BlockNumber', undefined); + Reflect.set(predictor, 'cachedState', undefined); + Reflect.set(predictor, 'fetchState', fetchState); + + const getState = Reflect.get(FeePredictor.prototype, 'getState') as () => Promise; + + await expect(getState.call(predictor)).rejects.toThrow('L1 RPC request failed'); + // Same L1 block: must recompute rather than replay the cached rejection. + await expect(getState.call(predictor)).resolves.toBe(state); + expect(fetchState).toHaveBeenCalledTimes(2); + }); + + it('does not clear the block marker when a stale fetch for an older block rejects', async () => { + const blockN = 1n; + const blockNext = 2n; + const getBlockNumber = jest + .fn<() => Promise>() + .mockResolvedValueOnce(blockN) + .mockResolvedValueOnce(blockNext); + + const fetchN = promiseWithResolvers(); + const state = { manaTarget: 1n } as unknown; + const fetchState = jest + .fn<() => Promise>() + .mockImplementationOnce(() => fetchN.promise) + .mockResolvedValue(state); + + const predictor: FeePredictor = Object.create(FeePredictor.prototype); + Reflect.set(predictor, 'publicClient', { getBlockNumber }); + Reflect.set(predictor, 'cachedL1BlockNumber', undefined); + Reflect.set(predictor, 'cachedState', undefined); + Reflect.set(predictor, 'fetchState', fetchState); + + const getState = Reflect.get(FeePredictor.prototype, 'getState') as () => Promise; + + // Fetch for block N stays in flight; the block N+1 call advances the marker meanwhile. + const callN = getState.call(predictor); + const callNext = getState.call(predictor); + + // The stale N fetch now rejects. It must NOT clear the marker (which now points at N+1). + fetchN.reject(new Error('stale L1 RPC request failed')); + + await expect(callN).rejects.toThrow('stale L1 RPC request failed'); + await expect(callNext).resolves.toBe(state); + + expect(Reflect.get(predictor, 'cachedL1BlockNumber')).toBe(blockNext); + expect(fetchState).toHaveBeenCalledTimes(2); + }); +}); diff --git a/yarn-project/sequencer-client/src/global_variable_builder/fee_predictor.ts b/yarn-project/sequencer-client/src/global_variable_builder/fee_predictor.ts index 7e51eeeca31f..da4f57f91c91 100644 --- a/yarn-project/sequencer-client/src/global_variable_builder/fee_predictor.ts +++ b/yarn-project/sequencer-client/src/global_variable_builder/fee_predictor.ts @@ -61,7 +61,17 @@ export class FeePredictor { const blockNumber = await this.publicClient.getBlockNumber({ cacheTime: 0 }); if (this.cachedL1BlockNumber === undefined || blockNumber > this.cachedL1BlockNumber) { this.cachedL1BlockNumber = blockNumber; - this.cachedState = this.fetchState(blockNumber); + // Reset the cached block number on failure so a transient L1 RPC error does not leave a + // rejected promise cached for this block, which would replay the same rejection on every + // subsequent call until the next L1 block arrives. Only clear it if it still points at the + // block this attempt was for, so a stale rejection from an older block cannot wipe a marker + // a newer call already advanced (which would also defeat the monotonic block-number guard). + this.cachedState = this.fetchState(blockNumber).catch(err => { + if (this.cachedL1BlockNumber === blockNumber) { + this.cachedL1BlockNumber = undefined; + } + throw err; + }); } return this.cachedState!; } diff --git a/yarn-project/sequencer-client/src/global_variable_builder/fee_provider.test.ts b/yarn-project/sequencer-client/src/global_variable_builder/fee_provider.test.ts index 784d5f2e35f4..ec64d472183d 100644 --- a/yarn-project/sequencer-client/src/global_variable_builder/fee_provider.test.ts +++ b/yarn-project/sequencer-client/src/global_variable_builder/fee_provider.test.ts @@ -1,3 +1,4 @@ +import { promiseWithResolvers } from '@aztec/foundation/promise'; import { GasFees, ManaUsageEstimate } from '@aztec/stdlib/gas'; import { jest } from '@jest/globals'; @@ -41,4 +42,62 @@ describe('FeeProviderImpl', () => { expect(getPredictedMinFees).toHaveBeenCalledWith(ManaUsageEstimate.Target); }); + + it('recovers from a transient L1 read failure without waiting for a new L1 block', async () => { + const blockNumber = 1n; + const getBlockNumber = jest.fn<() => Promise>(() => Promise.resolve(blockNumber)); + const computeCurrentMinFees = jest + .fn<() => Promise>() + .mockRejectedValueOnce(new Error('L1 RPC request failed')) + .mockResolvedValue(new GasFees(0, 42)); + + const provider: FeeProviderImpl = Object.create(FeeProviderImpl.prototype); + Reflect.set(provider, 'publicClient', { getBlockNumber }); + Reflect.set(provider, 'currentL1BlockNumber', undefined); + Reflect.set(provider, 'currentMinFees', Promise.resolve(new GasFees(0, 0))); + Reflect.set(provider, 'computeCurrentMinFees', computeCurrentMinFees); + + // First call fails on the transient L1 read. + await expect(provider.getCurrentMinFees()).rejects.toThrow('L1 RPC request failed'); + + // A subsequent call at the SAME L1 block must recompute rather than replay the cached rejection. + await expect(provider.getCurrentMinFees()).resolves.toEqual(new GasFees(0, 42)); + expect(computeCurrentMinFees).toHaveBeenCalledTimes(2); + }); + + it('does not clear the block marker when a stale computation for an older block rejects', async () => { + const blockN = 1n; + const blockNext = 2n; + const getBlockNumber = jest + .fn<() => Promise>() + .mockResolvedValueOnce(blockN) + .mockResolvedValueOnce(blockNext); + + const computeN = promiseWithResolvers(); + const computeCurrentMinFees = jest + .fn<() => Promise>() + .mockImplementationOnce(() => computeN.promise) + .mockResolvedValue(new GasFees(0, 42)); + + const provider: FeeProviderImpl = Object.create(FeeProviderImpl.prototype); + Reflect.set(provider, 'publicClient', { getBlockNumber }); + Reflect.set(provider, 'currentL1BlockNumber', undefined); + Reflect.set(provider, 'currentMinFees', Promise.resolve(new GasFees(0, 0))); + Reflect.set(provider, 'computeCurrentMinFees', computeCurrentMinFees); + + // Call at block N starts a computation that stays in flight. + const callN = provider.getCurrentMinFees(); + // Call at block N+1 advances the marker while the N computation is still pending. + const callNext = provider.getCurrentMinFees(); + + // The stale N computation now rejects. It must NOT clear the marker (which now points at N+1). + computeN.reject(new Error('stale L1 RPC request failed')); + + await expect(callN).rejects.toThrow('stale L1 RPC request failed'); + await expect(callNext).resolves.toEqual(new GasFees(0, 42)); + + // Marker still reflects the newer block; the N+1 computation ran exactly once (no spurious recompute). + expect(Reflect.get(provider, 'currentL1BlockNumber')).toBe(blockNext); + expect(computeCurrentMinFees).toHaveBeenCalledTimes(2); + }); }); diff --git a/yarn-project/sequencer-client/src/global_variable_builder/fee_provider.ts b/yarn-project/sequencer-client/src/global_variable_builder/fee_provider.ts index 3ec4cb194d7d..765f7213831d 100644 --- a/yarn-project/sequencer-client/src/global_variable_builder/fee_provider.ts +++ b/yarn-project/sequencer-client/src/global_variable_builder/fee_provider.ts @@ -61,10 +61,27 @@ export class FeeProviderImpl implements FeeProvider { // Get the current block number const blockNumber = await this.publicClient.getBlockNumber({ cacheTime: 0 }); - // If the L1 block number has changed then chain a new promise to get the current min fees + // If the L1 block number has changed then chain a new promise to get the current min fees. + // We chain off the previous promise's settlement (via a swallowing catch) rather than its + // fulfillment, so a prior rejection does not short-circuit the new computation. If the new + // computation fails (e.g. a transient L1 RPC error), reset the cached block number so the + // next call recomputes instead of permanently replaying the rejected promise — otherwise a + // single transient failure would wedge fee estimation until the next L1 block arrives. Only + // clear it if it still points at the block this attempt was for, so a stale rejection from an + // older block cannot wipe a marker a newer call already advanced (which would also defeat the + // monotonic block-number guard). if (this.currentL1BlockNumber === undefined || blockNumber > this.currentL1BlockNumber) { this.currentL1BlockNumber = blockNumber; - this.currentMinFees = this.currentMinFees.then(() => this.computeCurrentMinFees()); + this.currentMinFees = this.currentMinFees + .catch(() => undefined) + .then(() => + this.computeCurrentMinFees().catch(err => { + if (this.currentL1BlockNumber === blockNumber) { + this.currentL1BlockNumber = undefined; + } + throw err; + }), + ); } return this.currentMinFees; } diff --git a/yarn-project/telemetry-client/src/attributes.ts b/yarn-project/telemetry-client/src/attributes.ts index 900b27f915a8..8a262c03efe6 100644 --- a/yarn-project/telemetry-client/src/attributes.ts +++ b/yarn-project/telemetry-client/src/attributes.ts @@ -73,6 +73,8 @@ export const OK = 'aztec.ok'; export const STATUS = 'aztec.status'; /** Generic error type attribute */ export const ERROR_TYPE = 'aztec.error_type'; +/** The cause of an archiver prune (unproven / uncheckpointed / l1_conflict / orphan / l1_mismatch) */ +export const PRUNE_TYPE = 'aztec.archiver.prune_type'; /** The type of the transaction */ export const L1_TX_TYPE = 'aztec.l1.tx_type'; /** The L1 address of the entity that sent a transaction to L1 */ diff --git a/yarn-project/telemetry-client/src/metrics.ts b/yarn-project/telemetry-client/src/metrics.ts index 66c7ef86bdbb..7342f8bd4668 100644 --- a/yarn-project/telemetry-client/src/metrics.ts +++ b/yarn-project/telemetry-client/src/metrics.ts @@ -162,7 +162,7 @@ export const MEMPOOL_TX_ADDED_COUNT: MetricDefinition = { }; export const MEMPOOL_TX_MINED_DELAY: MetricDefinition = { name: 'aztec.mempool.tx_mined_delay', - description: 'Delay between transaction added and evicted from the mempool', + description: 'Delay (ms) from a transaction being received into the pool to being mined', unit: 'ms', valueType: ValueType.INT, }; @@ -340,7 +340,8 @@ export const ARCHIVER_PRUNE_DURATION: MetricDefinition = { }; export const ARCHIVER_PRUNE_COUNT: MetricDefinition = { name: 'aztec.archiver.prune_count', - description: 'Number of prunes detected', + description: + 'Number of prunes detected, dimensioned by prune_type: unproven (epoch prune of checkpoints that will not be proven), uncheckpointed (proposed blocks whose slot ended without a checkpoint), l1_conflict (proposed blocks conflicting with an L1 checkpoint), orphan (proposed blocks whose matching proposed checkpoint never arrived before the deadline), and l1_mismatch (the local checkpointed tip diverged from L1 — an L1 reorg or a pruned/missed-proof checkpoint — rewinding already-checkpointed blocks).', valueType: ValueType.INT, }; diff --git a/yarn-project/telemetry-client/src/otel.ts b/yarn-project/telemetry-client/src/otel.ts index 5e51a19aa548..b59b5acdf4d9 100644 --- a/yarn-project/telemetry-client/src/otel.ts +++ b/yarn-project/telemetry-client/src/otel.ts @@ -255,6 +255,23 @@ export class OpenTelemetryClient implements TelemetryClient { true, ), }), + // Pending-to-mined delay routinely exceeds the 1-minute ceiling of the generic `ms` + // view below under load, so it would saturate at 60s. Give this one metric wider + // buckets (1s to 10min). This must precede the generic `ms` view: when multiple views + // match an instrument, the SDK keeps the first-registered compatible storage, so the + // first view in this list wins the bucket boundaries. + new View({ + instrumentType: InstrumentType.HISTOGRAM, + instrumentName: 'aztec.mempool.tx_mined_delay', + instrumentUnit: 'ms', + aggregation: new ExplicitBucketHistogramAggregation( + [ + 1_000, 2_500, 5_000, 7_500, 10_000, 15_000, 30_000, 45_000, 60_000, 90_000, 120_000, 180_000, 300_000, + 600_000, + ], + true, + ), + }), new View({ instrumentType: InstrumentType.HISTOGRAM, instrumentUnit: 'ms',