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/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/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/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',