diff --git a/.github/scripts/classify-runtime-changes.sh b/.github/scripts/classify-runtime-changes.sh index 336e4ec802..6c48edc262 100755 --- a/.github/scripts/classify-runtime-changes.sh +++ b/.github/scripts/classify-runtime-changes.sh @@ -29,6 +29,10 @@ while IFS= read -r path; do runtime=true sdk_drift=true ;; + .github/workflows/clone-epoch-soak.yml|.github/scripts/test-clone-epoch-soak-workflow.sh|clones/scripts/clone-process-supervision.sh|clones/scripts/run-clone-block-monitor.sh|clones/scripts/run-clone-epoch-soak.sh|clones/js-tests/lib/clone-invariants.ts|clones/js-tests/lib/clone-performance.ts|clones/js-tests/lib/clone-readiness.ts|clones/js-tests/scripts/monitor-clone-blocks.ts|clones/js-tests/scripts/run-clone-epoch-soak.ts|clones/js-tests/scripts/wait-clone-readiness.ts|clones/js-tests/tests/clone-performance.test.ts|clones/js-tests/package.json) + runtime=true + snapshot_ci=true + ;; clones/*|website/apps/bittensor-website/scripts/*) runtime=true ;; @@ -63,7 +67,7 @@ while IFS= read -r path; do esac case "$path" in - .github/workflows/runtime-checks.yml|.github/workflows/refresh-mainnet-snapshot.yml|clones/scripts/run-clone-regression-phase.sh) + .github/workflows/runtime-checks.yml|.github/workflows/refresh-mainnet-snapshot.yml|.github/workflows/clone-epoch-soak.yml|clones/scripts/clone-process-supervision.sh|clones/scripts/run-clone-block-monitor.sh|clones/scripts/run-clone-regression-phase.sh|clones/scripts/run-clone-epoch-soak.sh) snapshot_ci=true ;; esac diff --git a/.github/scripts/download-artifact.sh b/.github/scripts/download-artifact.sh index 4c250bb5e5..2488ed67db 100755 --- a/.github/scripts/download-artifact.sh +++ b/.github/scripts/download-artifact.sh @@ -19,14 +19,16 @@ output_file="$6" : "${GITHUB_REPOSITORY:?GITHUB_REPOSITORY must be set}" : "${GITHUB_REPOSITORY_ID:?GITHUB_REPOSITORY_ID must be set}" +release_sha="${EXPECTED_RELEASE_SHA:-${GITHUB_SHA:-}}" + [[ "$artifact_id" =~ ^[1-9][0-9]*$ ]] || usage [[ "$expected_digest" =~ ^sha256:[0-9a-f]{64}$ ]] || usage [[ "$expected_size" =~ ^[1-9][0-9]*$ ]] || usage [[ -n "$destination" && "$destination" != / ]] || usage case "$artifact_name" in mainnet-snapshot|try-runtime-snap-v0.10.1-mainnet|try-runtime-snap-v0.10.1-testnet|try-runtime-snap-v0.10.1-devnet) ;; - "node-subtensor-release-${GITHUB_SHA:-invalid}") - [[ "${GITHUB_SHA:-}" =~ ^[0-9a-f]{40}$ ]] || usage + "node-subtensor-release-${release_sha:-invalid}") + [[ "$release_sha" =~ ^[0-9a-f]{40}$ ]] || usage ;; *) echo "artifact is outside the host-cache allowlist: $artifact_name" >&2; exit 2 ;; esac diff --git a/.github/scripts/select-shared-release-artifact.sh b/.github/scripts/select-shared-release-artifact.sh index 6ffcb79257..dc63265cd6 100755 --- a/.github/scripts/select-shared-release-artifact.sh +++ b/.github/scripts/select-shared-release-artifact.sh @@ -17,12 +17,38 @@ max_wait_seconds="${2:-360}" : "${GITHUB_SHA:?GITHUB_SHA must be set}" : "${GITHUB_PR_HEAD_SHA:?GITHUB_PR_HEAD_SHA must be set}" +event_name="${GITHUB_EVENT_NAME:-pull_request}" [[ "$GITHUB_REPOSITORY_ID" =~ ^[1-9][0-9]*$ ]] || usage [[ "$GITHUB_SHA" =~ ^[0-9a-f]{40}$ ]] || usage [[ "$GITHUB_PR_HEAD_SHA" =~ ^[0-9a-f]{40}$ ]] || usage [[ "$max_wait_seconds" =~ ^[0-9]+$ ]] || usage +[[ "$event_name" == pull_request || "$event_name" == workflow_dispatch ]] || usage -artifact_name="node-subtensor-release-$GITHUB_SHA" +artifact_sha="$GITHUB_SHA" +if [[ "$event_name" == workflow_dispatch ]]; then + pulls=$(gh api \ + -H 'Accept: application/vnd.github+json' \ + "repos/$GITHUB_REPOSITORY/commits/$GITHUB_PR_HEAD_SHA/pulls") + candidates=$(jq -cer \ + --arg repository_id "$GITHUB_REPOSITORY_ID" \ + --arg head_sha "$GITHUB_PR_HEAD_SHA" ' + [.[] + | select(.state == "open") + | select(.head.sha == $head_sha) + | select((.head.repo.id | tostring) == $repository_id) + | select((.base.repo.id | tostring) == $repository_id) + | select(.merge_commit_sha | type == "string") + | select(.merge_commit_sha | test("^[0-9a-f]{40}$"))] + ' <<< "$pulls") + candidate_count=$(jq -er 'length' <<< "$candidates") + if [[ "$candidate_count" != 1 ]]; then + echo "workflow_dispatch requires exactly one open same-repository PR for $GITHUB_PR_HEAD_SHA; found $candidate_count" >&2 + exit 1 + fi + artifact_sha=$(jq -er '.[0].merge_commit_sha' <<< "$candidates") +fi + +artifact_name="node-subtensor-release-$artifact_sha" workflow_path=.github/workflows/runtime-checks.yml started=$(date -u +%s) @@ -68,6 +94,8 @@ while true; do { echo "found=true" echo "artifact_id=$artifact_id" + echo "artifact_name=$artifact_name" + echo "artifact_sha=$artifact_sha" echo "digest=$digest" echo "size=$size" echo "run_id=$run_id" @@ -97,7 +125,7 @@ while true; do elapsed=$(($(date -u +%s) - started)) if (( elapsed >= max_wait_seconds )); then write_miss - echo "No exact-commit TypeScript release artifact appeared after ${elapsed}s; using the local build fallback." + echo "No exact-merge Runtime Checks release artifact appeared after ${elapsed}s." exit 0 fi remaining=$((max_wait_seconds - elapsed)) diff --git a/.github/scripts/test-clone-epoch-soak-workflow.sh b/.github/scripts/test-clone-epoch-soak-workflow.sh new file mode 100755 index 0000000000..43244a845c --- /dev/null +++ b/.github/scripts/test-clone-epoch-soak-workflow.sh @@ -0,0 +1,177 @@ +#!/usr/bin/env bash +set -euo pipefail + +repo_root=$(cd -- "$(dirname -- "${BASH_SOURCE[0]}")/../.." && pwd) +workflow="$repo_root/.github/workflows/clone-epoch-soak.yml" +soak_script="$repo_root/clones/scripts/run-clone-epoch-soak.sh" +monitor_script="$repo_root/clones/scripts/run-clone-block-monitor.sh" +supervisor_script="$repo_root/clones/scripts/clone-process-supervision.sh" +package="$repo_root/clones/js-tests/package.json" +epoch_script="$repo_root/clones/js-tests/scripts/run-clone-epoch-soak.ts" + +ruby -e 'require "yaml"; YAML.parse_file(ARGV.fetch(0))' "$workflow" +bash -n "$soak_script" +bash -n "$monitor_script" +bash -n "$supervisor_script" + +grep -Fq 'workflow_dispatch:' "$workflow" +grep -Fq 'types: [labeled, synchronize]' "$workflow" +grep -Fq "github.event.label.name == 'run-clone-epoch-soak'" "$workflow" +grep -Fq 'github.event.pull_request.head.repo.id || github.repository_id' "$workflow" +grep -Fq 'github.event.pull_request.head.ref || github.ref_name' "$workflow" +grep -Fq 'cancel-in-progress: true' "$workflow" +if grep -Fq 'cancel-in-progress: false' "$workflow"; then + echo "clone epoch soak must cancel superseded branch runs" >&2 + exit 1 +fi +if grep -Eq 'uses: actions/(checkout|setup-node|upload-artifact)@v[0-9]+' "$workflow"; then + echo "clone epoch soak actions must be pinned to full commit SHAs" >&2 + exit 1 +fi +grep -Fq 'github.event.pull_request.head.repo.fork == false' "$workflow" +if grep -Eq '^[[:space:]]*(push|schedule):' "$workflow"; then + echo "clone epoch soak must remain manually triggered" >&2 + exit 1 +fi +grep -Fq 'default: "2"' "$workflow" +dispatch=$(sed -n '/^ workflow_dispatch:/,/^concurrency:/p' "$workflow") +[[ $(grep -Ec '^ - "[123]"$' <<< "$dispatch") -eq 3 ]] +[[ $(grep -Ec '^ (epoch_cycles|fresh_state):$' <<< "$dispatch") -eq 2 ]] +grep -Fq 'type: boolean' <<< "$dispatch" +grep -Fq 'default: false' <<< "$dispatch" +grep -Fq 'runs-on: ubuntu-latest' "$workflow" +grep -Fq 'runs-on: [self-hosted, fireactions-turbo-8]' "$workflow" +if grep -Fq 'fireactions-validatorbench' "$workflow"; then + echo "clone epoch soak must use the turbo-8 runner" >&2 + exit 1 +fi +grep -Fq 'select-shared-release-artifact.sh "$GITHUB_OUTPUT" 1200' "$workflow" +grep -Fq 'needs.select-node-release.outputs.artifact_name' "$workflow" +grep -Fq 'EXPECTED_RELEASE_SHA: ${{ needs.select-node-release.outputs.artifact_sha }}' "$workflow" +grep -Fq 'needs.select-node-release.outputs.digest' "$workflow" +if grep -Fq 'cargo build --release -p node-subtensor' "$workflow"; then + echo "clone epoch soak must reuse the exact Runtime Checks release artifact" >&2 + exit 1 +fi +grep -Fq 'timeout-minutes: 150' "$workflow" +grep -Fq 'deadline_epoch_ms: ${{ steps.deadline.outputs.deadline_epoch_ms }}' "$workflow" +grep -Fq 'DEADLINE_EPOCH_MS: ${{ needs.select-node-release.outputs.deadline_epoch_ms }}' "$workflow" +grep -Fq 'retention-days: 14' "$workflow" +if grep -Fq 'clone-node.log.gz' "$workflow"; then + echo "the raw node log must not be retained as a soak artifact" >&2 + exit 1 +fi +grep -Fq 'inputs.fresh_state != true' "$workflow" +grep -Fq 'snapshot-artifact.sh select' "$workflow" +grep -Fq 'run-clone-epoch-soak.sh "${{ inputs.epoch_cycles || '\''2'\'' }}"' "$workflow" +grep -Fq 'SOAK_CHECKPOINT=' "$workflow" +grep -Fq 'clone-block-diagnostics-*.log' "$workflow" + +grep -Fq 'start-local-clone-and-wait.sh" accelerated' "$soak_script" +grep -Fq 'run-clone-block-monitor.sh" "$policy" "$label"' "$soak_script" +grep -Fq 'minimum_post_upgrade_blocks=${MINIMUM_POST_UPGRADE_BLOCKS:-7200}' "$soak_script" +if grep -Fq -- '--migration' "$soak_script"; then + echo "epoch soak must not permit bypassing its migration gate" >&2 + exit 1 +fi +grep -Fq 'waitForBetaBasketV2ReleaseReadiness(api' "$epoch_script" +if grep -Fq 'getFinalizedHead' "$epoch_script"; then + echo "single-node epoch coverage must use the same best-head state as readiness monitoring" >&2 + exit 1 +fi +jq -e '.scripts["monitor:block-latency"] and .scripts["wait:beta-basket-v2-readiness"] and .scripts["soak:epochs"] and .scripts["test:clone-performance"]' \ + "$package" >/dev/null + +tmp=$(mktemp -d) +trap 'rm -rf "$tmp"' EXIT +mkdir -p \ + "$tmp/repo/clones/scripts" \ + "$tmp/repo/clones/js-tests/temp" \ + "$tmp/bin" +cp "$soak_script" "$supervisor_script" "$tmp/repo/clones/scripts/" + +cat > "$tmp/repo/clones/scripts/run-clone-block-monitor.sh" <<'EOF' +#!/usr/bin/env bash +printf 'monitor start %s\n' "$*" >> "$HARNESS_LOG" +if [[ "${MOCK_MONITOR_FAIL:-false}" == true ]]; then + exit 1 +fi +[[ -z "${CLONE_MONITOR_READY_FILE:-}" ]] || printf '{}\n' > "$CLONE_MONITOR_READY_FILE" +trap 'printf "monitor stop\n" >> "$HARNESS_LOG"; exit 0' TERM INT +while true; do + /bin/sleep 0.02 +done +EOF +cat > "$tmp/repo/clones/scripts/start-local-clone-and-wait.sh" <<'EOF' +#!/usr/bin/env bash +repo_root=$(cd -- "$(dirname -- "$0")/../.." && pwd) +printf 'start %s\n' "$*" >> "$HARNESS_LOG" +: > "$repo_root/clone-node.log" +EOF +cat > "$tmp/repo/clones/scripts/stop-local-clone.sh" <<'EOF' +#!/usr/bin/env bash +printf 'stop\n' >> "$HARNESS_LOG" +EOF +cat > "$tmp/repo/clones/scripts/local-clone-checkpoint.sh" <<'EOF' +#!/usr/bin/env bash +printf 'checkpoint %s\n' "$*" >> "$HARNESS_LOG" +EOF +cat > "$tmp/bin/npm" <<'EOF' +#!/usr/bin/env bash +printf 'npm %s\n' "$*" >> "$HARNESS_LOG" +if [[ "$*" == *"soak:epochs"* ]]; then + exit "${MOCK_EPOCH_STATUS:-0}" +fi +if [[ "$*" == *"runtime:update:alice"* ]]; then + previous= + for argument in "$@"; do + if [[ "$previous" == --report ]]; then + printf '{"upgradeBlock":25,"finalizedAtEpochMs":123456}\n' > "$argument" + fi + previous=$argument + done +fi +EOF +chmod +x "$tmp/repo/clones/scripts/"*.sh "$tmp/bin/npm" + +export PATH="$tmp/bin:$PATH" +export HARNESS_LOG="$tmp/harness.log" +assert_before() { + local first=$1 second=$2 first_line second_line + first_line=$(grep -Fn -- "$first" "$HARNESS_LOG" | head -n 1 | cut -d: -f1) + second_line=$(grep -Fn -- "$second" "$HARNESS_LOG" | head -n 1 | cut -d: -f1) + [[ -n "$first_line" && -n "$second_line" && "$first_line" -lt "$second_line" ]] +} +deadline=$(( $(date +%s) * 1000 + 60000 )) +checkpoint="$tmp/checkpoint.tar.gz" +: > "$checkpoint" +SOAK_CHECKPOINT="$checkpoint" SOAK_DEADLINE_EPOCH_MS="$deadline" \ + "$tmp/repo/clones/scripts/run-clone-epoch-soak.sh" 2 +[[ $(grep -Fc 'start accelerated' "$HARNESS_LOG") -eq 2 ]] +grep -Fq 'monitor start baseline baseline ' "$HARNESS_LOG" +grep -Fq 'monitor start collect soak ' "$HARNESS_LOG" +[[ $(grep -Fc 'npm run soak:epochs -- --epoch-cycles 2' "$HARNESS_LOG") -eq 2 ]] +grep -Fq 'checkpoint restore' "$HARNESS_LOG" +grep -Fq -- '--release-gate beta-basket-v2 --upgrade-block 25 --minimum-post-upgrade-blocks 7200' "$HARNESS_LOG" +assert_before 'monitor start baseline baseline' '--release-gate none' +assert_before 'monitor start collect soak' 'npm run runtime:update:alice' +assert_before 'npm run runtime:update:alice' '--release-gate beta-basket-v2' +grep -Fq 'stop' "$HARNESS_LOG" + +: > "$HARNESS_LOG" +if MOCK_EPOCH_STATUS=1 SOAK_CHECKPOINT="$checkpoint" SOAK_DEADLINE_EPOCH_MS="$deadline" \ + "$tmp/repo/clones/scripts/run-clone-epoch-soak.sh" 2; then + echo "failed epoch coverage unexpectedly succeeded" >&2 + exit 1 +fi +grep -Fq 'stop' "$HARNESS_LOG" + +: > "$HARNESS_LOG" +if MOCK_MONITOR_FAIL=true SOAK_CHECKPOINT="$checkpoint" SOAK_DEADLINE_EPOCH_MS="$deadline" \ + "$tmp/repo/clones/scripts/run-clone-epoch-soak.sh" 2; then + echo "failed soak block monitor unexpectedly succeeded" >&2 + exit 1 +fi +grep -Fq 'stop' "$HARNESS_LOG" + +echo "clone epoch soak workflow contract tests passed" diff --git a/.github/scripts/test-clone-regression-phase.sh b/.github/scripts/test-clone-regression-phase.sh index 6c86f22fed..c553f1ca02 100755 --- a/.github/scripts/test-clone-regression-phase.sh +++ b/.github/scripts/test-clone-regression-phase.sh @@ -3,11 +3,12 @@ set -euo pipefail repo_root=$(cd -- "$(dirname -- "${BASH_SOURCE[0]}")/../.." && pwd) source_script="$repo_root/clones/scripts/run-clone-regression-phase.sh" +supervisor_script="$repo_root/clones/scripts/clone-process-supervision.sh" tmp=$(mktemp -d) trap 'rm -rf "$tmp"' EXIT -mkdir -p "$tmp/repo/clones/scripts" "$tmp/repo/clones/js-tests" "$tmp/repo/sdk/python" "$tmp/bin" -cp "$source_script" "$tmp/repo/clones/scripts/" +mkdir -p "$tmp/repo/clones/scripts" "$tmp/repo/clones/js-tests/temp" "$tmp/repo/sdk/python" "$tmp/bin" +cp "$source_script" "$supervisor_script" "$tmp/repo/clones/scripts/" for helper in start-local-clone-and-wait.sh stop-local-clone.sh local-clone-checkpoint.sh; do cat > "$tmp/repo/clones/scripts/$helper" <<'EOF' @@ -17,6 +18,22 @@ EOF chmod +x "$tmp/repo/clones/scripts/$helper" done +cat > "$tmp/repo/clones/scripts/run-clone-block-monitor.sh" <<'EOF' +#!/usr/bin/env bash +printf 'monitor start %s\n' "$*" >> "$HARNESS_LOG" +if [[ "${MOCK_MONITOR_FAIL:-false}" == true ]]; then + exit 1 +fi +if [[ "${MOCK_MONITOR_EXIT_EARLY:-false}" == true ]]; then + exit 0 +fi +[[ -z "${CLONE_MONITOR_READY_FILE:-}" ]] || printf '{}\n' > "$CLONE_MONITOR_READY_FILE" +trap 'printf "monitor stop\n" >> "$HARNESS_LOG"; exit 0' TERM INT +while true; do + /bin/sleep 0.02 +done +EOF + cat > "$tmp/bin/npm" <<'EOF' #!/usr/bin/env bash printf 'npm %s phase=%s cwd=%s\n' "$*" "${CLONE_REGRESSION_PHASE:-}" "$PWD" >> "$HARNESS_LOG" @@ -27,6 +44,15 @@ fi if [[ -n "${MOCK_NPM_FAIL:-}" && "$*" == *"$MOCK_NPM_FAIL"* ]]; then exit 1 fi +if [[ "$*" == *"runtime:update:alice"* ]]; then + previous= + for argument in "$@"; do + if [[ "$previous" == --report ]]; then + printf '{"upgradeBlock":22,"finalizedAtEpochMs":123456}\n' > "$argument" + fi + previous=$argument + done +fi EOF cat > "$tmp/bin/sleep" <<'EOF' #!/usr/bin/env bash @@ -36,7 +62,12 @@ cat > "$tmp/bin/uv" <<'EOF' #!/usr/bin/env bash printf 'uv %s cwd=%s\n' "$*" "$PWD" >> "$HARNESS_LOG" EOF -chmod +x "$tmp/bin/npm" "$tmp/bin/sleep" "$tmp/bin/uv" "$tmp/repo/clones/scripts/run-clone-regression-phase.sh" +chmod +x \ + "$tmp/bin/npm" \ + "$tmp/bin/sleep" \ + "$tmp/bin/uv" \ + "$tmp/repo/clones/scripts/run-clone-block-monitor.sh" \ + "$tmp/repo/clones/scripts/run-clone-regression-phase.sh" export PATH="$tmp/bin:$PATH" export HARNESS_LOG="$tmp/harness.log" @@ -50,22 +81,48 @@ run_phase() { "$tmp/repo/clones/scripts/run-clone-regression-phase.sh" "$1" } +assert_before() { + local first=$1 second=$2 first_line second_line + first_line=$(grep -Fn "$first" "$HARNESS_LOG" | head -n 1 | cut -d: -f1) + second_line=$(grep -Fn "$second" "$HARNESS_LOG" | head -n 1 | cut -d: -f1) + [[ -n "$first_line" && -n "$second_line" && "$first_line" -lt "$second_line" ]] +} + run_phase pristine grep -Fq 'start-local-clone-and-wait.sh accelerated' "$HARNESS_LOG" grep -Fq 'npm run runtime:update:alice' "$HARNESS_LOG" +assert_before 'monitor start fail-fast pristine' 'npm run runtime:update:alice' +grep -Fq 'npm run wait:beta-basket-v2-readiness -- --label pristine --timeout-ms 2700000 --report temp/clone-readiness-pristine.json' "$HARNESS_LOG" grep -Fq 'npm run test:clone-regressions phase=pristine' "$HARNESS_LOG" +assert_before 'npm run wait:beta-basket-v2-readiness' 'npm run test:clone-regressions' +grep -Fq 'monitor start fail-fast pristine ' "$HARNESS_LOG" +grep -Fq 'monitor stop' "$HARNESS_LOG" grep -Fq 'stop-local-clone.sh ' "$HARNESS_LOG" + +: > "$HARNESS_LOG" +if early_output=$(MOCK_MONITOR_EXIT_EARLY=true \ + RUN_SDK_DRIFT=false \ + "$tmp/repo/clones/scripts/run-clone-regression-phase.sh" pristine 2>&1); then + echo "early successful clone block monitor exit unexpectedly succeeded" >&2 + exit 1 +fi +grep -Fq 'clone block monitor exited before becoming ready' <<< "$early_output" if grep -Fq 'npm test' "$HARNESS_LOG"; then echo "pristine phase unexpectedly ran remaining smoke tests" >&2 exit 1 fi run_phase remaining +grep -Fq 'npm run wait:beta-basket-v2-readiness -- --label remaining --timeout-ms 2700000 --report temp/clone-readiness-remaining.json' "$HARNESS_LOG" grep -Fq 'npm test phase=' "$HARNESS_LOG" grep -Fq 'npm run test:clone-regressions phase=remaining' "$HARNESS_LOG" +assert_before 'npm run wait:beta-basket-v2-readiness' 'npm test phase=' +grep -Fq 'monitor start fail-fast remaining ' "$HARNESS_LOG" +assert_before 'monitor start fail-fast remaining' 'npm run runtime:update:alice' run_phase combined [[ $(grep -Fc 'start-local-clone-and-wait.sh accelerated' "$HARNESS_LOG") -eq 2 ]] +[[ $(grep -Fc 'monitor start fail-fast' "$HARNESS_LOG") -eq 2 ]] grep -Fq "local-clone-checkpoint.sh restore $checkpoint" "$HARNESS_LOG" grep -Fq 'npm run test:clone-regressions phase=pristine' "$HARNESS_LOG" grep -Fq 'npm run test:clone-regressions phase=remaining' "$HARNESS_LOG" @@ -92,6 +149,23 @@ if MOCK_NPM_FAIL=test:clone-regressions \ fi grep -Fq 'stop-local-clone.sh ' "$HARNESS_LOG" +: > "$HARNESS_LOG" +if MOCK_MONITOR_FAIL=true \ + RUN_SDK_DRIFT=false \ + "$tmp/repo/clones/scripts/run-clone-regression-phase.sh" pristine; then + echo "failed clone block monitor unexpectedly succeeded" >&2 + exit 1 +fi +grep -Fq 'monitor start fail-fast pristine ' "$HARNESS_LOG" +grep -Fq 'stop-local-clone.sh ' "$HARNESS_LOG" + +if CLONE_READINESS_TIMEOUT_MS=invalid \ + RUN_SDK_DRIFT=false \ + "$tmp/repo/clones/scripts/run-clone-regression-phase.sh" pristine; then + echo "invalid clone readiness timeout unexpectedly succeeded" >&2 + exit 1 +fi + if "$tmp/repo/clones/scripts/run-clone-regression-phase.sh" invalid >/dev/null 2>&1; then echo "invalid clone phase was accepted" >&2 exit 1 diff --git a/.github/scripts/test-download-artifact.sh b/.github/scripts/test-download-artifact.sh index 785d6f02b5..7634d5754d 100755 --- a/.github/scripts/test-download-artifact.sh +++ b/.github/scripts/test-download-artifact.sh @@ -71,6 +71,13 @@ cmp "$tmp/payload/mainnet-snapshot.tar.gz" "$tmp/local/mainnet-snapshot.tar.gz" grep -qx 'source=local-hit' "$tmp/output" cmp "$tmp/payload/mainnet-snapshot.tar.gz" "$tmp/release/mainnet-snapshot.tar.gz" +export EXPECTED_RELEASE_SHA=cccccccccccccccccccccccccccccccccccccccc +: > "$tmp/output" +"$helper" 123 node-subtensor-release-cccccccccccccccccccccccccccccccccccccccc "$digest" "$size" \ + "$tmp/manual-release" "$tmp/output" >/dev/null +grep -qx 'source=local-hit' "$tmp/output" +unset EXPECTED_RELEASE_SHA + : > "$tmp/output" "$helper" 123 try-runtime-snap-v0.10.1-mainnet "$digest" "$size" \ "$tmp/try-runtime" "$tmp/output" >/dev/null diff --git a/.github/scripts/test-r2-artifact-mirror.py b/.github/scripts/test-r2-artifact-mirror.py index 8557838f62..6d9abc23c6 100755 --- a/.github/scripts/test-r2-artifact-mirror.py +++ b/.github/scripts/test-r2-artifact-mirror.py @@ -19,6 +19,7 @@ CURRENT_RUN_HELPER = Path(__file__).with_name( "publish-current-run-artifact-mirror.sh" ) +SNAPSHOT_WORKFLOW = Path(__file__).parents[1] / "workflows" / "refresh-mainnet-snapshot.yml" SPEC = importlib.util.spec_from_file_location("r2_artifact_mirror", SCRIPT) assert SPEC and SPEC.loader MODULE = importlib.util.module_from_spec(SPEC) @@ -31,6 +32,14 @@ "try-runtime-snap-v0.10.1-devnet", } +snapshot_workflow = SNAPSHOT_WORKFLOW.read_text(encoding="utf-8") +mainnet_mirror_step = snapshot_workflow.split( + " # try-runtime state snapshots", maxsplit=1 +)[0].split(" - name: Mirror snapshot for fleet prefetch", maxsplit=1)[1] +assert "publish-current-run-artifact-mirror.sh" in mainnet_mirror_step +assert "mainnet-snapshot" in mainnet_mirror_step +assert "steps.upload-snapshot.outputs.artifact-digest" not in mainnet_mirror_step + assert MODULE.validate_endpoint( "https://3dc4cebb791314d78848969042fb3382.r2.cloudflarestorage.com" diff --git a/.github/scripts/test-runtime-change-filter.sh b/.github/scripts/test-runtime-change-filter.sh index e24706e60b..13e6ed4f5f 100755 --- a/.github/scripts/test-runtime-change-filter.sh +++ b/.github/scripts/test-runtime-change-filter.sh @@ -53,8 +53,17 @@ assert_classification .github/scripts/benchmark-artifact-cache.sh "$runtime_and_ assert_classification .github/scripts/publish-current-run-artifact-mirror.sh "$runtime_and_snapshot_only" assert_classification clones/scripts/start-local-clone-and-wait.sh "$runtime_only" assert_classification clones/scripts/run-clone-regression-phase.sh "$runtime_and_snapshot_only" +assert_classification clones/scripts/run-clone-epoch-soak.sh "$runtime_and_snapshot_only" +assert_classification clones/scripts/run-clone-block-monitor.sh "$runtime_and_snapshot_only" +assert_classification clones/scripts/clone-process-supervision.sh "$runtime_and_snapshot_only" +assert_classification clones/js-tests/lib/clone-performance.ts "$runtime_and_snapshot_only" +assert_classification clones/js-tests/lib/clone-invariants.ts "$runtime_and_snapshot_only" +assert_classification clones/js-tests/lib/clone-readiness.ts "$runtime_and_snapshot_only" +assert_classification clones/js-tests/scripts/wait-clone-readiness.ts "$runtime_and_snapshot_only" assert_classification .github/scripts/test-clone-regression-phase.sh "$runtime_and_snapshot_only" +assert_classification .github/scripts/test-clone-epoch-soak-workflow.sh "$runtime_and_snapshot_only" assert_classification .github/workflows/refresh-mainnet-snapshot.yml "$runtime_and_snapshot_only" +assert_classification .github/workflows/clone-epoch-soak.yml "$runtime_and_snapshot_only" assert_classification .github/workflows/runtime-checks.yml "$runtime_and_snapshot" assert_classification website/apps/bittensor-website/scripts/generate-metadata.mjs "$runtime_and_docs" assert_classification docs/concepts/client.mdx "$docs_only" @@ -76,7 +85,16 @@ grep -Fq 'matrix={"phase":["pristine","remaining"]}' "$runtime_workflow" grep -Fq 'matrix={"phase":["combined"]}' "$runtime_workflow" grep -Fq "needs.clone-plan.outputs.matrix || '{\"phase\":[\"combined\"]}'" "$runtime_workflow" grep -Fq './clones/scripts/run-clone-regression-phase.sh "${{ matrix.phase }}"' "$runtime_workflow" +clone_upgrade_job=$(sed -n '/^ clone-upgrade:/,/^ clone-upgrade-gate:/p' "$runtime_workflow") +grep -Fq 'runs-on: [self-hosted, fireactions-turbo-8]' <<< "$clone_upgrade_job" +if grep -Fq 'fireactions-validatorbench' <<< "$clone_upgrade_job"; then + echo "clone-upgrade phases, including remaining, must use fireactions-turbo-8" >&2 + exit 1 +fi grep -Fq 'RUN_SDK_DRIFT: ${{ github.event_name != '\''pull_request'\'' || needs.changes.outputs.sdk_drift == '\''true'\'' }}' "$runtime_workflow" +grep -Fq 'clones/js-tests/temp/clone-readiness-*.json' "$runtime_workflow" +grep -Fq 'uses: actions/setup-node@49933ea5288caeca8642d1e84afbd3f7d6820020 # v4' "$runtime_workflow" +grep -Fq 'uses: actions/upload-artifact@ea165f8d65b6e75b540449e92b4886f43607fa02 # v4' <<< "$clone_upgrade_job" grep -Fq 'artifact_id: ${{ steps.plan.outputs.artifact_id }}' "$runtime_workflow" grep -Fq 'ARTIFACT_ID: ${{ needs.clone-plan.outputs.artifact_id }}' "$runtime_workflow" grep -Fq 'gh api "repos/$GITHUB_REPOSITORY/actions/artifacts/$ARTIFACT_ID"' "$runtime_workflow" diff --git a/.github/scripts/test-select-shared-release-artifact.sh b/.github/scripts/test-select-shared-release-artifact.sh index 033363a118..07d713e5d9 100755 --- a/.github/scripts/test-select-shared-release-artifact.sh +++ b/.github/scripts/test-select-shared-release-artifact.sh @@ -15,6 +15,7 @@ endpoint="${!#}" case "$endpoint" in */actions/artifacts*) cat "$MOCK_ARTIFACTS" ;; */actions/runs/777) cat "$MOCK_RUN" ;; + */commits/*/pulls) cat "$MOCK_PULLS" ;; *) echo "unexpected endpoint: $endpoint" >&2; exit 2 ;; esac EOF @@ -26,8 +27,10 @@ export GITHUB_REPOSITORY=RaoFoundation/subtensor export GITHUB_REPOSITORY_ID=608683796 export GITHUB_SHA=cccccccccccccccccccccccccccccccccccccccc export GITHUB_PR_HEAD_SHA=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa +export GITHUB_EVENT_NAME=pull_request export MOCK_ARTIFACTS="$tmp/artifacts.json" export MOCK_RUN="$tmp/run.json" +export MOCK_PULLS="$tmp/pulls.json" cat > "$MOCK_ARTIFACTS" <<'EOF' {"artifacts":[{"id":123,"name":"node-subtensor-release-cccccccccccccccccccccccccccccccccccccccc","size_in_bytes":456,"digest":"sha256:bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb","expired":false,"created_at":"2026-07-17T00:00:00Z","workflow_run":{"id":777,"head_sha":"aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa","head_repository_id":608683796}}]} @@ -35,11 +38,16 @@ EOF cat > "$MOCK_RUN" <<'EOF' {"id":777,"event":"pull_request","head_sha":"aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa","head_repository":{"id":608683796},"path":".github/workflows/runtime-checks.yml"} EOF +cat > "$MOCK_PULLS" <<'EOF' +[{"state":"open","merge_commit_sha":"cccccccccccccccccccccccccccccccccccccccc","head":{"sha":"aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa","repo":{"id":608683796}},"base":{"repo":{"id":608683796}}}] +EOF : > "$tmp/output" "$selector" "$tmp/output" 0 >/dev/null grep -qx 'found=true' "$tmp/output" grep -qx 'artifact_id=123' "$tmp/output" +grep -qx 'artifact_name=node-subtensor-release-cccccccccccccccccccccccccccccccccccccccc' "$tmp/output" +grep -qx 'artifact_sha=cccccccccccccccccccccccccccccccccccccccc' "$tmp/output" grep -qx 'run_id=777' "$tmp/output" grep -qx 'size=456' "$tmp/output" grep -qx 'digest=sha256:bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb' "$tmp/output" @@ -70,4 +78,22 @@ export MOCK_ARTIFACTS="$tmp/bad-artifacts.json" "$selector" "$tmp/output" 0 >/dev/null grep -qx 'found=false' "$tmp/output" +# A manual dispatch runs at the source head SHA. Resolve its sole open, +# same-repository PR to the synthetic merge SHA that names the trusted build. +export GITHUB_EVENT_NAME=workflow_dispatch +export GITHUB_SHA=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa +export MOCK_ARTIFACTS="$tmp/artifacts.json" +export MOCK_RUN="$tmp/run.json" +: > "$tmp/output" +"$selector" "$tmp/output" 0 >/dev/null +grep -qx 'found=true' "$tmp/output" +grep -qx 'artifact_sha=cccccccccccccccccccccccccccccccccccccccc' "$tmp/output" + +jq '. + [.[0]]' "$MOCK_PULLS" > "$tmp/ambiguous-pulls.json" +export MOCK_PULLS="$tmp/ambiguous-pulls.json" +if "$selector" "$tmp/output" 0 >/dev/null 2>&1; then + echo "ambiguous manual PR context unexpectedly succeeded" >&2 + exit 1 +fi + echo "shared release artifact selector tests passed" diff --git a/.github/workflows/clone-epoch-soak.yml b/.github/workflows/clone-epoch-soak.yml new file mode 100644 index 0000000000..704224abbd --- /dev/null +++ b/.github/workflows/clone-epoch-soak.yml @@ -0,0 +1,217 @@ +name: Mainnet Clone Epoch Soak + +on: + pull_request: + types: [labeled, synchronize] + workflow_dispatch: + inputs: + epoch_cycles: + description: "Complete post-migration epoch cycles required for every active non-root subnet" + type: choice + options: + - "1" + - "2" + - "3" + default: "2" + fresh_state: + description: "Bypass the trusted nightly snapshot and scrape mainnet state live" + type: boolean + default: false + +concurrency: + group: mainnet-clone-epoch-soak-${{ github.event.pull_request.head.repo.id || github.repository_id }}-${{ github.event.pull_request.head.ref || github.ref_name }} + cancel-in-progress: true + +env: + CARGO_TERM_COLOR: always + WS_ENDPOINT: ws://127.0.0.1:9944 + +jobs: + select-node-release: + name: select exact Runtime Checks release node + if: >- + github.event_name == 'workflow_dispatch' || + (github.event.action == 'labeled' && + github.event.label.name == 'run-clone-epoch-soak' && + github.event.pull_request.head.repo.fork == false) + runs-on: ubuntu-latest + timeout-minutes: 25 + permissions: + contents: read + actions: read + pull-requests: read + outputs: + artifact_id: ${{ steps.release.outputs.artifact_id }} + artifact_name: ${{ steps.release.outputs.artifact_name }} + artifact_sha: ${{ steps.release.outputs.artifact_sha }} + digest: ${{ steps.release.outputs.digest }} + size: ${{ steps.release.outputs.size }} + run_id: ${{ steps.release.outputs.run_id }} + deadline_epoch_ms: ${{ steps.deadline.outputs.deadline_epoch_ms }} + steps: + # Keep the complete two-job workflow inside 150 minutes while reserving + # ten minutes for clone shutdown and report upload. + - name: Set workflow deadline + id: deadline + run: echo "deadline_epoch_ms=$(( $(date -u +%s) * 1000 + 140 * 60 * 1000 ))" >> "$GITHUB_OUTPUT" + + - uses: actions/checkout@34e114876b0b11c390a56381ad16ebd13914f8d5 # v4 + + - name: Wait for exact release node from Runtime Checks + id: release + env: + GH_TOKEN: ${{ github.token }} + GITHUB_REPOSITORY_ID: ${{ github.repository_id }} + GITHUB_PR_HEAD_SHA: ${{ github.event.pull_request.head.sha || github.sha }} + run: | + .github/scripts/select-shared-release-artifact.sh "$GITHUB_OUTPUT" 1200 + if ! grep -qx 'found=true' "$GITHUB_OUTPUT"; then + echo "::error::No exact Runtime Checks release artifact became available." + exit 1 + fi + + epoch-soak: + name: post-upgrade epoch soak (${{ inputs.epoch_cycles || '2' }} cycles) + needs: select-node-release + runs-on: [self-hosted, fireactions-turbo-8] + timeout-minutes: 150 + permissions: + contents: read + actions: read + steps: + - uses: actions/checkout@34e114876b0b11c390a56381ad16ebd13914f8d5 # v4 + + - name: Restore workflow deadline + env: + DEADLINE_EPOCH_MS: ${{ needs.select-node-release.outputs.deadline_epoch_ms }} + run: | + [[ "$DEADLINE_EPOCH_MS" =~ ^[1-9][0-9]*$ ]] + echo "SOAK_DEADLINE_EPOCH_MS=$DEADLINE_EPOCH_MS" >> "$GITHUB_ENV" + + - name: Download exact release node and runtime + id: release-download + env: + GH_TOKEN: ${{ github.token }} + GITHUB_REPOSITORY_ID: ${{ github.repository_id }} + EXPECTED_RELEASE_SHA: ${{ needs.select-node-release.outputs.artifact_sha }} + run: | + .github/scripts/download-artifact.sh \ + "${{ needs.select-node-release.outputs.artifact_id }}" \ + "${{ needs.select-node-release.outputs.artifact_name }}" \ + "${{ needs.select-node-release.outputs.digest }}" \ + "${{ needs.select-node-release.outputs.size }}" \ + target/release "$GITHUB_OUTPUT" + + - name: Validate release node and runtime + run: | + test -s target/release/node-subtensor + test -s target/release/wbuild/node-subtensor-runtime/node_subtensor_runtime.compact.compressed.wasm + chmod +x target/release/node-subtensor + + - name: Set up Node.js + uses: actions/setup-node@49933ea5288caeca8642d1e84afbd3f7d6820020 # v4 + with: + node-version: 20 + + - name: Install clone test dependencies + working-directory: clones/js-tests + run: npm ci + + - name: Select trusted mainnet snapshot + id: snapshot + if: github.event_name == 'pull_request' || inputs.fresh_state != true + env: + GH_TOKEN: ${{ github.token }} + run: | + .github/scripts/snapshot-artifact.sh select \ + mainnet-snapshot \ + "${{ github.event.repository.default_branch }}" \ + "${{ github.repository_id }}" \ + .github/workflows/refresh-mainnet-snapshot.yml \ + 168 "$GITHUB_OUTPUT" required + + - name: Download trusted mainnet snapshot + id: download-snapshot + if: github.event_name == 'pull_request' || inputs.fresh_state != true + env: + GH_TOKEN: ${{ github.token }} + GITHUB_REPOSITORY_ID: ${{ github.repository_id }} + run: | + .github/scripts/download-artifact.sh \ + "${{ steps.snapshot.outputs.artifact-id }}" \ + mainnet-snapshot \ + "${{ steps.snapshot.outputs.artifact-digest }}" \ + "${{ steps.snapshot.outputs.artifact-size-bytes }}" \ + "$RUNNER_TEMP/mainnet-epoch-soak-snapshot" "$GITHUB_OUTPUT" + + - name: Restore trusted mainnet snapshot + if: github.event_name == 'pull_request' || inputs.fresh_state != true + run: | + ./clones/scripts/local-clone-checkpoint.sh restore \ + "$RUNNER_TEMP/mainnet-epoch-soak-snapshot/mainnet-snapshot.tar.gz" + echo "KEEP_CLONE_DATA=1" >> "$GITHUB_ENV" + echo "SOAK_CHECKPOINT=$RUNNER_TEMP/mainnet-epoch-soak-snapshot/mainnet-snapshot.tar.gz" >> "$GITHUB_ENV" + { + echo "### Mainnet clone snapshot" + echo "- Artifact: ${{ steps.snapshot.outputs.artifact-id }}" + echo "- Age: ${{ steps.snapshot.outputs.age-hours }}h" + echo "- Download source: ${{ steps.download-snapshot.outputs.source }}" + } >> "$GITHUB_STEP_SUMMARY" + + - name: Create clone from fresh mainnet state + if: github.event_name == 'workflow_dispatch' && inputs.fresh_state == true + run: | + for attempt in 1 2 3; do + if timeout --kill-after=30 1200 ./clones/scripts/clone-mainnet.sh; then + exit 0 + fi + echo "::warning::mainnet scrape attempt ${attempt} timed out or failed; retrying" + pkill -9 -f build-patched-spec || true + sleep 10 + done + exit 1 + + - name: Checkpoint fresh clone state + if: github.event_name == 'workflow_dispatch' && inputs.fresh_state == true + run: | + checkpoint="$RUNNER_TEMP/mainnet-epoch-soak-fresh.tar" + ./clones/scripts/local-clone-checkpoint.sh create "$checkpoint" + echo "SOAK_CHECKPOINT=$checkpoint" >> "$GITHUB_ENV" + echo "KEEP_CLONE_DATA=1" >> "$GITHUB_ENV" + + - name: Run accelerated post-upgrade epoch soak + # The release runtime still advances Timestamp by 12 seconds per block; + # only manual-seal wall scheduling is compressed to 250ms. + run: ./clones/scripts/run-clone-epoch-soak.sh "${{ inputs.epoch_cycles || '2' }}" + + - name: Stop clone + if: always() + run: ./clones/scripts/stop-local-clone.sh + + - name: Dump diagnostic tails + if: failure() + run: | + echo "===== clone-node.log (last 300 lines) =====" + tail -n 300 clone-node.log 2>/dev/null || echo "(missing)" + for file in clones/js-tests/temp/clone-*.log; do + [ -f "$file" ] || continue + echo "===== $file =====" + tail -n 300 "$file" + done + + - name: Upload soak reports and logs + if: always() + uses: actions/upload-artifact@ea165f8d65b6e75b540449e92b4886f43607fa02 # v4 + with: + name: clone-epoch-soak-${{ github.run_id }}-${{ github.run_attempt }} + path: | + clones/js-tests/temp/clone-block-performance-*.log + clones/js-tests/temp/clone-block-performance-*.json + clones/js-tests/temp/clone-block-diagnostics-*.log + clones/js-tests/temp/runtime-upgrade-soak.json + clones/js-tests/temp/clone-epoch-baseline.log + clones/js-tests/temp/clone-epoch-coverage-baseline.json + clones/js-tests/temp/clone-epoch-soak.log + clones/js-tests/temp/clone-epoch-coverage.json + if-no-files-found: warn + retention-days: 14 diff --git a/.github/workflows/refresh-mainnet-snapshot.yml b/.github/workflows/refresh-mainnet-snapshot.yml index 1cc63e6278..edea7c8776 100644 --- a/.github/workflows/refresh-mainnet-snapshot.yml +++ b/.github/workflows/refresh-mainnet-snapshot.yml @@ -112,16 +112,9 @@ jobs: - name: Mirror snapshot for fleet prefetch env: GH_TOKEN: ${{ github.token }} - ARTIFACT_ID: ${{ steps.upload-snapshot.outputs.artifact-id }} - ARTIFACT_DIGEST: ${{ steps.upload-snapshot.outputs.artifact-digest }} - run: | - set -euo pipefail - .github/scripts/publish-artifact-mirror.sh \ - "$ARTIFACT_ID" \ - mainnet-snapshot \ - "$ARTIFACT_DIGEST" \ - "$GITHUB_SHA" \ - .github/workflows/refresh-mainnet-snapshot.yml + run: >- + .github/scripts/publish-current-run-artifact-mirror.sh + mainnet-snapshot # try-runtime state snapshots, one job per network so one flaky endpoint # doesn't prevent the others from publishing. The .snap format diff --git a/.github/workflows/runtime-checks.yml b/.github/workflows/runtime-checks.yml index 3e2bd43dec..fa769f2d8b 100644 --- a/.github/workflows/runtime-checks.yml +++ b/.github/workflows/runtime-checks.yml @@ -135,11 +135,21 @@ jobs: runs-on: ubuntu-latest steps: - uses: actions/checkout@v4 + - uses: actions/setup-node@49933ea5288caeca8642d1e84afbd3f7d6820020 # v4 + with: + node-version: 20 + - name: Install clone monitor dependencies + working-directory: clones/js-tests + run: npm ci + - name: Test clone performance monitor + working-directory: clones/js-tests + run: npm run test:clone-performance - run: .github/scripts/test-snapshot-artifact.sh - run: .github/scripts/test-download-artifact.sh - run: .github/scripts/test-select-shared-release-artifact.sh - run: .github/scripts/test-runtime-change-filter.sh - run: .github/scripts/test-clone-regression-phase.sh + - run: .github/scripts/test-clone-epoch-soak-workflow.sh # Build the try-runtime wasm independently so its consumers do not wait for # the unrelated release node build. The source check also makes the @@ -739,6 +749,21 @@ jobs: cat "$f" done + - name: Upload clone block performance report + if: always() + uses: actions/upload-artifact@ea165f8d65b6e75b540449e92b4886f43607fa02 # v4 + with: + name: clone-block-performance-${{ matrix.phase }}-${{ github.run_id }} + path: | + clones/js-tests/temp/clone-block-performance-*.log + clones/js-tests/temp/clone-block-performance-*.json + clones/js-tests/temp/clone-block-diagnostics-*.log + clones/js-tests/temp/runtime-upgrade-*.json + clones/js-tests/temp/clone-readiness-*.log + clones/js-tests/temp/clone-readiness-*.json + if-no-files-found: warn + retention-days: 14 + # Branch protection requires a check named exactly "Sudo-upgrade mainnet # clone and test"; this fan-in preserves the required-check name. It passes # when the clone job succeeded, or when the whole suite legitimately skipped diff --git a/.github/workflows/validate-sccache.yml b/.github/workflows/validate-sccache.yml index 72c10e1250..9e80c6afec 100644 --- a/.github/workflows/validate-sccache.yml +++ b/.github/workflows/validate-sccache.yml @@ -41,6 +41,7 @@ on: - ".github/workflows/check-node-compat.yml" - ".github/workflows/mainnet-clone-preview.yml" - ".github/workflows/runtime-checks.yml" + - ".github/workflows/refresh-mainnet-snapshot.yml" - ".github/workflows/sccache-warm.yml" - ".github/workflows/typescript-e2e.yml" - ".github/workflows/validate-sccache.yml" diff --git a/clones/js-tests/lib/clone-invariants.ts b/clones/js-tests/lib/clone-invariants.ts new file mode 100644 index 0000000000..39ef40488b --- /dev/null +++ b/clones/js-tests/lib/clone-invariants.ts @@ -0,0 +1,37 @@ +import type { ApiPromise } from "@polkadot/api"; + +export interface IssuanceMirror { + balancesTotalIssuance: bigint; + subtensorTotalIssuance: bigint; +} + +export async function readIssuanceMirror( + api: ApiPromise, + hash?: Parameters[0], +): Promise { + const query = hash === undefined ? api.query : (await api.at(hash)).query; + const [balances, subtensor] = await Promise.all([ + query.balances.totalIssuance(), + query.subtensorModule.totalIssuance(), + ]); + return { + balancesTotalIssuance: BigInt(balances.toString()), + subtensorTotalIssuance: BigInt(subtensor.toString()), + }; +} + +export function assertIssuanceMirror(invariant: IssuanceMirror, label: string) { + if (invariant.balancesTotalIssuance !== invariant.subtensorTotalIssuance) { + throw new Error( + `${label}: Balances.TotalIssuance ${invariant.balancesTotalIssuance} does not match ` + + `SubtensorModule.TotalIssuance ${invariant.subtensorTotalIssuance}`, + ); + } +} + +export function serializeIssuanceMirror(invariant: IssuanceMirror) { + return { + balancesTotalIssuance: invariant.balancesTotalIssuance.toString(), + subtensorTotalIssuance: invariant.subtensorTotalIssuance.toString(), + }; +} diff --git a/clones/js-tests/lib/clone-performance.ts b/clones/js-tests/lib/clone-performance.ts new file mode 100644 index 0000000000..cfa73347bc --- /dev/null +++ b/clones/js-tests/lib/clone-performance.ts @@ -0,0 +1,538 @@ +import fs from "node:fs"; + +export const DEFAULT_BLOCK_WARNING_MS = 2_000; +export const DEFAULT_BLOCK_FAILURE_MS = 4_000; +export const DEFAULT_HEAD_WARNING_MS = 4_000; +export const DEFAULT_HEAD_VIOLATION_MS = 12_000; +export const DEFAULT_HEAD_TIMEOUT_MS = 12_000; +export const COLLECT_HEAD_TIMEOUT_MS = 120_000; +export const DEFAULT_MIN_BLOCK_SAMPLES = 20; +export const DEFAULT_SAMPLE_DRAIN_TIMEOUT_MS = 120_000; +export const ACCELERATED_SEALING_MS = 250; + +export function remainingRequiredBlockSamples( + observedSamples: number, + minimumSamples = DEFAULT_MIN_BLOCK_SAMPLES, +): number { + if (!Number.isInteger(observedSamples) || observedSamples < 0) { + throw new Error(`invalid observed block samples: ${observedSamples}`); + } + if (!Number.isInteger(minimumSamples) || minimumSamples < 1) { + throw new Error(`invalid minimum block samples: ${minimumSamples}`); + } + return Math.max(0, minimumSamples - observedSamples); +} + +export function sampleDrainFailureReason( + observedSamples: number, + elapsedMs: number, + minimumSamples = DEFAULT_MIN_BLOCK_SAMPLES, + timeoutMs = DEFAULT_SAMPLE_DRAIN_TIMEOUT_MS, +): string | undefined { + const missingSamples = remainingRequiredBlockSamples(observedSamples, minimumSamples); + if (!Number.isFinite(elapsedMs) || elapsedMs < 0) { + throw new Error(`invalid sample drain elapsed time: ${elapsedMs}`); + } + if (!Number.isFinite(timeoutMs) || timeoutMs <= 0) { + throw new Error(`invalid sample drain timeout: ${timeoutMs}`); + } + if (missingSamples === 0 || elapsedMs < timeoutMs) { + return undefined; + } + return ( + `expected proposer log format produced ${observedSamples} sample(s); ` + + `required ${minimumSamples} within ${timeoutMs}ms after the workload completed` + ); +} + +export interface BlockConstructionSample { + block: number; + durationMs: number; +} + +export interface ParsedBlockChunk { + remainder: string; + samples: BlockConstructionSample[]; +} + +export function postUpgradeBlockSamples( + samples: readonly BlockConstructionSample[], + upgradeBlock: number, +): BlockConstructionSample[] { + if (!Number.isSafeInteger(upgradeBlock) || upgradeBlock < 0) { + throw new Error(`invalid runtime upgrade block: ${upgradeBlock}`); + } + return samples.filter(({ block }) => block > upgradeBlock); +} + +export interface BlockLatencySummary { + sampleCount: number; + meanMs: number | null; + maximumMs: number | null; + p50Ms: number | null; + p95Ms: number | null; + p99Ms: number | null; + warnings: BlockConstructionSample[]; + violations: BlockConstructionSample[]; + slowestBlocks: BlockConstructionSample[]; +} + +export interface BestHeadStall { + afterBlock: number; + warnedAtMs: number; + violatedAtMs: number | null; + endedAtMs: number | null; + outcome: "active" | "recovered" | "aborted"; + durationMs: number; +} + +export type LivenessTick = + | { kind: "healthy" } + | { kind: "warning"; stall: BestHeadStall } + | { kind: "violation"; stall: BestHeadStall } + | { kind: "abort"; stall: BestHeadStall }; + +export interface EpochBaseline { + netuid: number; + tempo: number; + epochIndex: bigint; + lastSuccessfulEpochBlock: bigint; +} + +export interface EpochProgress extends EpochBaseline { + currentEpochIndex: bigint; + currentSuccessfulEpochBlock: bigint; + attemptedCycles: bigint; + completedCycles: bigint; +} + +export interface EpochCoverageEvaluation { + complete: boolean; + progress: EpochProgress[]; + removedNetuids: number[]; + missingNetuids: number[]; + regressedNetuids: number[]; + skippedNetuids: number[]; +} + +export interface EpochCoverageBudget { + activeSubnets: number; + maxTempo: number; + maxEpochsPerBlock: number; + schedulingBlocksPerCycle: number; + unpaddedBlocks: number; + blockBudget: number; + nominalWallMs: number; +} + +export class SuccessfulEpochTracker { + private readonly previousBlocks = new Map(); + private readonly completedCycles = new Map(); + private readonly sourceHeightPending = new Set(); + private readonly baselineBlock: bigint; + + constructor(baseline: readonly EpochBaseline[], baselineBlock: number) { + if (!Number.isSafeInteger(baselineBlock) || baselineBlock < 0) { + throw new Error(`invalid epoch coverage baseline block: ${baselineBlock}`); + } + this.baselineBlock = BigInt(baselineBlock); + for (const { netuid, lastSuccessfulEpochBlock } of baseline) { + this.previousBlocks.set(netuid, lastSuccessfulEpochBlock); + this.completedCycles.set(netuid, 0n); + // A cloned snapshot retains mainnet block numbers in this storage item, + // while the clone itself starts near block zero. Its first successful + // local epoch therefore performs one legitimate coordinate-system reset. + if (lastSuccessfulEpochBlock > this.baselineBlock) { + this.sourceHeightPending.add(netuid); + } + } + } + + observe( + currentBlocks: ReadonlyMap, + observedAtBlock: number, + ): ReadonlyMap { + if (!Number.isSafeInteger(observedAtBlock) || BigInt(observedAtBlock) < this.baselineBlock) { + throw new Error(`invalid successful epoch observation block: ${observedAtBlock}`); + } + const observedAt = BigInt(observedAtBlock); + for (const [netuid, previousBlock] of this.previousBlocks) { + const currentBlock = currentBlocks.get(netuid); + if (currentBlock === undefined) { + continue; + } + if (currentBlock === previousBlock) { + continue; + } + const validLocalSuccess = + currentBlock > this.baselineBlock && currentBlock <= observedAt; + const validSourceHeightReset = + currentBlock < previousBlock && this.sourceHeightPending.has(netuid); + if (!validLocalSuccess || (currentBlock < previousBlock && !validSourceHeightReset)) { + throw new Error( + `successful epoch block regressed for subnet ${netuid}: ${previousBlock} to ${currentBlock}`, + ); + } + this.sourceHeightPending.delete(netuid); + this.previousBlocks.set(netuid, currentBlock); + this.completedCycles.set(netuid, (this.completedCycles.get(netuid) ?? 0n) + 1n); + } + return new Map(this.completedCycles); + } +} + +export function assertReliableEpochPollingGap( + previousBlock: number, + currentBlock: number, + minimumTempo: number, +): number { + if (![previousBlock, currentBlock, minimumTempo].every(Number.isSafeInteger)) { + throw new Error("epoch polling blocks and tempo must be safe integers"); + } + const gap = currentBlock - previousBlock; + if (gap < 0) { + throw new Error(`epoch polling block regressed from ${previousBlock} to ${currentBlock}`); + } + if (minimumTempo < 1 || gap >= minimumTempo) { + throw new Error( + `epoch coverage polling skipped ${gap} blocks, which is not strictly below ` + + `the minimum subnet tempo ${minimumTempo}`, + ); + } + return gap; +} + +export class NodeLogTail { + private position: number; + private remainder = ""; + + constructor( + private readonly filename: string, + startOffset: number, + ) { + const size = fs.statSync(filename).size; + if (startOffset < 0 || startOffset > size) { + throw new Error(`invalid node log offset ${startOffset}; ${filename} is ${size} bytes`); + } + this.position = startOffset; + } + + read(flush = false): BlockConstructionSample[] { + const size = fs.statSync(this.filename).size; + if (size < this.position) { + throw new Error(`node log was truncated from ${this.position} to ${size} bytes`); + } + + let chunk = ""; + if (size > this.position) { + const length = size - this.position; + const buffer = Buffer.alloc(length); + const descriptor = fs.openSync(this.filename, "r"); + try { + fs.readSync(descriptor, buffer, 0, length, this.position); + } finally { + fs.closeSync(descriptor); + } + this.position = size; + chunk = buffer.toString("utf8"); + } + + const parsed = parsePreparedBlockChunk(this.remainder, chunk, flush); + this.remainder = parsed.remainder; + return parsed.samples; + } +} + +const PREPARED_BLOCK_PATTERN = /Prepared block for proposing at\s+#?(\d+)\s+\((\d+)\s*ms\)/; + +export function parsePreparedBlockChunk( + remainder: string, + chunk: string, + flush = false, +): ParsedBlockChunk { + const lines = `${remainder}${chunk}`.split(/\r?\n/); + const nextRemainder = flush ? "" : (lines.pop() ?? ""); + const samples: BlockConstructionSample[] = []; + + for (const line of lines) { + const match = PREPARED_BLOCK_PATTERN.exec(line); + if (match === null) { + continue; + } + samples.push({ + block: Number.parseInt(match[1], 10), + durationMs: Number.parseInt(match[2], 10), + }); + } + + return { remainder: nextRemainder, samples }; +} + +export function summarizeBlockSamples( + samples: readonly BlockConstructionSample[], + warningMs = DEFAULT_BLOCK_WARNING_MS, + failureMs = DEFAULT_BLOCK_FAILURE_MS, +): BlockLatencySummary { + const byDuration = [...samples].sort((left, right) => left.durationMs - right.durationMs); + const warnings = samples.filter( + ({ durationMs }) => durationMs >= warningMs && durationMs < failureMs, + ); + const violations = samples.filter(({ durationMs }) => durationMs >= failureMs); + const slowestBlocks = [...samples] + .sort((left, right) => right.durationMs - left.durationMs || left.block - right.block) + .slice(0, 20); + + return { + sampleCount: samples.length, + meanMs: + samples.length === 0 + ? null + : Math.round( + (samples.reduce((total, { durationMs }) => total + durationMs, 0) / samples.length) * + 10, + ) / 10, + maximumMs: byDuration.at(-1)?.durationMs ?? null, + p50Ms: percentile(byDuration, 50), + p95Ms: percentile(byDuration, 95), + p99Ms: percentile(byDuration, 99), + warnings, + violations, + slowestBlocks, + }; +} + +export function blockLatencyFailureReasons( + summary: BlockLatencySummary, + minimumSamples: number, + failureMs = DEFAULT_BLOCK_FAILURE_MS, +): string[] { + const reasons: string[] = []; + const missingSamples = remainingRequiredBlockSamples(summary.sampleCount, minimumSamples); + if (missingSamples > 0) { + reasons.push(`observed ${summary.sampleCount} proposer samples; required at least ${minimumSamples}`); + } + if (summary.violations.length > 0) { + reasons.push(`${summary.violations.length} block(s) met or exceeded ${failureMs}ms`); + } + return reasons; +} + +export class BestHeadLiveness { + private lastBlock: number | undefined; + private lastObservedAtMs: number | undefined; + private activeStall: BestHeadStall | undefined; + private readonly completedStalls: BestHeadStall[] = []; + + constructor( + readonly warningMs = DEFAULT_HEAD_WARNING_MS, + readonly violationMs = DEFAULT_HEAD_VIOLATION_MS, + readonly timeoutMs = DEFAULT_HEAD_TIMEOUT_MS, + ) { + if (!(warningMs > 0 && violationMs > warningMs && timeoutMs >= violationMs)) { + throw new Error( + `invalid best-head thresholds: warning=${warningMs} violation=${violationMs} ` + + `timeout=${timeoutMs}`, + ); + } + } + + observe(block: number, nowMs: number): BestHeadStall | undefined { + if (this.lastBlock !== undefined && block < this.lastBlock) { + throw new Error(`best head regressed from ${this.lastBlock} to ${block}`); + } + if (this.lastBlock === block) { + return undefined; + } + + let recovered: BestHeadStall | undefined; + if (this.activeStall !== undefined && this.lastObservedAtMs !== undefined) { + this.activeStall.endedAtMs = nowMs; + this.activeStall.outcome = "recovered"; + this.activeStall.durationMs = nowMs - this.lastObservedAtMs; + recovered = { ...this.activeStall }; + this.completedStalls.push(recovered); + this.activeStall = undefined; + } + + this.lastBlock = block; + this.lastObservedAtMs = nowMs; + return recovered; + } + + tick(nowMs: number): LivenessTick { + if (this.lastBlock === undefined || this.lastObservedAtMs === undefined) { + return { kind: "healthy" }; + } + + const durationMs = nowMs - this.lastObservedAtMs; + if (durationMs < this.warningMs) { + return { kind: "healthy" }; + } + + if (this.activeStall === undefined) { + this.activeStall = { + afterBlock: this.lastBlock, + warnedAtMs: nowMs, + violatedAtMs: null, + endedAtMs: null, + outcome: "active", + durationMs, + }; + if (durationMs < this.violationMs) { + return { kind: "warning", stall: { ...this.activeStall } }; + } + } else { + this.activeStall.durationMs = durationMs; + } + + if (durationMs >= this.timeoutMs) { + this.activeStall.endedAtMs = nowMs; + this.activeStall.outcome = "aborted"; + return { kind: "abort", stall: { ...this.activeStall } }; + } + if (durationMs >= this.violationMs && this.activeStall.violatedAtMs === null) { + this.activeStall.violatedAtMs = nowMs; + return { kind: "violation", stall: { ...this.activeStall } }; + } + return { kind: "healthy" }; + } + + getLastBlock(): number | undefined { + return this.lastBlock; + } + + getStalls(nowMs = Date.now()): BestHeadStall[] { + const result = this.completedStalls.map((stall) => ({ ...stall })); + if (this.activeStall !== undefined && this.lastObservedAtMs !== undefined) { + result.push({ + ...this.activeStall, + durationMs: Math.max(this.activeStall.durationMs, nowMs - this.lastObservedAtMs), + }); + } + return result; + } +} + +export function bestHeadFailureReasons( + stalls: readonly BestHeadStall[], + violationMs = DEFAULT_HEAD_VIOLATION_MS, +): string[] { + const violations = stalls.filter(({ durationMs }) => durationMs >= violationMs); + return violations.length === 0 + ? [] + : [`${violations.length} best-head stall(s) met or exceeded ${violationMs}ms`]; +} + +export function evaluateEpochCoverage( + baseline: readonly EpochBaseline[], + currentEpochIndices: ReadonlyMap, + currentSuccessfulEpochBlocks: ReadonlyMap, + successfulCycles: ReadonlyMap, + activeNetuids: ReadonlySet, + requiredCycles: number, +): EpochCoverageEvaluation { + if (!Number.isInteger(requiredCycles) || requiredCycles < 1) { + throw new Error(`invalid required epoch cycles: ${requiredCycles}`); + } + + const progress: EpochProgress[] = []; + const removedNetuids: number[] = []; + const missingNetuids: number[] = []; + const regressedNetuids: number[] = []; + const skippedNetuids: number[] = []; + + for (const subnet of baseline) { + if (!activeNetuids.has(subnet.netuid)) { + removedNetuids.push(subnet.netuid); + } + const currentEpochIndex = currentEpochIndices.get(subnet.netuid); + const currentSuccessfulEpochBlock = currentSuccessfulEpochBlocks.get(subnet.netuid); + const completedCycles = successfulCycles.get(subnet.netuid); + if ( + currentEpochIndex === undefined || + currentSuccessfulEpochBlock === undefined || + completedCycles === undefined + ) { + missingNetuids.push(subnet.netuid); + continue; + } + if (currentEpochIndex < subnet.epochIndex) { + regressedNetuids.push(subnet.netuid); + } + const attemptedCycles = + currentEpochIndex >= subnet.epochIndex ? currentEpochIndex - subnet.epochIndex : 0n; + if (attemptedCycles > completedCycles) { + skippedNetuids.push(subnet.netuid); + } + progress.push({ + ...subnet, + currentEpochIndex, + currentSuccessfulEpochBlock, + attemptedCycles, + completedCycles, + }); + } + + return { + complete: + removedNetuids.length === 0 && + missingNetuids.length === 0 && + regressedNetuids.length === 0 && + skippedNetuids.length === 0 && + progress.length === baseline.length && + progress.every(({ completedCycles }) => completedCycles >= BigInt(requiredCycles)), + progress, + removedNetuids, + missingNetuids, + regressedNetuids, + skippedNetuids, + }; +} + +export function computeEpochCoverageBudget( + baseline: readonly EpochBaseline[], + requiredCycles: number, + maxEpochsPerBlock: number, + margin = 0.1, +): EpochCoverageBudget { + if (baseline.length === 0) { + throw new Error("cannot calculate epoch coverage for an empty subnet baseline"); + } + if (!Number.isInteger(requiredCycles) || requiredCycles < 1) { + throw new Error(`invalid required epoch cycles: ${requiredCycles}`); + } + if (!Number.isInteger(maxEpochsPerBlock) || maxEpochsPerBlock < 1) { + throw new Error(`invalid MaxEpochsPerBlock: ${maxEpochsPerBlock}`); + } + if (!(margin >= 0 && margin <= 1)) { + throw new Error(`invalid epoch coverage margin: ${margin}`); + } + for (const { netuid, tempo } of baseline) { + if (!Number.isInteger(tempo) || tempo < 1) { + throw new Error(`invalid tempo ${tempo} for subnet ${netuid}`); + } + } + + const maxTempo = Math.max(...baseline.map(({ tempo }) => tempo)); + const schedulingBlocksPerCycle = Math.ceil(baseline.length / maxEpochsPerBlock); + const unpaddedBlocks = requiredCycles * (maxTempo + schedulingBlocksPerCycle); + const blockBudget = Math.ceil(unpaddedBlocks * (1 + margin)); + + return { + activeSubnets: baseline.length, + maxTempo, + maxEpochsPerBlock, + schedulingBlocksPerCycle, + unpaddedBlocks, + blockBudget, + nominalWallMs: blockBudget * ACCELERATED_SEALING_MS, + }; +} + +function percentile(sorted: readonly BlockConstructionSample[], value: number): number | null { + if (sorted.length === 0) { + return null; + } + const index = Math.max(0, Math.ceil((value / 100) * sorted.length) - 1); + return sorted[index].durationMs; +} diff --git a/clones/js-tests/lib/clone-readiness.ts b/clones/js-tests/lib/clone-readiness.ts new file mode 100644 index 0000000000..74b3ad6e99 --- /dev/null +++ b/clones/js-tests/lib/clone-readiness.ts @@ -0,0 +1,270 @@ +import type { ApiPromise } from "@polkadot/api"; +import { xxhashAsHex } from "@polkadot/util-crypto"; + +// Release-v438/PR #3019 gate. This is intentionally not a generic migration +// detector: future multi-block migrations must add their own explicit gate. +const MIGRATION_NAME = "migrate_seed_beta_basket_v2"; +const CURSOR_STORAGE_ITEM = "SeedBetaBasketV2Migration"; +const DEFERRED_STORAGE_ITEMS = ["DeferredRootAlphaDividends"] as const; + +export interface BetaBasketV2ReadinessSnapshot { + cursorExists: boolean; + completionFlag: boolean; + deferredEntriesExist: boolean; +} + +export interface BetaBasketV2ReadinessHistory { + sawCursor: boolean; + sawDeferredEntries: boolean; +} + +export type BetaBasketV2ReadinessEvaluation = + | { kind: "not-observed"; history: BetaBasketV2ReadinessHistory } + | { + kind: "waiting"; + stage: "migration" | "deferred-release"; + history: BetaBasketV2ReadinessHistory; + } + | { kind: "ready"; history: BetaBasketV2ReadinessHistory } + | { kind: "invalid"; history: BetaBasketV2ReadinessHistory; reason: string }; + +export interface BetaBasketV2ReadinessObservation extends BetaBasketV2ReadinessHistory { + descriptor: string; + mode: "not-observed" | "cursorless-complete" | "multi-block"; + startBlock: number; + cursorCompletionBlock: number | null; + readinessBlock: number; + observedBlocks: number; + observedWallMs: number; +} + +export interface WaitForBetaBasketV2ReadinessOptions { + deadlineEpochMs: number; + pollIntervalMs?: number; + log?: (message: string) => void; +} + +const EMPTY_HISTORY: BetaBasketV2ReadinessHistory = { + sawCursor: false, + sawDeferredEntries: false, +}; + +export function evaluateBetaBasketV2Readiness( + snapshot: BetaBasketV2ReadinessSnapshot, + previous: BetaBasketV2ReadinessHistory = EMPTY_HISTORY, +): BetaBasketV2ReadinessEvaluation { + const history = { + sawCursor: previous.sawCursor || snapshot.cursorExists, + sawDeferredEntries: previous.sawDeferredEntries || snapshot.deferredEntriesExist, + }; + + if (snapshot.cursorExists && snapshot.completionFlag) { + return { + kind: "invalid", + history, + reason: "migration cursor and completion flag both exist", + }; + } + if ( + !snapshot.cursorExists && + !snapshot.completionFlag && + !snapshot.deferredEntriesExist && + !history.sawCursor && + !history.sawDeferredEntries + ) { + return { kind: "not-observed", history }; + } + if (previous.sawCursor && !snapshot.cursorExists && !snapshot.completionFlag) { + return { + kind: "invalid", + history, + reason: "migration cursor disappeared without its completion flag", + }; + } + if (!snapshot.cursorExists && !snapshot.completionFlag && snapshot.deferredEntriesExist) { + return { + kind: "invalid", + history, + reason: "deferred migration work exists without a cursor or completion flag", + }; + } + if (snapshot.cursorExists) { + return { kind: "waiting", stage: "migration", history }; + } + if (!snapshot.completionFlag) { + return { + kind: "invalid", + history, + reason: "observed migration state has no completion flag", + }; + } + if (snapshot.deferredEntriesExist) { + return { kind: "waiting", stage: "deferred-release", history }; + } + return { kind: "ready", history }; +} + +export async function waitForBetaBasketV2ReleaseReadiness( + api: ApiPromise, + options: WaitForBetaBasketV2ReadinessOptions, +): Promise { + const pollIntervalMs = options.pollIntervalMs ?? 1_000; + const log = options.log ?? (() => undefined); + if (!Number.isSafeInteger(options.deadlineEpochMs) || options.deadlineEpochMs <= Date.now()) { + throw new Error(`invalid migration readiness deadline: ${options.deadlineEpochMs}`); + } + if (!Number.isSafeInteger(pollIntervalMs) || pollIntervalMs < 1) { + throw new Error(`invalid migration readiness poll interval: ${pollIntervalMs}`); + } + + const startedAtEpochMs = Date.now(); + const start = await bestHeader(api); + let header = start; + let lastBlock = start.block; + let lastReportedBlock = start.block - 50; + let history = EMPTY_HISTORY; + let cursorCompletionBlock: number | null = null; + + for (;;) { + ensureDeadline(options.deadlineEpochMs, MIGRATION_NAME); + if (header.block < lastBlock) { + throw new Error(`best block regressed from ${lastBlock} to ${header.block}`); + } + lastBlock = header.block; + + const snapshot = await readMigrationSnapshot(api, header.hash); + const evaluation = evaluateBetaBasketV2Readiness(snapshot, history); + history = evaluation.history; + if (!snapshot.cursorExists && snapshot.completionFlag && cursorCompletionBlock === null) { + cursorCompletionBlock = header.block; + } + + if (evaluation.kind === "invalid") { + throw new Error(`${MIGRATION_NAME}: ${evaluation.reason} at block ${header.block}`); + } + if (evaluation.kind === "not-observed") { + log( + `No ${MIGRATION_NAME} cursor, completion marker, or deferred work observed after ` + + "the runtime upgrade; continuing immediately.", + ); + return observation( + "not-observed", + start.block, + header.block, + cursorCompletionBlock, + history, + startedAtEpochMs, + ); + } + if (evaluation.kind === "ready") { + const mode = history.sawCursor ? "multi-block" : "cursorless-complete"; + log( + `${MIGRATION_NAME} ready at block ${header.block}; mode=${mode} ` + + `cursor_completion=${cursorCompletionBlock ?? "not-observed"} ` + + `deferred_release_observed=${history.sawDeferredEntries}`, + ); + return observation( + mode, + start.block, + header.block, + cursorCompletionBlock, + history, + startedAtEpochMs, + ); + } + if (header.block >= lastReportedBlock + 50 || header.block === start.block) { + lastReportedBlock = header.block; + log( + `Waiting for ${MIGRATION_NAME}: block=${header.block} stage=${evaluation.stage} ` + + `cursor=${snapshot.cursorExists} completed=${snapshot.completionFlag} ` + + `deferred=${snapshot.deferredEntriesExist}`, + ); + } + await delay(pollIntervalMs); + header = await bestHeader(api); + } +} + +async function readMigrationSnapshot( + api: ApiPromise, + hash: string, +): Promise { + const [cursorExists, completionFlag, deferredEntries] = await Promise.all([ + storageValueExistsAt(api, storagePrefix(CURSOR_STORAGE_ITEM), hash), + hasMigrationRunAt(api, MIGRATION_NAME, hash), + Promise.all( + DEFERRED_STORAGE_ITEMS.map((item) => + storageEntriesExistAt(api, storagePrefix(item), hash), + ), + ), + ]); + return { + cursorExists, + completionFlag, + deferredEntriesExist: deferredEntries.some(Boolean), + }; +} + +async function hasMigrationRunAt(api: ApiPromise, name: string, hash: string): Promise { + const at = await api.at(hash); + const value = await at.query.subtensorModule.hasMigrationRun([...Buffer.from(name)]); + return value.toString() === "true"; +} + +async function storageValueExistsAt(api: ApiPromise, key: string, hash: string): Promise { + const value = await api.rpc.state.getStorage(key, hash); + if (value === null || typeof value !== "object" || !("isSome" in value)) { + throw new Error(`unexpected storage response for ${key}`); + } + return value.isSome === true; +} + +async function storageEntriesExistAt( + api: ApiPromise, + prefix: string, + hash: string, +): Promise { + const keys = await api.rpc.state.getKeysPaged(prefix, 1, prefix, hash); + return keys.length > 0; +} + +async function bestHeader(api: ApiPromise): Promise<{ block: number; hash: string }> { + const header = await api.rpc.chain.getHeader(); + return { block: header.number.toNumber(), hash: header.hash.toHex() }; +} + +function observation( + mode: BetaBasketV2ReadinessObservation["mode"], + startBlock: number, + readinessBlock: number, + cursorCompletionBlock: number | null, + history: BetaBasketV2ReadinessHistory, + startedAtEpochMs: number, +): BetaBasketV2ReadinessObservation { + return { + descriptor: MIGRATION_NAME, + mode, + ...history, + startBlock, + cursorCompletionBlock, + readinessBlock, + observedBlocks: Math.max(0, readinessBlock - startBlock), + observedWallMs: Date.now() - startedAtEpochMs, + }; +} + +function storagePrefix(item: string): string { + return `${xxhashAsHex("SubtensorModule", 128)}${xxhashAsHex(item, 128).slice(2)}`; +} + +function ensureDeadline(deadlineEpochMs: number, migrationName: string) { + if (Date.now() >= deadlineEpochMs) { + throw new Error( + `${migrationName} readiness deadline ${new Date(deadlineEpochMs).toISOString()} was reached`, + ); + } +} + +function delay(milliseconds: number): Promise { + return new Promise((resolve) => setTimeout(resolve, milliseconds)); +} diff --git a/clones/js-tests/package.json b/clones/js-tests/package.json index a554fe8372..6207afdfc4 100644 --- a/clones/js-tests/package.json +++ b/clones/js-tests/package.json @@ -3,6 +3,10 @@ "scripts": { "test": "tsx tests/clone-smoke-test.ts", "typecheck": "tsc --noEmit", + "test:clone-performance": "bash -o pipefail -c 'node --import tsx --test tests/clone-performance.test.ts 2>&1 | tee temp/clone-performance-unit.log'", + "monitor:block-latency": "tsx scripts/monitor-clone-blocks.ts", + "wait:beta-basket-v2-readiness": "tsx scripts/wait-clone-readiness.ts", + "soak:epochs": "tsx scripts/run-clone-epoch-soak.ts", "test:clone-regressions": "tsx scripts/run-clone-regressions.ts", "runtime:update:alice": "tsx scripts/update-runtime-with-alice.ts", "test:balancer-operation": "tsx tests/test-balancer-operation.ts", diff --git a/clones/js-tests/scripts/monitor-clone-blocks.ts b/clones/js-tests/scripts/monitor-clone-blocks.ts new file mode 100644 index 0000000000..1dbc9d882d --- /dev/null +++ b/clones/js-tests/scripts/monitor-clone-blocks.ts @@ -0,0 +1,690 @@ +import fs from "node:fs"; +import path from "node:path"; +import { createInterface } from "node:readline"; +import { parseArgs } from "node:util"; +import { connectApi } from "../lib/api.js"; +import { + DEFAULT_BLOCK_FAILURE_MS, + DEFAULT_BLOCK_WARNING_MS, + COLLECT_HEAD_TIMEOUT_MS, + DEFAULT_HEAD_TIMEOUT_MS, + DEFAULT_HEAD_VIOLATION_MS, + DEFAULT_HEAD_WARNING_MS, + DEFAULT_MIN_BLOCK_SAMPLES, + DEFAULT_SAMPLE_DRAIN_TIMEOUT_MS, + BestHeadLiveness, + NodeLogTail, + bestHeadFailureReasons, + blockLatencyFailureReasons, + parsePreparedBlockChunk, + postUpgradeBlockSamples, + remainingRequiredBlockSamples, + sampleDrainFailureReason, + summarizeBlockSamples, + type BlockConstructionSample, +} from "../lib/clone-performance.js"; +import { createTempLogger } from "../lib/file-log.js"; + +type MonitorPolicy = "fail-fast" | "collect" | "baseline"; + +const MONITOR_POLICIES: Record< + MonitorPolicy, + { + failImmediatelyOnLatency: boolean; + enforceLatency: boolean; + enforceStalls: boolean; + headTimeoutMs: number; + } +> = { + "fail-fast": { + failImmediatelyOnLatency: true, + enforceLatency: true, + enforceStalls: true, + headTimeoutMs: DEFAULT_HEAD_TIMEOUT_MS, + }, + collect: { + failImmediatelyOnLatency: false, + enforceLatency: true, + enforceStalls: true, + headTimeoutMs: COLLECT_HEAD_TIMEOUT_MS, + }, + baseline: { + failImmediatelyOnLatency: false, + enforceLatency: false, + enforceStalls: false, + headTimeoutMs: COLLECT_HEAD_TIMEOUT_MS, + }, +}; + +interface RuntimeUpgradeActivation { + upgradeBlock: number; + finalizedAtEpochMs: number; +} + +interface MonitorArguments { + policy: MonitorPolicy; + nodeLog: string; + startOffset: number; + reportFile: string; + logName: string; + activationReport?: string; + readyFile?: string; + baselineReport?: string; + diagnosticFile?: string; +} + +interface MonitorReport { + schemaVersion: 2; + status: "passed" | "failed"; + policy: MonitorPolicy; + startedAt: string; + finishedAt: string; + nodeLog: string; + startOffset: number; + activation: RuntimeUpgradeActivation | null; + thresholds: { + blockWarningMs: number; + blockFailureMs: number; + headWarningMs: number; + headViolationMs: number; + headTimeoutMs: number; + minimumSamples: number; + sampleDrainTimeoutMs: number; + }; + bestHead: { + lastBlock: number | null; + stalls: ReturnType; + }; + latency: ReturnType; + baselineComparison: LatencyComparison | null; + diagnosticFile: string | null; + failureReasons: string[]; +} + +interface LatencyComparison { + baselineSamples: number; + currentSamples: number; + meanMs: MetricComparison; + p50Ms: MetricComparison; + p95Ms: MetricComparison; + p99Ms: MetricComparison; + maximumMs: MetricComparison; +} + +interface MetricComparison { + baseline: number | null; + current: number | null; + deltaMs: number | null; + ratio: number | null; +} + +async function main() { + const args = parseArguments(process.argv.slice(2)); + const logger = createTempLogger(args.logName); + await logger.start(); + logger.captureConsole(); + + const startedAt = new Date(); + const samples: BlockConstructionSample[] = []; + const pendingSamples: BlockConstructionSample[] = []; + const pendingHeads: Array<{ block: number; observedAtMs: number }> = []; + const failureReasons: string[] = []; + const tail = new NodeLogTail(args.nodeLog, args.startOffset); + const policy = MONITOR_POLICIES[args.policy]; + const headTimeoutMs = policy.headTimeoutMs; + const liveness = new BestHeadLiveness( + DEFAULT_HEAD_WARNING_MS, + DEFAULT_HEAD_VIOLATION_MS, + headTimeoutMs, + ); + let shutdownRequested = false; + let shutdownRequestedAtMs: number | undefined; + let shutdownNoticePrinted = false; + let disconnecting = false; + let fatalError: Error | undefined; + let activation: RuntimeUpgradeActivation | undefined; + let activated = args.activationReport === undefined; + let api; + let unsubscribe: (() => void) | undefined; + + const requestStop = () => { + shutdownRequested = true; + shutdownRequestedAtMs ??= Date.now(); + }; + process.once("SIGINT", requestStop); + process.once("SIGTERM", requestStop); + + const acceptSamples = (newSamples: BlockConstructionSample[]) => { + for (const sample of newSamples) { + samples.push(sample); + if (sample.durationMs >= DEFAULT_BLOCK_FAILURE_MS) { + const message = + `block ${sample.block} construction took ${sample.durationMs}ms ` + + `(limit ${DEFAULT_BLOCK_FAILURE_MS}ms)`; + console.error(`LATENCY VIOLATION: ${message}`); + if (policy.failImmediatelyOnLatency && fatalError === undefined) { + fatalError = new Error(message); + } + } else if (sample.durationMs >= DEFAULT_BLOCK_WARNING_MS) { + console.log( + `LATENCY WARNING: block ${sample.block} construction took ${sample.durationMs}ms`, + ); + } + } + }; + + const observeHead = (block: number, observedAtMs: number) => { + const recovered = liveness.observe(block, observedAtMs); + if (recovered !== undefined) { + console.log( + `BEST HEAD RECOVERED: block ${block} after ${recovered.durationMs}ms`, + ); + } + }; + + const activate = (value: RuntimeUpgradeActivation) => { + activation = value; + activated = true; + const boundary = pendingHeads.find(({ block }) => block === value.upgradeBlock); + observeHead(value.upgradeBlock, boundary?.observedAtMs ?? value.finalizedAtEpochMs); + for (const observation of pendingHeads) { + if (observation.block > value.upgradeBlock) { + observeHead(observation.block, observation.observedAtMs); + } + } + acceptSamples(postUpgradeBlockSamples(pendingSamples, value.upgradeBlock)); + pendingHeads.length = 0; + pendingSamples.length = 0; + console.log(`Block monitor activated after runtime upgrade block ${value.upgradeBlock}.`); + }; + + try { + console.log( + `Starting clone block monitor policy=${args.policy} node_log=${args.nodeLog} ` + + `offset=${args.startOffset}`, + ); + api = await connectApi(process.env.WS_ENDPOINT ?? "ws://127.0.0.1:9944", { + log: (message) => console.log(message), + }); + + const initialHeader = await api.rpc.chain.getHeader(); + if (activated) { + observeHead(initialHeader.number.toNumber(), Date.now()); + } else { + pendingHeads.push({ block: initialHeader.number.toNumber(), observedAtMs: Date.now() }); + } + console.log(`Initial best block: ${initialHeader.number.toNumber()}`); + + const markRpcFailure = (value: unknown) => { + if (disconnecting || fatalError !== undefined) { + return; + } + fatalError = value instanceof Error ? value : new Error(String(value)); + }; + api.on("disconnected", () => markRpcFailure(new Error("clone RPC disconnected"))); + api.on("error", markRpcFailure); + + unsubscribe = await api.rpc.chain.subscribeNewHeads((header) => { + try { + const observation = { block: header.number.toNumber(), observedAtMs: Date.now() }; + if (activated) { + observeHead(observation.block, observation.observedAtMs); + } else { + pendingHeads.push(observation); + } + } catch (error) { + markRpcFailure(error); + } + }); + if (args.readyFile) { + writeJson(args.readyFile, { + schemaVersion: 1, + readyAt: new Date().toISOString(), + initialBestBlock: initialHeader.number.toNumber(), + }); + } + + while (fatalError === undefined) { + const newSamples = tail.read(); + if (activated) { + acceptSamples(newSamples); + } else { + pendingSamples.push(...newSamples); + const discovered = readActivationReport(args.activationReport); + if (discovered !== undefined) { + activate(discovered); + } + } + if (fatalError !== undefined) { + break; + } + + if (!activated) { + if (shutdownRequested) { + fatalError = new Error("block monitor stopped before runtime upgrade activation"); + break; + } + await delay(50); + continue; + } + + const missingSamples = remainingRequiredBlockSamples(samples.length); + if (shutdownRequested && missingSamples === 0) { + break; + } + if (shutdownRequested && !shutdownNoticePrinted) { + shutdownNoticePrinted = true; + console.log( + `Graceful shutdown requested; waiting for ${missingSamples} more proposer sample(s).`, + ); + } + if (shutdownRequestedAtMs !== undefined) { + const drainFailure = sampleDrainFailureReason( + samples.length, + Date.now() - shutdownRequestedAtMs, + ); + if (drainFailure !== undefined) { + fatalError = new Error(drainFailure); + break; + } + } + + const tick = liveness.tick(Date.now()); + if (tick.kind === "warning") { + console.log( + `BEST HEAD WARNING: no new best head for ${tick.stall.durationMs}ms ` + + `after block ${tick.stall.afterBlock}`, + ); + } else if (tick.kind === "abort") { + fatalError = new Error( + `no new best head for ${tick.stall.durationMs}ms after block ${tick.stall.afterBlock}`, + ); + break; + } else if (tick.kind === "violation") { + console.error( + `BEST HEAD VIOLATION: no new best head for ${tick.stall.durationMs}ms ` + + `after block ${tick.stall.afterBlock}; continuing until recovery or ` + + `${headTimeoutMs}ms hard timeout`, + ); + } + + await delay(200); + } + + const finalSamples = tail.read(true); + if (activated && activation !== undefined) { + acceptSamples(postUpgradeBlockSamples(finalSamples, activation.upgradeBlock)); + } else if (activated) { + acceptSamples(finalSamples); + } + } catch (error) { + fatalError = error instanceof Error ? error : new Error(String(error)); + } finally { + disconnecting = true; + try { + unsubscribe?.(); + } catch { + // The report remains authoritative even if an already-dead RPC cannot unsubscribe. + } + await api?.disconnect().catch(() => undefined); + process.removeListener("SIGINT", requestStop); + process.removeListener("SIGTERM", requestStop); + } + + if (fatalError !== undefined) { + failureReasons.push(fatalError.message); + } + + const latency = summarizeBlockSamples(samples); + if (policy.enforceLatency) { + failureReasons.push( + ...blockLatencyFailureReasons(latency, DEFAULT_MIN_BLOCK_SAMPLES), + ); + } else if (latency.sampleCount < DEFAULT_MIN_BLOCK_SAMPLES) { + failureReasons.push( + ...blockLatencyFailureReasons(latency, DEFAULT_MIN_BLOCK_SAMPLES).filter((reason) => + reason.startsWith("observed "), + ), + ); + } + const stalls = liveness.getStalls(); + if (policy.enforceStalls) { + failureReasons.push(...bestHeadFailureReasons(stalls)); + } + let baselineComparison: LatencyComparison | null = null; + try { + baselineComparison = readBaselineComparison(args.baselineReport, latency); + } catch (error) { + failureReasons.push(error instanceof Error ? error.message : String(error)); + } + if (args.diagnosticFile) { + try { + await writeDiagnosticContext( + args.nodeLog, + args.diagnosticFile, + latency.slowestBlocks.slice(0, 10), + ); + } catch (error) { + console.error( + `Unable to write slow-block diagnostic context: ${ + error instanceof Error ? error.message : String(error) + }`, + ); + } + } + + const report: MonitorReport = { + schemaVersion: 2, + status: failureReasons.length === 0 ? "passed" : "failed", + policy: args.policy, + startedAt: startedAt.toISOString(), + finishedAt: new Date().toISOString(), + nodeLog: args.nodeLog, + startOffset: args.startOffset, + activation: activation ?? null, + thresholds: { + blockWarningMs: DEFAULT_BLOCK_WARNING_MS, + blockFailureMs: DEFAULT_BLOCK_FAILURE_MS, + headWarningMs: DEFAULT_HEAD_WARNING_MS, + headViolationMs: DEFAULT_HEAD_VIOLATION_MS, + headTimeoutMs, + minimumSamples: DEFAULT_MIN_BLOCK_SAMPLES, + sampleDrainTimeoutMs: DEFAULT_SAMPLE_DRAIN_TIMEOUT_MS, + }, + bestHead: { + lastBlock: liveness.getLastBlock() ?? null, + stalls, + }, + latency, + baselineComparison, + diagnosticFile: args.diagnosticFile ?? null, + failureReasons, + }; + + writeJson(args.reportFile, report); + appendStepSummary(report); + console.log( + `Clone block monitor ${report.status}: samples=${latency.sampleCount} ` + + `mean_ms=${latency.meanMs ?? "none"} max_ms=${latency.maximumMs ?? "none"} ` + + `warnings=${latency.warnings.length} ` + + `violations=${latency.violations.length} stalls=${report.bestHead.stalls.length}`, + ); + if (failureReasons.length > 0) { + for (const reason of failureReasons) { + console.error(`BLOCK MONITOR FAILURE: ${reason}`); + } + process.exitCode = 1; + } + await logger.flush(); +} + +function parseArguments(values: string[]): MonitorArguments { + const { values: options } = parseArgs({ + args: values, + allowPositionals: false, + strict: true, + options: { + policy: { type: "string" }, + "node-log": { type: "string" }, + "start-offset": { type: "string" }, + report: { type: "string" }, + "log-name": { type: "string" }, + "activation-report": { type: "string" }, + "ready-file": { type: "string" }, + "baseline-report": { type: "string" }, + "diagnostic-file": { type: "string" }, + }, + }); + const required = (name: keyof typeof options): string => { + const value = options[name]; + if (value === undefined || value.length === 0) { + throw new Error(`missing --${name}`); + } + return value; + }; + const integer = (name: keyof typeof options, minimum: number): number => { + const raw = required(name); + const value = Number(raw); + if (!Number.isSafeInteger(value) || value < minimum) { + throw new Error(`invalid --${name}: ${raw}`); + } + return value; + }; + + const policy = required("policy"); + if (policy !== "fail-fast" && policy !== "collect" && policy !== "baseline") { + throw new Error(`invalid --policy: ${policy}`); + } + const logName = required("log-name"); + if (path.basename(logName) !== logName) { + throw new Error(`--log-name must be a filename: ${logName}`); + } + + return { + policy, + nodeLog: path.resolve(required("node-log")), + startOffset: integer("start-offset", 0), + reportFile: path.resolve(required("report")), + logName, + activationReport: options["activation-report"] + ? path.resolve(options["activation-report"]) + : undefined, + readyFile: options["ready-file"] ? path.resolve(options["ready-file"]) : undefined, + baselineReport: options["baseline-report"] + ? path.resolve(options["baseline-report"]) + : undefined, + diagnosticFile: options["diagnostic-file"] + ? path.resolve(options["diagnostic-file"]) + : undefined, + }; +} + +function writeJson(filename: string, value: unknown) { + fs.mkdirSync(path.dirname(filename), { recursive: true }); + fs.writeFileSync(filename, `${JSON.stringify(value, bigintJson, 2)}\n`); +} + +function readActivationReport(filename?: string): RuntimeUpgradeActivation | undefined { + if (filename === undefined || !fs.existsSync(filename)) { + return undefined; + } + const value: unknown = JSON.parse(fs.readFileSync(filename, "utf8")); + if (!isRecord(value)) { + throw new Error(`invalid runtime upgrade report: ${filename}`); + } + const upgradeBlock = value.upgradeBlock; + const finalizedAtEpochMs = value.finalizedAtEpochMs; + if (!isNonnegativeSafeInteger(upgradeBlock)) { + throw new Error(`invalid runtime upgrade block in ${filename}`); + } + if (!isPositiveSafeInteger(finalizedAtEpochMs)) { + throw new Error(`invalid runtime upgrade finalization time in ${filename}`); + } + return { + upgradeBlock, + finalizedAtEpochMs, + }; +} + +function readBaselineComparison( + filename: string | undefined, + current: ReturnType, +): LatencyComparison | null { + if (filename === undefined) { + return null; + } + const report: unknown = JSON.parse(fs.readFileSync(filename, "utf8")); + if (!isRecord(report) || !isRecord(report.latency)) { + throw new Error(`invalid baseline block monitor report: ${filename}`); + } + const latency = report.latency; + const sampleCount = latency.sampleCount; + if (!isNonnegativeSafeInteger(sampleCount)) { + throw new Error(`invalid baseline sample count in ${filename}`); + } + const meanMs = nullableMetric(latency.meanMs, "meanMs", filename); + const p50Ms = nullableMetric(latency.p50Ms, "p50Ms", filename); + const p95Ms = nullableMetric(latency.p95Ms, "p95Ms", filename); + const p99Ms = nullableMetric(latency.p99Ms, "p99Ms", filename); + const maximumMs = nullableMetric(latency.maximumMs, "maximumMs", filename); + return { + baselineSamples: sampleCount, + currentSamples: current.sampleCount, + meanMs: compareMetric(meanMs, current.meanMs), + p50Ms: compareMetric(p50Ms, current.p50Ms), + p95Ms: compareMetric(p95Ms, current.p95Ms), + p99Ms: compareMetric(p99Ms, current.p99Ms), + maximumMs: compareMetric(maximumMs, current.maximumMs), + }; +} + +function nullableMetric(value: unknown, name: string, filename: string): number | null { + if (value === null) { + return null; + } + if (typeof value !== "number" || !Number.isFinite(value) || value < 0) { + throw new Error(`invalid baseline ${name} in ${filename}`); + } + return value; +} + +function isRecord(value: unknown): value is Record { + return typeof value === "object" && value !== null; +} + +function isNonnegativeSafeInteger(value: unknown): value is number { + return typeof value === "number" && Number.isSafeInteger(value) && value >= 0; +} + +function isPositiveSafeInteger(value: unknown): value is number { + return isNonnegativeSafeInteger(value) && value > 0; +} + +function compareMetric(baseline: number | null, current: number | null): MetricComparison { + return { + baseline, + current, + deltaMs: + baseline === null || current === null + ? null + : Math.round((current - baseline) * 10) / 10, + ratio: + baseline === null || baseline === 0 || current === null + ? null + : Math.round((current / baseline) * 1_000) / 1_000, + }; +} + +async function writeDiagnosticContext( + nodeLog: string, + filename: string, + slowestBlocks: readonly BlockConstructionSample[], +) { + fs.mkdirSync(path.dirname(filename), { recursive: true }); + if (slowestBlocks.length === 0) { + fs.writeFileSync(filename, "No proposer samples were observed.\n"); + return; + } + + const targets = new Set(slowestBlocks.map(({ block }) => block)); + const contexts = new Map(); + const previousLines: string[] = []; + const active = new Map(); + const lines = createInterface({ + input: fs.createReadStream(nodeLog, { encoding: "utf8" }), + crlfDelay: Infinity, + }); + + for await (const line of lines) { + for (const [block, remaining] of active) { + contexts.get(block)?.push(line); + if (remaining === 1) { + active.delete(block); + } else { + active.set(block, remaining - 1); + } + } + + const parsed = parsePreparedBlockChunk("", `${line}\n`).samples[0]; + if (parsed !== undefined && targets.has(parsed.block) && !contexts.has(parsed.block)) { + contexts.set(parsed.block, [...previousLines, line]); + active.set(parsed.block, 5); + } + previousLines.push(line); + if (previousLines.length > 5) { + previousLines.shift(); + } + } + + const sections = slowestBlocks.map(({ block, durationMs }) => { + const context = contexts.get(block) ?? ["(proposer line was not found in the retained node log)"]; + return [`===== block ${block} (${durationMs}ms) =====`, ...context].join("\n"); + }); + fs.writeFileSync(filename, `${sections.join("\n\n")}\n`); +} + +function appendStepSummary(report: MonitorReport) { + const filename = process.env.GITHUB_STEP_SUMMARY; + if (!filename) { + return; + } + const slowest = report.latency.slowestBlocks + .slice(0, 10) + .map(({ block, durationMs }) => `#${block}: ${durationMs}ms`) + .join(", "); + const comparison = report.baselineComparison; + const comparisonLines = comparison + ? [ + `- Baseline / candidate samples: ${comparison.baselineSamples} / ${comparison.currentSamples}`, + `- Mean delta / ratio: ${formatComparison(comparison.meanMs)}`, + `- p50 delta / ratio: ${formatComparison(comparison.p50Ms)}`, + `- p95 delta / ratio: ${formatComparison(comparison.p95Ms)}`, + `- p99 delta / ratio: ${formatComparison(comparison.p99Ms)}`, + `- Maximum delta / ratio: ${formatComparison(comparison.maximumMs)}`, + ] + : []; + fs.appendFileSync( + filename, + [ + "### Clone block performance", + `- Status: **${report.status}**`, + `- Samples: ${report.latency.sampleCount}`, + `- Mean: ${report.latency.meanMs ?? "n/a"}ms`, + `- Maximum: ${report.latency.maximumMs ?? "n/a"}ms`, + `- p50 / p95 / p99: ${report.latency.p50Ms ?? "n/a"} / ${report.latency.p95Ms ?? "n/a"} / ${report.latency.p99Ms ?? "n/a"} ms`, + `- Warnings / violations: ${report.latency.warnings.length} / ${report.latency.violations.length}`, + `- Best-head stalls: ${report.bestHead.stalls.length}`, + `- Slowest blocks: ${slowest || "none"}`, + ...comparisonLines, + report.diagnosticFile + ? `- Slow-block diagnostic context: ${path.basename(report.diagnosticFile)}` + : "", + "", + ] + .filter((line) => line !== "") + .concat("") + .join("\n"), + ); +} + +function formatComparison(value: MetricComparison): string { + const delta = + value.deltaMs === null + ? "n/a" + : `${value.deltaMs >= 0 ? "+" : ""}${value.deltaMs}ms`; + const ratio = value.ratio === null ? "n/a" : `${value.ratio}x`; + return `${delta} / ${ratio}`; +} + +function bigintJson(_key: string, value: unknown) { + return typeof value === "bigint" ? value.toString() : value; +} + +function delay(milliseconds: number): Promise { + return new Promise((resolve) => setTimeout(resolve, milliseconds)); +} + +main().catch((error) => { + console.error(error); + process.exit(1); +}); diff --git a/clones/js-tests/scripts/run-clone-epoch-soak.ts b/clones/js-tests/scripts/run-clone-epoch-soak.ts new file mode 100644 index 0000000000..1a55cd2ecf --- /dev/null +++ b/clones/js-tests/scripts/run-clone-epoch-soak.ts @@ -0,0 +1,530 @@ +import fs from "node:fs"; +import path from "node:path"; +import { parseArgs } from "node:util"; +import type { ApiPromise } from "@polkadot/api"; +import { connectApi } from "../lib/api.js"; +import { + waitForBetaBasketV2ReleaseReadiness, + type BetaBasketV2ReadinessObservation, +} from "../lib/clone-readiness.js"; +import { + assertIssuanceMirror, + readIssuanceMirror, + serializeIssuanceMirror, +} from "../lib/clone-invariants.js"; +import { + ACCELERATED_SEALING_MS, + assertReliableEpochPollingGap, + computeEpochCoverageBudget, + SuccessfulEpochTracker, + evaluateEpochCoverage, + type EpochBaseline, + type EpochCoverageBudget, + type EpochCoverageEvaluation, +} from "../lib/clone-performance.js"; +import { createTempLogger } from "../lib/file-log.js"; + +const ROOT_NETUID = 0; +const POLL_INTERVAL_MS = 1_000; +const COVERAGE_POLL_BLOCKS = 10; +const EXPECTED_CHAIN_BLOCK_TIME_MS = 12_000; +type ReleaseGate = "none" | "beta-basket-v2"; + +interface SoakArguments { + epochCycles: number; + releaseGate: ReleaseGate; + upgradeBlock: number; + minimumPostUpgradeBlocks: number; + deadlineEpochMs: number; + reportFile: string; + logName: string; +} + +interface EpochSoakReport { + schemaVersion: 3; + status: "running" | "passed" | "failed"; + startedAt: string; + finishedAt?: string; + requestedCycles: number; + releaseGate: ReleaseGate; + upgradeBlock: number; + minimumPostUpgradeBlocks: number; + deadlineEpochMs: number; + betaBasketV2Readiness?: BetaBasketV2ReadinessObservation; + baselineBlock?: number; + completionBlock?: number; + budget?: EpochCoverageBudget; + coverageWindow?: { + startedAtEpochMs: number; + deadlineEpochMs: number; + availableWallMs: number; + nominalWallMs: number; + }; + chainTiming?: { + baselineTimestampMs: string; + completionTimestampMs: string; + elapsedMs: string; + expectedElapsedMs: string; + millisecondsPerBlock: number; + }; + baseline?: Array<{ + netuid: number; + tempo: number; + epochIndex: string; + lastSuccessfulEpochBlock: string; + }>; + coverage?: Array<{ + netuid: number; + tempo: number; + baselineEpochIndex: string; + currentEpochIndex: string; + baselineSuccessfulEpochBlock: string; + currentSuccessfulEpochBlock: string; + attemptedCycles: string; + completedCycles: string; + }>; + invariants?: { + baseline: ReturnType; + completion?: ReturnType; + }; + failure?: string; +} + +type ChainHash = Awaited>["hash"]; + +async function main() { + const args = parseArguments(process.argv.slice(2)); + const logger = createTempLogger(args.logName); + await logger.start(); + logger.captureConsole(); + + const report: EpochSoakReport = { + schemaVersion: 3, + status: "running", + startedAt: new Date().toISOString(), + requestedCycles: args.epochCycles, + releaseGate: args.releaseGate, + upgradeBlock: args.upgradeBlock, + minimumPostUpgradeBlocks: args.minimumPostUpgradeBlocks, + deadlineEpochMs: args.deadlineEpochMs, + }; + let api: ApiPromise | undefined; + + try { + api = await connectApi(process.env.WS_ENDPOINT ?? "ws://127.0.0.1:9944", { + log: (message) => console.log(message), + }); + if (args.releaseGate === "beta-basket-v2") { + report.betaBasketV2Readiness = await waitForBetaBasketV2ReleaseReadiness(api, { + deadlineEpochMs: args.deadlineEpochMs, + log: (message) => console.log(message), + }); + console.log( + `Beta-basket v2 release gate resolved at block ${report.betaBasketV2Readiness.readinessBlock}; ` + + `mode=${report.betaBasketV2Readiness.mode} ` + + `saw_cursor=${report.betaBasketV2Readiness.sawCursor} ` + + `saw_deferred=${report.betaBasketV2Readiness.sawDeferredEntries}`, + ); + } else { + console.log("Release-specific migration gate disabled for pre-upgrade baseline."); + } + + const baselineHeader = await bestHeader(api); + const baselineBlock = baselineHeader.number.toNumber(); + const baseline = await readEpochBaseline(api, baselineHeader.hash); + const minimumTempo = Math.min(...baseline.map(({ tempo }) => tempo)); + if (minimumTempo <= COVERAGE_POLL_BLOCKS) { + throw new Error( + `minimum subnet tempo ${minimumTempo} is too short for ${COVERAGE_POLL_BLOCKS}-block ` + + "successful-epoch polling", + ); + } + const successTracker = new SuccessfulEpochTracker(baseline, baselineBlock); + const atBaseline = await api.at(baselineHeader.hash); + const maxEpochsPerBlock = Number( + (await atBaseline.query.subtensorModule.maxEpochsPerBlock()).toString(), + ); + const baselineTimestampMs = BigInt((await atBaseline.query.timestamp.now()).toString()); + const baselineIssuance = await readIssuanceMirror(api, baselineHeader.hash); + assertIssuanceMirror(baselineIssuance, "epoch soak baseline"); + const budget = computeEpochCoverageBudget(baseline, args.epochCycles, maxEpochsPerBlock); + const coverageStartedAtEpochMs = Date.now(); + const remainingWallMs = Math.max(0, args.deadlineEpochMs - coverageStartedAtEpochMs); + const minimumCompletionBlock = args.upgradeBlock + args.minimumPostUpgradeBlocks; + const remainingMinimumBlocks = Math.max(0, minimumCompletionBlock - baselineBlock); + const requiredCoverageBlocks = Math.max(budget.blockBudget, remainingMinimumBlocks); + const nominalRequiredWallMs = requiredCoverageBlocks * ACCELERATED_SEALING_MS; + if (nominalRequiredWallMs > remainingWallMs) { + throw new Error( + `epoch coverage cannot fit: nominal ${formatDuration(nominalRequiredWallMs)} exceeds ` + + `${formatDuration(Math.max(0, remainingWallMs))} remaining`, + ); + } + const coverageDeadlineEpochMs = args.deadlineEpochMs; + + report.baselineBlock = baselineBlock; + report.budget = budget; + report.coverageWindow = { + startedAtEpochMs: coverageStartedAtEpochMs, + deadlineEpochMs: coverageDeadlineEpochMs, + availableWallMs: remainingWallMs, + nominalWallMs: nominalRequiredWallMs, + }; + report.baseline = baseline.map(({ netuid, tempo, epochIndex, lastSuccessfulEpochBlock }) => ({ + netuid, + tempo, + epochIndex: epochIndex.toString(), + lastSuccessfulEpochBlock: lastSuccessfulEpochBlock.toString(), + })); + report.invariants = { baseline: serializeIssuanceMirror(baselineIssuance) }; + writeJson(args.reportFile, report); + + console.log( + `Epoch baseline: block=${baselineBlock} active_non_root=${baseline.length} ` + + `max_tempo=${budget.maxTempo} max_epochs_per_block=${maxEpochsPerBlock} ` + + `cycles=${args.epochCycles} block_budget=${budget.blockBudget} ` + + `minimum_post_upgrade_blocks=${args.minimumPostUpgradeBlocks} ` + + `minimum_completion_block=${minimumCompletionBlock} ` + + `nominal=${formatDuration(nominalRequiredWallMs)} ` + + `operational_window=${formatDuration(remainingWallMs)}`, + ); + + const blockDeadline = baselineBlock + budget.blockBudget; + let lastBlock = baselineBlock; + let lastCoverageBlock = baselineBlock - COVERAGE_POLL_BLOCKS; + let lastCompletedSubnets = -1; + let lastReportBlock = baselineBlock - 100; + + for (;;) { + ensureWallDeadline(coverageDeadlineEpochMs, "epoch coverage wall"); + const header = await bestHeader(api); + const block = header.number.toNumber(); + if (block === lastBlock) { + await delay(POLL_INTERVAL_MS); + continue; + } + if (block < lastBlock) { + throw new Error(`best block regressed from ${lastBlock} to ${block}`); + } + lastBlock = block; + if (block < lastCoverageBlock + COVERAGE_POLL_BLOCKS) { + await delay(POLL_INTERVAL_MS); + continue; + } + assertReliableEpochPollingGap(lastCoverageBlock, block, minimumTempo); + lastCoverageBlock = block; + + const snapshot = await readCoverageAt(api, header.hash, baseline); + const successfulCycles = successTracker.observe( + snapshot.currentSuccessfulEpochBlocks, + block, + ); + const evaluation = evaluateEpochCoverage( + baseline, + snapshot.currentEpochIndices, + snapshot.currentSuccessfulEpochBlocks, + successfulCycles, + snapshot.activeNetuids, + args.epochCycles, + ); + assertCoverageState(evaluation, block); + const completedSubnets = evaluation.progress.filter( + ({ completedCycles }) => completedCycles >= BigInt(args.epochCycles), + ).length; + + if ( + evaluation.complete || + completedSubnets !== lastCompletedSubnets || + block >= lastReportBlock + 100 + ) { + lastCompletedSubnets = completedSubnets; + lastReportBlock = block; + report.coverage = serializeCoverage(evaluation); + writeJson(args.reportFile, report); + console.log( + `Epoch coverage: block=${block} completed=${completedSubnets}/${baseline.length} ` + + `elapsed_blocks=${block - baselineBlock}/${budget.blockBudget}`, + ); + } + + const minimumBlockCoverageComplete = block >= minimumCompletionBlock; + if (evaluation.complete && minimumBlockCoverageComplete) { + const completed = await api.at(header.hash); + const completionTimestampMs = BigInt((await completed.query.timestamp.now()).toString()); + const elapsedMs = completionTimestampMs - baselineTimestampMs; + const expectedElapsedMs = BigInt( + (block - baselineBlock) * EXPECTED_CHAIN_BLOCK_TIME_MS, + ); + if (elapsedMs !== expectedElapsedMs) { + throw new Error( + `accelerated clone changed chain-time semantics: elapsed_ms=${elapsedMs} ` + + `expected_ms=${expectedElapsedMs} blocks=${block - baselineBlock}`, + ); + } + const completionIssuance = await readIssuanceMirror(api, header.hash); + assertIssuanceMirror(completionIssuance, "epoch soak completion"); + report.status = "passed"; + report.finishedAt = new Date().toISOString(); + report.completionBlock = block; + report.coverage = serializeCoverage(evaluation); + report.chainTiming = { + baselineTimestampMs: baselineTimestampMs.toString(), + completionTimestampMs: completionTimestampMs.toString(), + elapsedMs: elapsedMs.toString(), + expectedElapsedMs: expectedElapsedMs.toString(), + millisecondsPerBlock: EXPECTED_CHAIN_BLOCK_TIME_MS, + }; + report.invariants = { + baseline: serializeIssuanceMirror(baselineIssuance), + completion: serializeIssuanceMirror(completionIssuance), + }; + writeJson(args.reportFile, report); + appendStepSummary(report); + const completionScope = + args.releaseGate === "none" + ? "pre-upgrade baseline" + : `${block - args.upgradeBlock} post-upgrade blocks observed`; + console.log( + `Epoch soak complete at block ${block}: every baseline subnet advanced ` + + `${args.epochCycles} successful epoch(s); ${completionScope}.`, + ); + return; + } + if (!evaluation.complete && block > blockDeadline) { + throw new Error( + `epoch coverage exceeded block budget at ${block}; baseline=${baselineBlock} ` + + `budget=${budget.blockBudget} completed=${completedSubnets}/${baseline.length}`, + ); + } + await delay(POLL_INTERVAL_MS); + } + } catch (error) { + const failure = error instanceof Error ? error.message : String(error); + report.status = "failed"; + report.finishedAt = new Date().toISOString(); + report.failure = failure; + writeJson(args.reportFile, report); + appendStepSummary(report); + console.error(`EPOCH SOAK FAILURE: ${failure}`); + throw error; + } finally { + await api?.disconnect().catch(() => undefined); + await logger.flush(); + } +} + +async function readEpochBaseline(api: ApiPromise, hash: ChainHash): Promise { + const at = await api.at(hash); + const query = at.query.subtensorModule; + const entries = await query.networksAdded.entries(); + const netuids = entries + .filter(([, isAdded]) => isAdded.toString() === "true") + .map(([key]) => Number(key.args[0].toString())) + .filter((netuid) => netuid !== ROOT_NETUID) + .sort((left, right) => left - right); + if (netuids.length === 0) { + throw new Error("post-migration state has no active non-root subnets"); + } + + const [tempos, epochIndices, lastSuccessfulEpochBlocks] = await Promise.all([ + query.tempo.multi(netuids), + query.subnetEpochIndex.multi(netuids), + query.lastMechansimStepBlock.multi(netuids), + ]); + return netuids.map((netuid, index) => ({ + netuid, + tempo: Number(tempos[index].toString()), + epochIndex: BigInt(epochIndices[index].toString()), + lastSuccessfulEpochBlock: BigInt(lastSuccessfulEpochBlocks[index].toString()), + })); +} + +async function readCoverageAt( + api: ApiPromise, + hash: ChainHash, + baseline: readonly EpochBaseline[], +): Promise<{ + activeNetuids: Set; + currentEpochIndices: Map; + currentSuccessfulEpochBlocks: Map; +}> { + const at = await api.at(hash); + const query = at.query.subtensorModule; + const netuids = baseline.map(({ netuid }) => netuid); + const [added, epochIndices, lastSuccessfulEpochBlocks] = await Promise.all([ + query.networksAdded.multi(netuids), + query.subnetEpochIndex.multi(netuids), + query.lastMechansimStepBlock.multi(netuids), + ]); + const activeNetuids = new Set(); + const currentEpochIndices = new Map(); + const currentSuccessfulEpochBlocks = new Map(); + netuids.forEach((netuid, index) => { + if (added[index].toString() === "true") { + activeNetuids.add(netuid); + } + currentEpochIndices.set(netuid, BigInt(epochIndices[index].toString())); + currentSuccessfulEpochBlocks.set( + netuid, + BigInt(lastSuccessfulEpochBlocks[index].toString()), + ); + }); + return { activeNetuids, currentEpochIndices, currentSuccessfulEpochBlocks }; +} + +function assertCoverageState(evaluation: EpochCoverageEvaluation, block: number) { + if (evaluation.removedNetuids.length > 0) { + throw new Error( + `baseline subnet(s) removed before coverage at block ${block}: ${evaluation.removedNetuids.join(",")}`, + ); + } + if (evaluation.missingNetuids.length > 0) { + throw new Error( + `baseline subnet epoch state missing at block ${block}: ${evaluation.missingNetuids.join(",")}`, + ); + } + if (evaluation.regressedNetuids.length > 0) { + throw new Error( + `subnet epoch index regressed at block ${block}: ${evaluation.regressedNetuids.join(",")}`, + ); + } + if (evaluation.skippedNetuids.length > 0) { + throw new Error( + `subnet epoch slot(s) advanced without successful execution at block ${block}: ` + + evaluation.skippedNetuids.join(","), + ); + } +} + +function serializeCoverage(evaluation: EpochCoverageEvaluation) { + return evaluation.progress.map((subnet) => ({ + netuid: subnet.netuid, + tempo: subnet.tempo, + baselineEpochIndex: subnet.epochIndex.toString(), + currentEpochIndex: subnet.currentEpochIndex.toString(), + baselineSuccessfulEpochBlock: subnet.lastSuccessfulEpochBlock.toString(), + currentSuccessfulEpochBlock: subnet.currentSuccessfulEpochBlock.toString(), + attemptedCycles: subnet.attemptedCycles.toString(), + completedCycles: subnet.completedCycles.toString(), + })); +} + +async function bestHeader(api: ApiPromise) { + return api.rpc.chain.getHeader(); +} + +function parseArguments(values: string[]): SoakArguments { + const { values: options } = parseArgs({ + args: values, + allowPositionals: false, + strict: true, + options: { + "epoch-cycles": { type: "string" }, + "release-gate": { type: "string" }, + "upgrade-block": { type: "string" }, + "minimum-post-upgrade-blocks": { type: "string" }, + "deadline-epoch-ms": { type: "string" }, + report: { type: "string" }, + "log-name": { type: "string" }, + }, + }); + const required = (name: keyof typeof options): string => { + const value = options[name]; + if (value === undefined || value.length === 0) { + throw new Error(`missing --${name}`); + } + return value; + }; + const integer = (name: keyof typeof options, minimum: number): number => { + const raw = required(name); + const value = Number(raw); + if (!Number.isSafeInteger(value) || value < minimum) { + throw new Error(`invalid --${name}: ${raw}`); + } + return value; + }; + + const epochCycles = integer("epoch-cycles", 1); + if (epochCycles > 3) { + throw new Error(`--epoch-cycles must be 1, 2, or 3; got ${epochCycles}`); + } + const releaseGate = required("release-gate"); + if (releaseGate !== "none" && releaseGate !== "beta-basket-v2") { + throw new Error(`invalid --release-gate: ${releaseGate}`); + } + const logName = required("log-name"); + if (path.basename(logName) !== logName) { + throw new Error(`--log-name must be a filename: ${logName}`); + } + return { + epochCycles, + releaseGate, + upgradeBlock: integer("upgrade-block", 0), + minimumPostUpgradeBlocks: integer("minimum-post-upgrade-blocks", 0), + deadlineEpochMs: integer("deadline-epoch-ms", 1), + reportFile: path.resolve(required("report")), + logName, + }; +} + +function ensureWallDeadline(deadlineEpochMs: number, label = "soak wall") { + if (Date.now() >= deadlineEpochMs) { + throw new Error(`${label} deadline ${new Date(deadlineEpochMs).toISOString()} was reached`); + } +} + +function writeJson(filename: string, report: EpochSoakReport) { + fs.mkdirSync(path.dirname(filename), { recursive: true }); + fs.writeFileSync(filename, `${JSON.stringify(report, null, 2)}\n`); +} + +function appendStepSummary(report: EpochSoakReport) { + const filename = process.env.GITHUB_STEP_SUMMARY; + if (!filename || report.status === "running") { + return; + } + fs.appendFileSync( + filename, + `${[ + report.releaseGate === "none" + ? "### Pre-upgrade epoch baseline" + : "### Post-upgrade epoch soak", + `- Status: **${report.status}**`, + `- Requested cycles: ${report.requestedCycles}`, + `- Release gate: ${report.releaseGate}`, + `- Migration mode: ${report.betaBasketV2Readiness?.mode ?? "not-applicable"}`, + `- Migration cursor completion block: ${report.betaBasketV2Readiness?.cursorCompletionBlock ?? "not-observed"}`, + `- Fully writable block: ${report.betaBasketV2Readiness?.readinessBlock ?? "not-applicable"}`, + `- Deferred release observed: ${report.betaBasketV2Readiness?.sawDeferredEntries ?? false}`, + `- Baseline / completion block: ${report.baselineBlock ?? "n/a"} / ${report.completionBlock ?? "n/a"}`, + `- Upgrade block / minimum post-upgrade blocks: ${report.upgradeBlock} / ${report.minimumPostUpgradeBlocks}`, + `- Active non-root subnets: ${report.budget?.activeSubnets ?? "n/a"}`, + `- Maximum tempo: ${report.budget?.maxTempo ?? "n/a"}`, + `- Block budget: ${report.budget?.blockBudget ?? "n/a"}`, + `- Nominal coverage / available window: ${ + report.coverageWindow + ? `${formatDuration(report.coverageWindow.nominalWallMs)} / ${formatDuration( + report.coverageWindow.availableWallMs, + )}` + : "n/a" + }`, + `- Verified chain block time: ${report.chainTiming?.millisecondsPerBlock ?? "n/a"}ms`, + report.failure ? `- Failure: ${report.failure}` : "", + ] + .filter(Boolean) + .join("\n")}\n\n`, + ); +} + +function formatDuration(milliseconds: number): string { + return `${(milliseconds / 60_000).toFixed(1)}m`; +} + +function delay(milliseconds: number): Promise { + return new Promise((resolve) => setTimeout(resolve, milliseconds)); +} + +main().catch((error) => { + console.error(error); + process.exit(1); +}); diff --git a/clones/js-tests/scripts/update-runtime-with-alice.ts b/clones/js-tests/scripts/update-runtime-with-alice.ts index 3c780d3cf9..78aee06977 100644 --- a/clones/js-tests/scripts/update-runtime-with-alice.ts +++ b/clones/js-tests/scripts/update-runtime-with-alice.ts @@ -1,6 +1,7 @@ import assert from "node:assert/strict"; import fs from "node:fs"; import path from "node:path"; +import { parseArgs } from "node:util"; import { fileURLToPath } from "node:url"; import { Keyring } from "@polkadot/api"; @@ -28,6 +29,10 @@ const alice = keyring.addFromUri("//Alice"); const logger = createTempLogger("runtime-update-alice.log"); logger.captureConsole(); +interface RuntimeUpdateArguments { + reportFile?: string; +} + function formatDispatchError(api, error) { if (!error.isModule) { return error.toString(); @@ -38,7 +43,7 @@ function formatDispatchError(api, error) { } async function submitAndWait(api, signer, tx, label) { - return new Promise((resolve, reject) => { + return new Promise((resolve, reject) => { let unsubscribe; let settled = false; @@ -81,6 +86,8 @@ async function connect() { } async function main() { + const args = parseArguments(process.argv.slice(2)); + const startedAt = new Date().toISOString(); await logger.start(); assert.ok(fs.existsSync(WASM_PATH), `runtime wasm not found: ${WASM_PATH}`); @@ -112,19 +119,57 @@ async function main() { api.tx.sudo.sudo(api.tx.system.setCode(`0x${wasm.toString("hex")}`)), "runtime upgrade" ); + const upgradeHeader = await api.rpc.chain.getHeader(blockHash); + const finalizedAtEpochMs = Date.now(); + const upgradeBlock = upgradeHeader.number.toNumber(); console.log("runtime upgrade finalized in block:", blockHash); + console.log("runtime upgrade finalized at height:", upgradeBlock); await api.disconnect(); api = await connect(); const after = await api.rpc.state.getRuntimeVersion(); console.log("runtime after:", after.specName.toString(), after.specVersion.toString()); + + if (args.reportFile) { + writeJson(args.reportFile, { + schemaVersion: 1, + startedAt, + finalizedAt: new Date().toISOString(), + finalizedAtEpochMs, + upgradeBlock, + upgradeBlockHash: blockHash, + beforeSpecVersion: before.specVersion.toNumber(), + afterSpecVersion: after.specVersion.toNumber(), + }); + } } finally { await api.disconnect(); } } +function parseArguments(values: string[]): RuntimeUpdateArguments { + const { values: options } = parseArgs({ + args: values, + allowPositionals: false, + strict: true, + options: { + report: { type: "string" }, + }, + }); + return { + reportFile: options.report ? path.resolve(options.report) : undefined, + }; +} + +function writeJson(filename: string, value: unknown) { + fs.mkdirSync(path.dirname(filename), { recursive: true }); + const temporary = `${filename}.tmp-${process.pid}`; + fs.writeFileSync(temporary, `${JSON.stringify(value, null, 2)}\n`); + fs.renameSync(temporary, filename); +} + main().then(() => logger.flush()).catch(async (error) => { await logger.error(error); await logger.flush(); diff --git a/clones/js-tests/scripts/wait-clone-readiness.ts b/clones/js-tests/scripts/wait-clone-readiness.ts new file mode 100644 index 0000000000..6dc8f721c6 --- /dev/null +++ b/clones/js-tests/scripts/wait-clone-readiness.ts @@ -0,0 +1,141 @@ +import fs from "node:fs"; +import path from "node:path"; +import { parseArgs } from "node:util"; +import { connectApi } from "../lib/api.js"; +import { + waitForBetaBasketV2ReleaseReadiness, + type BetaBasketV2ReadinessObservation, +} from "../lib/clone-readiness.js"; +import { createTempLogger } from "../lib/file-log.js"; + +interface ReadinessArguments { + label: string; + timeoutMs: number; + reportFile: string; +} + +interface ReadinessReport { + schemaVersion: 1; + status: "passed" | "failed"; + startedAt: string; + finishedAt: string; + timeoutMs: number; + observation?: BetaBasketV2ReadinessObservation; + failure?: string; +} + +async function main() { + const args = parseArguments(process.argv.slice(2)); + const logger = createTempLogger(`clone-readiness-${args.label}.log`); + await logger.start(); + logger.captureConsole(); + const startedAt = new Date(); + let api; + let report: ReadinessReport; + + try { + api = await connectApi(process.env.WS_ENDPOINT ?? "ws://127.0.0.1:9944", { + log: (message) => console.log(message), + }); + const observation = await waitForBetaBasketV2ReleaseReadiness(api, { + deadlineEpochMs: startedAt.getTime() + args.timeoutMs, + log: (message) => console.log(message), + }); + report = { + schemaVersion: 1, + status: "passed", + startedAt: startedAt.toISOString(), + finishedAt: new Date().toISOString(), + timeoutMs: args.timeoutMs, + observation, + }; + console.log( + `Beta-basket v2 readiness passed: mode=${observation.mode} start=${observation.startBlock} ` + + `cursor_completion=${observation.cursorCompletionBlock ?? "not-observed"} ` + + `ready=${observation.readinessBlock}`, + ); + } catch (error) { + const failure = error instanceof Error ? error.message : String(error); + report = { + schemaVersion: 1, + status: "failed", + startedAt: startedAt.toISOString(), + finishedAt: new Date().toISOString(), + timeoutMs: args.timeoutMs, + failure, + }; + console.error(`CLONE READINESS FAILURE: ${failure}`); + process.exitCode = 1; + } finally { + await api?.disconnect().catch(() => undefined); + } + + writeJson(args.reportFile, report); + appendStepSummary(report); + await logger.flush(); +} + +function parseArguments(values: string[]): ReadinessArguments { + const { values: options } = parseArgs({ + args: values, + allowPositionals: false, + strict: true, + options: { + label: { type: "string" }, + "timeout-ms": { type: "string" }, + report: { type: "string" }, + }, + }); + const required = (name: keyof typeof options): string => { + const value = options[name]; + if (value === undefined || value.length === 0) { + throw new Error(`missing --${name}`); + } + return value; + }; + const label = required("label"); + if (!/^[a-z0-9-]+$/.test(label)) { + throw new Error(`invalid --label: ${label}`); + } + const timeoutMs = Number(required("timeout-ms")); + if (!Number.isSafeInteger(timeoutMs) || timeoutMs < 1) { + throw new Error(`invalid --timeout-ms: ${options["timeout-ms"]}`); + } + return { + label, + timeoutMs, + reportFile: path.resolve(required("report")), + }; +} + +function writeJson(filename: string, report: ReadinessReport) { + fs.mkdirSync(path.dirname(filename), { recursive: true }); + fs.writeFileSync(filename, `${JSON.stringify(report, null, 2)}\n`); +} + +function appendStepSummary(report: ReadinessReport) { + const filename = process.env.GITHUB_STEP_SUMMARY; + if (!filename) { + return; + } + const observation = report.observation; + fs.appendFileSync( + filename, + `${[ + "### Release-v438 beta-basket v2 readiness", + `- Status: **${report.status}**`, + `- Migration mode: ${observation?.mode ?? "unresolved"}`, + `- Migration cursor completion block: ${observation?.cursorCompletionBlock ?? "not-observed"}`, + `- Fully writable block: ${observation?.readinessBlock ?? "unresolved"}`, + `- Deferred release observed: ${observation?.sawDeferredEntries ?? false}`, + report.failure ? `- Failure: ${report.failure}` : "", + ] + .filter(Boolean) + .join("\n")}\n\n`, + ); +} + +main().catch((error) => { + console.error(error); + process.exit(1); +}); diff --git a/clones/js-tests/tests/clone-performance.test.ts b/clones/js-tests/tests/clone-performance.test.ts new file mode 100644 index 0000000000..9c5cc8715d --- /dev/null +++ b/clones/js-tests/tests/clone-performance.test.ts @@ -0,0 +1,462 @@ +import assert from "node:assert/strict"; +import fs from "node:fs"; +import os from "node:os"; +import path from "node:path"; +import test from "node:test"; +import type { ApiPromise } from "@polkadot/api"; +import { + evaluateBetaBasketV2Readiness, + waitForBetaBasketV2ReleaseReadiness, + type BetaBasketV2ReadinessSnapshot, +} from "../lib/clone-readiness.js"; +import { assertIssuanceMirror } from "../lib/clone-invariants.js"; +import { + BestHeadLiveness, + NodeLogTail, + SuccessfulEpochTracker, + assertReliableEpochPollingGap, + bestHeadFailureReasons, + blockLatencyFailureReasons, + computeEpochCoverageBudget, + evaluateEpochCoverage, + parsePreparedBlockChunk, + postUpgradeBlockSamples, + remainingRequiredBlockSamples, + sampleDrainFailureReason, + summarizeBlockSamples, + type EpochBaseline, +} from "../lib/clone-performance.js"; + +test("parses complete and partial proposer log lines without duplicating samples", () => { + const first = parsePreparedBlockChunk( + "", + "noise\n2026 Prepared block for proposing at 100 (1999 ms)\nPrepared block for proposing at 101 (20", + ); + assert.deepEqual(first.samples, [{ block: 100, durationMs: 1999 }]); + assert.equal(first.remainder, "Prepared block for proposing at 101 (20"); + + const second = parsePreparedBlockChunk(first.remainder, "00 ms) hash=0x1\nmalformed (5000 ms)\n"); + assert.deepEqual(second.samples, [{ block: 101, durationMs: 2000 }]); + assert.equal(second.remainder, ""); +}); + +test("flushes a final unterminated proposer line", () => { + const parsed = parsePreparedBlockChunk( + "Prepared block for proposing at #9 (4000", + " ms)", + true, + ); + assert.deepEqual(parsed.samples, [{ block: 9, durationMs: 4000 }]); +}); + +test("tails from the post-upgrade byte offset and handles appended partial lines", (context) => { + const directory = fs.mkdtempSync(path.join(os.tmpdir(), "clone-block-tail-")); + context.after(() => fs.rmSync(directory, { recursive: true, force: true })); + const filename = path.join(directory, "clone-node.log"); + fs.writeFileSync(filename, "Prepared block for proposing at 1 (9000 ms)\n"); + const postUpgradeOffset = fs.statSync(filename).size; + const tail = new NodeLogTail(filename, postUpgradeOffset); + + fs.appendFileSync(filename, "Prepared block for proposing at 2 (250"); + assert.deepEqual(tail.read(), []); + fs.appendFileSync(filename, " ms)\n"); + assert.deepEqual(tail.read(), [{ block: 2, durationMs: 250 }]); +}); + +test("excludes startup and upgrade-block proposer samples from post-upgrade enforcement", () => { + assert.deepEqual( + postUpgradeBlockSamples( + [ + { block: 40, durationMs: 9_000 }, + { block: 41, durationMs: 8_000 }, + { block: 42, durationMs: 250 }, + ], + 41, + ), + [{ block: 42, durationMs: 250 }], + ); + assert.throws(() => postUpgradeBlockSamples([], -1), /invalid runtime upgrade block/); +}); + +test("classifies warning and hard-failure boundaries and calculates nearest-rank percentiles", () => { + const summary = summarizeBlockSamples([ + { block: 1, durationMs: 100 }, + { block: 2, durationMs: 1999 }, + { block: 3, durationMs: 2000 }, + { block: 4, durationMs: 3999 }, + { block: 5, durationMs: 4000 }, + ]); + + assert.equal(summary.sampleCount, 5); + assert.equal(summary.meanMs, 2419.6); + assert.equal(summary.maximumMs, 4000); + assert.equal(summary.p50Ms, 2000); + assert.equal(summary.p95Ms, 4000); + assert.deepEqual(summary.warnings.map(({ block }) => block), [3, 4]); + assert.deepEqual(summary.violations.map(({ block }) => block), [5]); + const empty = summarizeBlockSamples([]); + assert.equal(empty.meanMs, null); + assert.equal(empty.maximumMs, null); + assert.match(blockLatencyFailureReasons(empty, 20)[0], /observed 0 proposer samples/); + assert.match(blockLatencyFailureReasons(summary, 5)[0], /1 block\(s\)/); +}); + +test("graceful monitor shutdown drains exactly to the minimum sample count", () => { + assert.equal(remainingRequiredBlockSamples(0), 20); + assert.equal(remainingRequiredBlockSamples(19), 1); + assert.equal(remainingRequiredBlockSamples(20), 0); + assert.equal(remainingRequiredBlockSamples(25), 0); + assert.throws(() => remainingRequiredBlockSamples(-1), /invalid observed/); + assert.equal(sampleDrainFailureReason(19, 119_999), undefined); + assert.match(sampleDrainFailureReason(19, 120_000) ?? "", /expected proposer log format/); + assert.equal(sampleDrainFailureReason(20, 120_000), undefined); +}); + +test("flags the 4725ms proposer duration observed on PR 3019", () => { + const parsed = parsePreparedBlockChunk( + "", + "Prepared block for proposing at 491 (4725 ms) hash=0xabc\n", + ); + const summary = summarizeBlockSamples(parsed.samples); + assert.deepEqual(summary.violations, [{ block: 491, durationMs: 4725 }]); +}); + +test("warns, recovers, and aborts best-head stalls at distinct thresholds", () => { + const liveness = new BestHeadLiveness(4_000, 12_000); + liveness.observe(10, 1_000); + assert.equal(liveness.tick(4_999).kind, "healthy"); + assert.equal(liveness.tick(5_000).kind, "warning"); + assert.equal(liveness.tick(8_000).kind, "healthy"); + + const recovered = liveness.observe(11, 8_500); + assert.equal(recovered?.durationMs, 7_500); + assert.equal(recovered?.outcome, "recovered"); + assert.equal(recovered?.endedAtMs, 8_500); + assert.equal(liveness.getStalls().length, 1); + + assert.equal(liveness.tick(20_499).kind, "warning"); + const aborted = liveness.tick(20_500); + assert.equal(aborted.kind, "abort"); + if (aborted.kind === "abort") { + assert.equal(aborted.stall.afterBlock, 11); + assert.equal(aborted.stall.durationMs, 12_000); + assert.equal(aborted.stall.outcome, "aborted"); + assert.equal(aborted.stall.endedAtMs, 20_500); + } +}); + +test("rejects a best-head regression", () => { + const liveness = new BestHeadLiveness(); + liveness.observe(20, 0); + assert.throws(() => liveness.observe(19, 1), /regressed/); +}); + +test("records a recoverable soak stall as a violation before its hard timeout", () => { + const liveness = new BestHeadLiveness(4_000, 12_000, 120_000); + liveness.observe(50, 0); + assert.equal(liveness.tick(4_000).kind, "warning"); + const violation = liveness.tick(12_000); + assert.equal(violation.kind, "violation"); + assert.equal(liveness.tick(30_000).kind, "healthy"); + + const recovered = liveness.observe(51, 30_660); + assert.equal(recovered?.durationMs, 30_660); + assert.equal(recovered?.violatedAtMs, 12_000); + assert.deepEqual(bestHeadFailureReasons(liveness.getStalls()), [ + "1 best-head stall(s) met or exceeded 12000ms", + ]); + + liveness.tick(34_660); + liveness.tick(42_660); + const aborted = liveness.tick(150_660); + assert.equal(aborted.kind, "abort"); +}); + +test("tracks complete epoch cycles and exposes removal, missing, and regression failures", () => { + const baseline: EpochBaseline[] = [ + { netuid: 1, tempo: 360, epochIndex: 4n, lastSuccessfulEpochBlock: 100n }, + { netuid: 2, tempo: 1800, epochIndex: 10n, lastSuccessfulEpochBlock: 200n }, + ]; + const tracker = new SuccessfulEpochTracker(baseline, 200); + tracker.observe(new Map([[1, 201n], [2, 201n]]), 201); + const successfulCycles = tracker.observe(new Map([[1, 202n], [2, 202n]]), 202); + const complete = evaluateEpochCoverage( + baseline, + new Map([ + [1, 6n], + [2, 12n], + ]), + new Map([[1, 202n], [2, 202n]]), + successfulCycles, + new Set([1, 2]), + 2, + ); + assert.equal(complete.complete, true); + + const incomplete = evaluateEpochCoverage( + baseline, + new Map([ + [1, 3n], + [2, 11n], + ]), + new Map([[1, 99n], [2, 201n]]), + new Map([[1, 0n], [2, 1n]]), + new Set([1]), + 2, + ); + assert.equal(incomplete.complete, false); + assert.deepEqual(incomplete.removedNetuids, [2]); + assert.deepEqual(incomplete.regressedNetuids, [1]); + + const missing = evaluateEpochCoverage( + baseline, + new Map([[1, 6n]]), + new Map([[1, 102n]]), + new Map([[1, 2n]]), + new Set([1, 2]), + 2, + ); + assert.deepEqual(missing.missingNetuids, [2]); +}); + +test("does not count skipped epoch attempts as successful coverage", () => { + const baseline: EpochBaseline[] = [ + { netuid: 7, tempo: 360, epochIndex: 10n, lastSuccessfulEpochBlock: 500n }, + ]; + const tracker = new SuccessfulEpochTracker(baseline, 500); + const successfulCycles = tracker.observe(new Map([[7, 500n]]), 501); + const skipped = evaluateEpochCoverage( + baseline, + new Map([[7, 11n]]), + new Map([[7, 500n]]), + successfulCycles, + new Set([7]), + 1, + ); + assert.equal(skipped.complete, false); + assert.deepEqual(skipped.skippedNetuids, [7]); + assert.equal(skipped.progress[0].attemptedCycles, 1n); + assert.equal(skipped.progress[0].completedCycles, 0n); +}); + +test("accepts one source-to-clone block-coordinate reset, then fails closed", () => { + const baseline: EpochBaseline[] = [ + { + netuid: 96, + tempo: 360, + epochIndex: 10n, + lastSuccessfulEpochBlock: 8_761_331n, + }, + ]; + const tracker = new SuccessfulEpochTracker(baseline, 29); + + assert.equal(tracker.observe(new Map([[96, 8_761_331n]]), 31).get(96), 0n); + assert.equal(tracker.observe(new Map([[96, 32n]]), 39).get(96), 1n); + assert.equal(tracker.observe(new Map([[96, 40n]]), 45).get(96), 2n); + assert.throws(() => tracker.observe(new Map([[96, 39n]]), 50), /regressed/); + + const invalidReset = new SuccessfulEpochTracker(baseline, 29); + assert.throws(() => invalidReset.observe(new Map([[96, 0n]]), 39), /regressed/); +}); + +test("fails closed when polling could miss more than one epoch transition", () => { + assert.equal(assertReliableEpochPollingGap(100, 109, 10), 9); + assert.throws(() => assertReliableEpochPollingGap(100, 110, 10), /not strictly below/); + assert.throws(() => assertReliableEpochPollingGap(100, 99, 10), /regressed/); +}); + +test("supports absent, cursorless instant, and multi-block migration states", () => { + assert.deepEqual( + evaluateBetaBasketV2Readiness({ + cursorExists: false, + completionFlag: false, + deferredEntriesExist: false, + }), + { + kind: "not-observed", + history: { sawCursor: false, sawDeferredEntries: false }, + }, + ); + + const instant = evaluateBetaBasketV2Readiness({ + cursorExists: false, + completionFlag: true, + deferredEntriesExist: false, + }); + assert.equal(instant.kind, "ready"); + + const migrating = evaluateBetaBasketV2Readiness({ + cursorExists: true, + completionFlag: false, + deferredEntriesExist: true, + }); + assert.equal(migrating.kind, "waiting"); + if (migrating.kind !== "waiting") { + assert.fail("expected migration to be waiting"); + } + assert.equal(migrating.stage, "migration"); + + const draining = evaluateBetaBasketV2Readiness( + { cursorExists: false, completionFlag: true, deferredEntriesExist: true }, + migrating.history, + ); + assert.equal(draining.kind, "waiting"); + if (draining.kind !== "waiting") { + assert.fail("expected deferred release to be waiting"); + } + assert.equal(draining.stage, "deferred-release"); + + const ready = evaluateBetaBasketV2Readiness( + { cursorExists: false, completionFlag: true, deferredEntriesExist: false }, + draining.history, + ); + assert.equal(ready.kind, "ready"); + assert.deepEqual(ready.history, { sawCursor: true, sawDeferredEntries: true }); + + assert.equal( + evaluateBetaBasketV2Readiness({ + cursorExists: true, + completionFlag: true, + deferredEntriesExist: false, + }).kind, + "invalid", + ); + assert.equal( + evaluateBetaBasketV2Readiness( + { cursorExists: false, completionFlag: false, deferredEntriesExist: false }, + migrating.history, + ).kind, + "invalid", + ); + assert.equal( + evaluateBetaBasketV2Readiness({ + cursorExists: false, + completionFlag: false, + deferredEntriesExist: true, + }).kind, + "invalid", + ); +}); + +test("waits through cursor completion and deferred release before reporting readiness", async () => { + const snapshots = [ + { + block: 10, + hash: "0x10", + state: { cursorExists: true, completionFlag: false, deferredEntriesExist: true }, + }, + { + block: 11, + hash: "0x11", + state: { cursorExists: false, completionFlag: true, deferredEntriesExist: true }, + }, + { + block: 12, + hash: "0x12", + state: { cursorExists: false, completionFlag: true, deferredEntriesExist: false }, + }, + ]; + const api = mockReadinessApi(snapshots); + const observation = await waitForBetaBasketV2ReleaseReadiness(api, { + deadlineEpochMs: Date.now() + 5_000, + pollIntervalMs: 1, + }); + + assert.equal(observation.mode, "multi-block"); + assert.equal(observation.startBlock, 10); + assert.equal(observation.cursorCompletionBlock, 11); + assert.equal(observation.readinessBlock, 12); + assert.equal(observation.observedBlocks, 2); + assert.equal(observation.sawCursor, true); + assert.equal(observation.sawDeferredEntries, true); +}); + +test("budgets tempo, two-per-block deferral, margin, and accelerated wall time", () => { + const baseline: EpochBaseline[] = Array.from({ length: 128 }, (_, index) => ({ + netuid: index + 1, + tempo: index === 0 ? 1800 : 360, + epochIndex: 0n, + lastSuccessfulEpochBlock: 0n, + })); + const budget = computeEpochCoverageBudget(baseline, 2, 2); + + assert.equal(budget.maxTempo, 1800); + assert.equal(budget.schedulingBlocksPerCycle, 64); + assert.equal(budget.unpaddedBlocks, 3728); + assert.equal(budget.blockBudget, 4101); + assert.equal(budget.nominalWallMs, 1_025_250); + assert.throws( + () => + computeEpochCoverageBudget( + [{ netuid: 1, tempo: 0, epochIndex: 0n, lastSuccessfulEpochBlock: 0n }], + 2, + 2, + ), + /invalid tempo/, + ); +}); + +function mockReadinessApi( + snapshots: ReadonlyArray<{ + block: number; + hash: string; + state: BetaBasketV2ReadinessSnapshot; + }>, +): ApiPromise { + assert.ok(snapshots.length > 0); + const byHash = new Map(snapshots.map((snapshot) => [snapshot.hash, snapshot.state])); + let headerIndex = 0; + const stateAt = (hash: string) => { + const state = byHash.get(hash); + assert.ok(state, `unknown mock block hash: ${hash}`); + return state; + }; + const api = { + rpc: { + chain: { + getHeader: async () => { + const snapshot = snapshots[Math.min(headerIndex, snapshots.length - 1)]; + headerIndex += 1; + return { + number: { toNumber: () => snapshot.block }, + hash: { toHex: () => snapshot.hash }, + }; + }, + }, + state: { + getStorage: async (_key: string, hash: string) => ({ + isSome: stateAt(hash).cursorExists, + }), + getKeysPaged: async (_prefix: string, _count: number, _start: string, hash: string) => + stateAt(hash).deferredEntriesExist ? ["0xentry"] : [], + }, + }, + at: async (hash: string) => ({ + query: { + subtensorModule: { + hasMigrationRun: async () => ({ + toString: () => String(stateAt(hash).completionFlag), + }), + }, + }, + }), + }; + return api as unknown as ApiPromise; +} + +test("checks the end-of-soak issuance mirror without mutating chain state", () => { + assert.doesNotThrow(() => + assertIssuanceMirror( + { balancesTotalIssuance: 123n, subtensorTotalIssuance: 123n }, + "test", + ), + ); + assert.throws( + () => + assertIssuanceMirror( + { balancesTotalIssuance: 123n, subtensorTotalIssuance: 122n }, + "test", + ), + /does not match/, + ); +}); diff --git a/clones/scripts/clone-process-supervision.sh b/clones/scripts/clone-process-supervision.sh new file mode 100644 index 0000000000..c03e119a80 --- /dev/null +++ b/clones/scripts/clone-process-supervision.sh @@ -0,0 +1,69 @@ +#!/usr/bin/env bash + +# Shared by clone jobs that run a block monitor alongside a workload. The +# monitor launcher execs Node, so SIGTERM reaches the process that owns the RPC +# subscription and lets it flush its report before exiting. + +terminate_process_tree() { + local pid=$1 child + while IFS= read -r child; do + [[ -n "$child" ]] || continue + terminate_process_tree "$child" + done < <(pgrep -P "$pid" 2>/dev/null || true) + kill -TERM "$pid" 2>/dev/null || true +} + +wait_for_monitor_ready() { + local monitor_pid=$1 ready_file=$2 timeout_seconds=${3:-60} + local elapsed_tenths=0 + + while (( elapsed_tenths < timeout_seconds * 10 )); do + [[ -s "$ready_file" ]] && return 0 + if ! kill -0 "$monitor_pid" 2>/dev/null; then + local status=0 + wait "$monitor_pid" || status=$? + if (( status == 0 )); then + echo "clone block monitor exited before becoming ready" >&2 + return 1 + fi + return "$status" + fi + sleep 0.1 + elapsed_tenths=$((elapsed_tenths + 1)) + done + + echo "clone block monitor did not become ready within ${timeout_seconds}s" >&2 + return 1 +} + +supervise_monitor_and_workload() { + local monitor_pid=$1 workload_pid=$2 description=$3 + local monitor_ended_early=false monitor_status=0 workload_status=0 + + while kill -0 "$workload_pid" 2>/dev/null; do + if ! kill -0 "$monitor_pid" 2>/dev/null; then + monitor_ended_early=true + terminate_process_tree "$workload_pid" + break + fi + sleep 1 + done + + wait "$workload_pid" || workload_status=$? + if kill -0 "$monitor_pid" 2>/dev/null; then + kill -TERM "$monitor_pid" 2>/dev/null || true + fi + wait "$monitor_pid" || monitor_status=$? + + if [[ "$monitor_ended_early" == true ]]; then + if (( monitor_status == 0 )); then + echo "clone block monitor exited before $description completed" >&2 + return 1 + fi + return "$monitor_status" + fi + if (( workload_status != 0 )); then + return "$workload_status" + fi + return "$monitor_status" +} diff --git a/clones/scripts/run-clone-block-monitor.sh b/clones/scripts/run-clone-block-monitor.sh new file mode 100755 index 0000000000..d03c6895ef --- /dev/null +++ b/clones/scripts/run-clone-block-monitor.sh @@ -0,0 +1,41 @@ +#!/usr/bin/env bash +set -euo pipefail + +SCRIPT_DIR="$(cd -- "$(dirname -- "${BASH_SOURCE[0]}")" && pwd)" +REPO_ROOT="$(cd -- "$SCRIPT_DIR/../.." && pwd)" +JS_TESTS="$REPO_ROOT/clones/js-tests" + +[[ $# -eq 3 ]] || { + echo "usage: run-clone-block-monitor.sh fail-fast|collect|baseline REPORT_LABEL START_OFFSET" >&2 + exit 2 +} +policy=$1 +report_label=$2 +start_offset=$3 +[[ "$policy" == fail-fast || "$policy" == collect || "$policy" == baseline ]] || { + echo "monitor policy must be fail-fast, collect, or baseline" >&2 + exit 2 +} +[[ "$report_label" =~ ^[A-Za-z0-9_-]+$ ]] || { + echo "report label may contain only letters, digits, underscores, and hyphens" >&2 + exit 2 +} +[[ "$start_offset" =~ ^[0-9]+$ ]] || { + echo "start offset must be a non-negative integer" >&2 + exit 2 +} + +mkdir -p "$JS_TESTS/temp" +cd "$JS_TESTS" +extra_args=() +[[ -z "${CLONE_MONITOR_ACTIVATION_REPORT:-}" ]] || extra_args+=(--activation-report "$CLONE_MONITOR_ACTIVATION_REPORT") +[[ -z "${CLONE_MONITOR_READY_FILE:-}" ]] || extra_args+=(--ready-file "$CLONE_MONITOR_READY_FILE") +[[ -z "${CLONE_MONITOR_BASELINE_REPORT:-}" ]] || extra_args+=(--baseline-report "$CLONE_MONITOR_BASELINE_REPORT") +[[ -z "${CLONE_MONITOR_DIAGNOSTIC_FILE:-}" ]] || extra_args+=(--diagnostic-file "$CLONE_MONITOR_DIAGNOSTIC_FILE") +exec node --import tsx scripts/monitor-clone-blocks.ts \ + --policy "$policy" \ + --node-log "$REPO_ROOT/clone-node.log" \ + --start-offset "$start_offset" \ + --report "$JS_TESTS/temp/clone-block-performance-${report_label}.json" \ + --log-name "clone-block-performance-${report_label}.log" \ + "${extra_args[@]}" diff --git a/clones/scripts/run-clone-epoch-soak.sh b/clones/scripts/run-clone-epoch-soak.sh new file mode 100755 index 0000000000..733cb3afd3 --- /dev/null +++ b/clones/scripts/run-clone-epoch-soak.sh @@ -0,0 +1,123 @@ +#!/usr/bin/env bash +set -euo pipefail + +SCRIPT_DIR="$(cd -- "$(dirname -- "${BASH_SOURCE[0]}")" && pwd)" +REPO_ROOT="$(cd -- "$SCRIPT_DIR/../.." && pwd)" +JS_TESTS="$REPO_ROOT/clones/js-tests" +NODE_LOG="$REPO_ROOT/clone-node.log" +source "$SCRIPT_DIR/clone-process-supervision.sh" + +[[ $# -eq 1 ]] || { echo "usage: run-clone-epoch-soak.sh EPOCH_CYCLES" >&2; exit 2; } +epoch_cycles=$1 +[[ "$epoch_cycles" =~ ^[123]$ ]] || { echo "epoch cycles must be 1, 2, or 3" >&2; exit 2; } +: "${SOAK_DEADLINE_EPOCH_MS:?SOAK_DEADLINE_EPOCH_MS is required}" +: "${SOAK_CHECKPOINT:?SOAK_CHECKPOINT is required}" +[[ "$SOAK_DEADLINE_EPOCH_MS" =~ ^[1-9][0-9]*$ ]] || { + echo "SOAK_DEADLINE_EPOCH_MS must be a positive integer" >&2 + exit 2 +} +[[ -f "$SOAK_CHECKPOINT" ]] || { echo "missing soak checkpoint: $SOAK_CHECKPOINT" >&2; exit 1; } + +minimum_post_upgrade_blocks=${MINIMUM_POST_UPGRADE_BLOCKS:-7200} +[[ "$minimum_post_upgrade_blocks" =~ ^[1-9][0-9]*$ ]] || { + echo "MINIMUM_POST_UPGRADE_BLOCKS must be a positive integer" >&2 + exit 2 +} + +baseline_monitor_report="$JS_TESTS/temp/clone-block-performance-baseline.json" +baseline_epoch_report="$JS_TESTS/temp/clone-epoch-coverage-baseline.json" +candidate_monitor_report="$JS_TESTS/temp/clone-block-performance-soak.json" +candidate_epoch_report="$JS_TESTS/temp/clone-epoch-coverage.json" +activation_report="$JS_TESTS/temp/runtime-upgrade-soak.json" +monitor_pid= +coverage_pid= + +cleanup() { + local status=$? + if [[ -n "$coverage_pid" ]]; then + terminate_process_tree "$coverage_pid" + wait "$coverage_pid" 2>/dev/null || true + fi + if [[ -n "$monitor_pid" ]]; then + kill -TERM "$monitor_pid" 2>/dev/null || true + wait "$monitor_pid" 2>/dev/null || true + fi + "$SCRIPT_DIR/stop-local-clone.sh" || true + exit "$status" +} +trap cleanup EXIT + +start_monitor() { + local policy=$1 label=$2 activation=${3:-} baseline=${4:-} + local start_offset ready_file diagnostic_file + + [[ -f "$NODE_LOG" ]] || : > "$NODE_LOG" + start_offset=$(wc -c < "$NODE_LOG" | tr -d '[:space:]') + ready_file="$JS_TESTS/temp/clone-block-monitor-$label.ready.json" + diagnostic_file="$JS_TESTS/temp/clone-block-diagnostics-$label.log" + rm -f "$ready_file" "$diagnostic_file" + CLONE_MONITOR_ACTIVATION_REPORT="$activation" \ + CLONE_MONITOR_READY_FILE="$ready_file" \ + CLONE_MONITOR_BASELINE_REPORT="$baseline" \ + CLONE_MONITOR_DIAGNOSTIC_FILE="$diagnostic_file" \ + "$SCRIPT_DIR/run-clone-block-monitor.sh" "$policy" "$label" "$start_offset" & + monitor_pid=$! + wait_for_monitor_ready "$monitor_pid" "$ready_file" +} + +run_epoch_coverage() { + local release_gate=$1 upgrade_block=$2 minimum_blocks=$3 report=$4 log_name=$5 + local status=0 + + ( + cd "$JS_TESTS" + npm run soak:epochs -- \ + --epoch-cycles "$epoch_cycles" \ + --release-gate "$release_gate" \ + --upgrade-block "$upgrade_block" \ + --minimum-post-upgrade-blocks "$minimum_blocks" \ + --deadline-epoch-ms "$SOAK_DEADLINE_EPOCH_MS" \ + --report "$report" \ + --log-name "$log_name" + ) & + coverage_pid=$! + + supervise_monitor_and_workload "$monitor_pid" "$coverage_pid" "$release_gate epoch coverage" || status=$? + coverage_pid= + monitor_pid= + return "$status" +} + +upgrade_runtime() { + rm -f "$activation_report" + ( + cd "$JS_TESTS" + npm run runtime:update:alice -- --report "$activation_report" || { + sleep 15 + npm run runtime:update:alice -- --report "$activation_report" + } + ) +} + +mkdir -p "$JS_TESTS/temp" +rm -f \ + "$baseline_monitor_report" "$baseline_epoch_report" \ + "$candidate_monitor_report" "$candidate_epoch_report" "$activation_report" + +echo "Running same-snapshot pre-upgrade latency baseline (report-only thresholds)." +"$SCRIPT_DIR/start-local-clone-and-wait.sh" accelerated +start_monitor baseline baseline +run_epoch_coverage none 0 0 "$baseline_epoch_report" clone-epoch-baseline.log + +"$SCRIPT_DIR/stop-local-clone.sh" +"$SCRIPT_DIR/local-clone-checkpoint.sh" restore "$SOAK_CHECKPOINT" + +echo "Running release-v438 post-upgrade epoch soak." +"$SCRIPT_DIR/start-local-clone-and-wait.sh" accelerated +start_monitor collect soak "$activation_report" "$baseline_monitor_report" +upgrade_runtime +upgrade_block=$(jq -er '.upgradeBlock | numbers' "$activation_report") +[[ "$upgrade_block" =~ ^[0-9]+$ ]] || { echo "invalid upgrade block: $upgrade_block" >&2; exit 1; } +run_epoch_coverage \ + beta-basket-v2 "$upgrade_block" "$minimum_post_upgrade_blocks" \ + "$candidate_epoch_report" clone-epoch-soak.log diff --git a/clones/scripts/run-clone-regression-phase.sh b/clones/scripts/run-clone-regression-phase.sh index 82e963a054..fc1cca13b8 100755 --- a/clones/scripts/run-clone-regression-phase.sh +++ b/clones/scripts/run-clone-regression-phase.sh @@ -4,6 +4,7 @@ set -euo pipefail SCRIPT_DIR="$(cd -- "$(dirname -- "${BASH_SOURCE[0]}")" && pwd)" REPO_ROOT="$(cd -- "$SCRIPT_DIR/../.." && pwd)" JS_TESTS="$REPO_ROOT/clones/js-tests" +source "$SCRIPT_DIR/clone-process-supervision.sh" usage() { echo "usage: run-clone-regression-phase.sh pristine|remaining|combined" >&2 @@ -22,6 +23,14 @@ run_sdk_drift=${RUN_SDK_DRIFT:-false} cleanup() { local status=$? + if [[ -n "${workload_pid:-}" ]]; then + terminate_process_tree "$workload_pid" + wait "$workload_pid" 2>/dev/null || true + fi + if [[ -n "${monitor_pid:-}" ]]; then + kill -TERM "$monitor_pid" 2>/dev/null || true + wait "$monitor_pid" 2>/dev/null || true + fi "$SCRIPT_DIR/stop-local-clone.sh" || true exit "$status" } @@ -32,9 +41,14 @@ start_clone() { } upgrade_runtime() { + local activation_report=$1 + rm -f "$activation_report" ( cd "$JS_TESTS" - npm run runtime:update:alice || { sleep 15; npm run runtime:update:alice; } + npm run runtime:update:alice -- --report "$activation_report" || { + sleep 15 + npm run runtime:update:alice -- --report "$activation_report" + } ) } @@ -48,9 +62,65 @@ run_regressions() { ) } +wait_for_readiness() { + local phase_name=$1 + local timeout_ms=${CLONE_READINESS_TIMEOUT_MS:-2700000} + [[ "$timeout_ms" =~ ^[1-9][0-9]*$ ]] || { + echo "CLONE_READINESS_TIMEOUT_MS must be a positive integer" >&2 + return 2 + } + ( + cd "$JS_TESTS" + npm run wait:beta-basket-v2-readiness -- \ + --label "$phase_name" \ + --timeout-ms "$timeout_ms" \ + --report "temp/clone-readiness-$phase_name.json" + ) +} + +start_block_monitor() { + local phase_name=$1 + local activation_report=$2 + local node_log="$REPO_ROOT/clone-node.log" + local start_offset ready_file diagnostic_file + + [[ -f "$node_log" ]] || : > "$node_log" + start_offset=$(wc -c < "$node_log" | tr -d '[:space:]') + ready_file="$JS_TESTS/temp/clone-block-monitor-$phase_name.ready.json" + diagnostic_file="$JS_TESTS/temp/clone-block-diagnostics-$phase_name.log" + rm -f "$ready_file" "$diagnostic_file" + CLONE_MONITOR_ACTIVATION_REPORT="$activation_report" \ + CLONE_MONITOR_READY_FILE="$ready_file" \ + CLONE_MONITOR_DIAGNOSTIC_FILE="$diagnostic_file" \ + "$SCRIPT_DIR/run-clone-block-monitor.sh" fail-fast "$phase_name" "$start_offset" & + monitor_pid=$! + wait_for_monitor_ready "$monitor_pid" "$ready_file" +} + +run_monitored_workload() { + local phase_name=$1 + shift + local status=0 + + "$@" & + workload_pid=$! + + supervise_monitor_and_workload "$monitor_pid" "$workload_pid" "$phase_name workload" || status=$? + workload_pid= + monitor_pid= + return "$status" +} + run_pristine() { + local activation_report="$JS_TESTS/temp/runtime-upgrade-pristine.json" start_clone - upgrade_runtime + start_block_monitor pristine "$activation_report" + upgrade_runtime "$activation_report" + run_monitored_workload pristine run_pristine_workload +} + +run_pristine_workload() { + wait_for_readiness pristine run_regressions pristine } @@ -67,9 +137,8 @@ run_sdk_metadata_drift() { ) } -run_remaining() { - start_clone - upgrade_runtime +run_remaining_workload() { + wait_for_readiness remaining ( cd "$JS_TESTS" npm test @@ -78,6 +147,14 @@ run_remaining() { run_sdk_metadata_drift } +run_remaining() { + local activation_report="$JS_TESTS/temp/runtime-upgrade-remaining.json" + start_clone + start_block_monitor remaining "$activation_report" + upgrade_runtime "$activation_report" + run_monitored_workload remaining run_remaining_workload +} + case "$phase" in pristine) run_pristine