diff --git a/.github/workflows/performance-ab.yml b/.github/workflows/performance-ab.yml index 320e11c77..cf9fb8037 100644 --- a/.github/workflows/performance-ab.yml +++ b/.github/workflows/performance-ab.yml @@ -30,9 +30,9 @@ on: workflow_dispatch: inputs: duration: - description: "warp duration per round" + description: "warp duration per round (short by default to fit the double-build budget)" required: false - default: "30s" + default: "12s" type: string allow_regression: description: "Pass the gate despite a FAIL (deliberate tradeoff)" @@ -69,7 +69,12 @@ jobs: (contains(github.event.pull_request.labels.*.name, 'perf-ab') && (github.event.action != 'labeled' || github.event.label.name == 'perf-ab')) runs-on: sm-standard-2 - timeout-minutes: 90 + # Phase-0 stopgap: the baseline+candidate release double-build alone is + # ~65min on this runner, so 90min left no room for a real full-matrix + # measurement (the earlier nightly runs only ever failed *before* + # measuring). 120min gives the 24-cell short matrix headroom until perf-3 + # caches the baseline binary and restores a tighter budget. + timeout-minutes: 120 steps: - name: Checkout repository uses: actions/checkout@9c091bb21b7c1c1d1991bb908d89e4e9dddfe3e0 # v7 @@ -109,7 +114,17 @@ jobs: id: ab run: | set -euo pipefail - args=(--baseline-ref origin/main --duration "${{ github.event.inputs.duration || '30s' }}") + # Budget note: the baseline+candidate release double-build (~65 min, + # cached away later by perf-3) dominates the 90-min job, so the + # measurement runs a short warp matrix — duration/rounds/cooldown are + # kept small to fit all 24 cells (6 workloads x 2 phases x 2 drive-sync) + # under budget rather than dropping cells. --health-timeout 180 outlasts + # the server's own 120s startup-readiness budget, which is what the + # rig's previous 60s health poll undershot (the first two nightly + # failures). perf-6 will recalibrate these once the pipeline is green. + duration="${{ github.event.inputs.duration || '12s' }}" + args=(--baseline-ref origin/main + --duration "$duration" --rounds 2 --cooldown 5 --health-timeout 180) if [[ "${{ steps.exempt.outputs.allow_regression }}" == "true" ]]; then args+=(--allow-regression --exemption-reason "labeled perf-deliberate-tradeoff / dispatch override") fi @@ -119,7 +134,14 @@ jobs: bash scripts/run_hotpath_warp_ab.sh "${args[@]}" echo "status=$?" >> "$GITHUB_OUTPUT" set -e - # Locate the newest gate.md for the comment/artifact steps. + # Locate the newest run dir + gate.md for the summary/comment/artifact + # steps. On a startup failure there is no gate.md, but the run dir still + # holds server-logs/ for diagnosis. + # Run dirs are UTC-timestamp names (no special chars); ls is safe here. + # shellcheck disable=SC2012 + run_dir="$(ls -td target/hotpath-ab/*/ 2>/dev/null | head -n1 || true)" + echo "run_dir=${run_dir%/}" >> "$GITHUB_OUTPUT" + # shellcheck disable=SC2012 gate_md="$(ls -t target/hotpath-ab/*/gate.md 2>/dev/null | head -n1 || true)" echo "gate_md=$gate_md" >> "$GITHUB_OUTPUT" @@ -128,8 +150,49 @@ jobs: uses: actions/upload-artifact@b7c566a772e6b6bfb58ed0dc250532a479d7789f # v6 with: name: hotpath-warp-ab-${{ github.run_number }} + # Includes per-cell median_summary.csv / baseline_compare.csv, gate.md, + # and server-logs/ (rustfs.log + startup env per phase) so a failed run + # is diagnosable. Short retention: this is churny nightly debug data. path: target/hotpath-ab/ if-no-files-found: warn + retention-days: 14 + + - name: Write gate summary + if: always() + run: | + set -euo pipefail + status="${{ steps.ab.outputs.status }}" + gate_md="${{ steps.ab.outputs.gate_md }}" + run_dir="${{ steps.ab.outputs.run_dir }}" + { + echo "## Hotpath warp A/B — run ${{ github.run_number }}" + echo + if [[ "$status" == "0" ]]; then + echo "Rig/gate exit: \`0\` (pass or warn)." + else + echo "Rig/gate exit: \`${status:-unknown}\` — **FAILED**." + fi + echo + if [[ -n "$gate_md" && -f "$gate_md" ]]; then + cat "$gate_md" + else + echo "No \`gate.md\` produced — the rig failed **before** the gate" + echo "(most likely server startup / health). Failing phase(s) below;" + echo "full logs in the \`hotpath-warp-ab-${{ github.run_number }}\` artifact." + if [[ -n "$run_dir" && -d "$run_dir/server-logs" ]]; then + for f in "$run_dir"/server-logs/*.log; do + [[ -f "$f" ]] || continue + echo + echo "
$(basename "$f")" + echo + echo '```' + tail -n 30 "$f" + echo '```' + echo "
" + done + fi + fi + } >> "$GITHUB_STEP_SUMMARY" - name: Comment gate result on PR if: always() && github.event_name == 'pull_request' && steps.ab.outputs.gate_md != '' @@ -138,12 +201,19 @@ jobs: run: | gh pr comment "${{ github.event.pull_request.number }}" --body-file "${{ steps.ab.outputs.gate_md }}" + # TODO(ci-8/perf-2): scheduled/dispatch failures are currently silent. Once + # ci-8 lands the .github/actions/schedule-failure-issue composite action, + # perf-2 adds a step here guarded by + # if: failure() && github.event_name != 'pull_request' + # that calls it (label perf-nightly-failure, append to an existing open + # issue) instead of hand-rolling gh CLI dedup. Do not implement it here. + - name: Enforce gate if: always() run: | status="${{ steps.ab.outputs.status }}" if [[ "$status" != "0" ]]; then - echo "::error::warp A/B budget gate failed (exit $status). See the PR comment / gate.md artifact." >&2 + echo "::error::warp A/B budget gate failed (exit $status). See the step summary / PR comment / gate.md artifact." >&2 exit "$status" fi echo "warp A/B budget gate passed." diff --git a/docs/operations/hotpath-warp-ab-runbook.md b/docs/operations/hotpath-warp-ab-runbook.md index 8bb2f484b..0d5affed9 100644 --- a/docs/operations/hotpath-warp-ab-runbook.md +++ b/docs/operations/hotpath-warp-ab-runbook.md @@ -23,6 +23,29 @@ Metric directions: `reqps` (put obj/s) and `throughput` (get MiB/s) are higher-is-better; `latency` / p99 (mixed) is lower-is-better. warp is assumed pre-installed, as elsewhere in `scripts/`. +## Workload matrix + +Six workloads × the drive-sync on/off matrix × baseline/candidate = 24 cells: + +| Workload | mode | size | why | +| --- | --- | --- | --- | +| `put-4kib` / `get-4kib` | put / get | 4KiB | the #4221 fsync regression size (~-10% @4KiB) — previously invisible | +| `put-4mib` / `get-4mib` | put / get | 4MiB | bulk obj/s and MiB/s | +| `get-10mib` | get | 10MiB | the historical large-GET EOF size | +| `mixed-256k` | mixed | 256KiB | p99 latency | + +Sizes are passed to the load driver via `--sizes` (one size per cell); the +driver's `DEFAULT_SIZES` covers 1KiB..10MiB, so any of those can be added by +editing `WORKLOADS` in `scripts/run_hotpath_warp_ab.sh`. A 1KiB cell is left +out for now to keep the nightly matrix under the 90-minute job budget (the +baseline+candidate double build dominates until perf-3 caches it); re-enable it +once that lands. + +CI runs a **short** warp matrix (`--duration`/`--rounds`/`--cooldown` tuned in +`.github/workflows/performance-ab.yml`) so all 24 cells fit the budget without +dropping cells. These params are deliberately noisy-but-fast for the Phase-0 +"keep the pipeline alive" goal; perf-6 recalibrates them. + ## Local mode (quick / CI smoke) Builds both binaries and runs a throwaway single-node server on local disks. @@ -94,6 +117,22 @@ cost to restore power-loss durability. For those, run with `--allow-regression` (or add the `perf-deliberate-tradeoff` label in CI): the FAIL is recorded and rendered as an exempted WARN, and the gate exits 0. +## Diagnosing a failed run + +Each phase's server log and its startup environment are written under the run's +output dir (`target/hotpath-ab//server-logs/-sync-.{log,env}`) +and uploaded in the `hotpath-warp-ab-` artifact, so a failure is +diagnosable after the fact. On a health-check failure the rig also dumps the +last 50 log lines into the job log and the CI job writes the failing phase (or +the gate table) into the GitHub step summary. + +Readiness polling waits up to `--health-timeout` seconds (default **180**), +which must outlast the server's own startup-readiness budget +(`RUSTFS_STARTUP_READINESS_MAX_WAIT_SECS`, default 120s) — a shorter poll on a +slow shared runner mis-reports a slow cold start as a failure. In local mode the +rig also fails fast if the server process exits before becoming healthy instead +of polling out the full budget. + ## Scope note The gate logic is unit-validated across pass/warn/fail/exempt outcomes; the diff --git a/scripts/run_hotpath_warp_ab.sh b/scripts/run_hotpath_warp_ab.sh index 0d1395ec5..d5374ed62 100755 --- a/scripts/run_hotpath_warp_ab.sh +++ b/scripts/run_hotpath_warp_ab.sh @@ -41,6 +41,7 @@ DISKS=4 CONCURRENCY=8 DURATION="30s" ROUNDS=3 +COOLDOWN_SECS="" # empty -> load driver default; CI passes a short value LOCAL_ADDRESS="127.0.0.1:9000" ACCESS_KEY="rustfsadmin" SECRET_KEY="rustfsadmin" @@ -57,9 +58,32 @@ SKIP_BUILD="false" EXTERNAL_ENDPOINT="" # set -> external mode (warp targets this cluster) DEPLOY_HOOK="" # external mode: command to deploy a phase's binary HEALTH_PATH="/health" +# Readiness poll budget. The server binds its public listener only after startup +# converges (erasure-format load + IAM); its own budget is +# RUSTFS_STARTUP_READINESS_MAX_WAIT_SECS (default 120s). Polling must outlast +# that, otherwise a slow cold start on a shared CI runner looks like a failure — +# this is exactly what killed the first two nightly runs (60s poll < 120s +# startup budget). Default 180s; override with --health-timeout. +HEALTH_TIMEOUT_SECS=180 -# Workloads: name|warp-mode|size. put-4mib obj/s, get-4mib MiB/s, mixed-256k p99. -WORKLOADS=("put-4mib|put|4MiB" "get-4mib|get|4MiB" "mixed-256k|mixed|256KiB") +# Workloads: name|warp-mode|size. +# put-4kib / get-4kib — the #4221 fsync regression size (~-10% @4KiB), invisible +# until now; put-4mib / get-4mib — bulk obj/s & MiB/s; get-10mib — the historical +# large-GET EOF size; mixed-256k — p99 latency. +# Tradeoff: 6 workloads × 2 phases × 2 drive-sync = 24 cells. Until perf-3 caches +# the baseline binary (the ~65min double build dominates the 90min job), CI keeps +# the matrix under budget with short warp params (--duration/--rounds/--cooldown +# passed by the workflow), NOT by dropping cells. A 1KiB cell (optional per +# perf-1) is deferred until that caching frees wall-clock; re-enable by adding +# e.g. "put-1kib|put|1KiB" here. +WORKLOADS=( + "put-4kib|put|4KiB" + "put-4mib|put|4MiB" + "get-4kib|get|4KiB" + "get-4mib|get|4MiB" + "get-10mib|get|10MiB" + "mixed-256k|mixed|256KiB" +) # Durability matrix: label|RUSTFS_DRIVE_SYNC_ENABLE value. DRIVE_SYNC_MATRIX=("sync-on|true" "sync-off|false") @@ -87,6 +111,9 @@ Common: --concurrency warp --concurrent (default 8). --duration warp --duration (default 30s). --rounds Rounds per cell for the median (default 3). + --cooldown Seconds between rounds/sizes, forwarded to the load + driver (default: driver default, 20s). + --health-timeout Seconds to poll readiness after bring-up (default 180). --fail-pct Gate fail budget (default 10). --warn-pct Gate warn budget (default 5). --allow-regression Pass the gate despite a FAIL (deliberate tradeoff). @@ -109,6 +136,8 @@ while [[ $# -gt 0 ]]; do --concurrency) CONCURRENCY="$2"; shift 2 ;; --duration) DURATION="$2"; shift 2 ;; --rounds) ROUNDS="$2"; shift 2 ;; + --cooldown) COOLDOWN_SECS="$2"; shift 2 ;; + --health-timeout) HEALTH_TIMEOUT_SECS="$2"; shift 2 ;; --fail-pct) FAIL_PCT="$2"; shift 2 ;; --warn-pct) WARN_PCT="$2"; shift 2 ;; --allow-regression) ALLOW_REGRESSION="true"; shift ;; @@ -184,7 +213,13 @@ else fi # --- Deployment: bring a phase up, tear it down ----------------------------- +# Server logs live under OUT_DIR (not $DATA_ROOT) so they ride along in the CI +# artifact and the run is diagnosable after the fact — the missing piece that +# left the first nightly failures unexplained. +SERVER_LOG_DIR="$OUT_DIR/server-logs" +run mkdir -p "$SERVER_LOG_DIR" SERVER_PID="" +SERVER_LOG="" tear_down() { # Local mode owns the server process; external mode leaves lifecycle to the # deploy hook / cluster orchestrator. @@ -195,14 +230,32 @@ tear_down() { } trap tear_down EXIT INT TERM +# Dump the tail of the current server log to stderr (job log) so a startup +# failure is visible without downloading the artifact. +dump_server_log() { + [[ -n "$SERVER_LOG" && -f "$SERVER_LOG" ]] || return 0 + echo "----- last 50 lines of $SERVER_LOG -----" >&2 + tail -n 50 "$SERVER_LOG" >&2 || true + echo "----------------------------------------" >&2 +} + wait_health() { [[ "$DRY_RUN" == "true" ]] && return 0 local i - for ((i = 0; i < 60; i++)); do + for ((i = 0; i < HEALTH_TIMEOUT_SECS; i++)); do + # Local mode owns the process: if it already exited (port bind failure, + # panic, disk-check abort), stop polling and surface the log immediately + # instead of waiting out the full budget. + if [[ "$EXTERNAL" != "true" && -n "$SERVER_PID" ]] && ! kill -0 "$SERVER_PID" 2>/dev/null; then + echo "error: rustfs server (pid $SERVER_PID) exited before becoming healthy after ${i}s" >&2 + dump_server_log + return 1 + fi if curl -fsS "http://${ADDRESS}${HEALTH_PATH}" >/dev/null 2>&1; then return 0; fi sleep 1 done - echo "error: endpoint http://${ADDRESS}${HEALTH_PATH} did not become healthy" >&2 + echo "error: endpoint http://${ADDRESS}${HEALTH_PATH} did not become healthy within ${HEALTH_TIMEOUT_SECS}s" >&2 + dump_server_log return 1 } @@ -224,12 +277,26 @@ bring_up() { local disks=() d for ((d = 1; d <= DISKS; d++)); do disks+=("$node_dir/d$d"); done run mkdir -p "${disks[@]}" + SERVER_LOG="$SERVER_LOG_DIR/$phase-sync-$drive_sync.log" if [[ "$DRY_RUN" == "true" ]]; then { printf 'DRY-RUN: RUSTFS_DRIVE_SYNC_ENABLE=%s %q server' "$drive_sync" "$bin" printf ' %q' "${disks[@]}"; printf '\n'; } >&2 SERVER_PID="dry-run" return 0 fi + # Record the startup environment next to the log so a failed run is + # self-explanatory in the artifact. + cat >"$SERVER_LOG_DIR/$phase-sync-$drive_sync.env" </dev/null || echo unknown) +warp_version=$("$WARP_BIN" --version 2>/dev/null | head -n1 || echo unknown) +EOF RUSTFS_UNSAFE_BYPASS_DISK_CHECK=true \ RUSTFS_ADDRESS="$ADDRESS" \ RUSTFS_ACCESS_KEY="$ACCESS_KEY" \ @@ -237,7 +304,7 @@ bring_up() { RUSTFS_REGION="$REGION" \ RUSTFS_CONSOLE_ENABLE=false \ RUSTFS_DRIVE_SYNC_ENABLE="$drive_sync" \ - "$bin" server "${disks[@]}" >"$node_dir/rustfs.log" 2>&1 & + "$bin" server "${disks[@]}" >"$SERVER_LOG" 2>&1 & SERVER_PID=$! wait_health } @@ -254,6 +321,7 @@ measure() { --region "$REGION" --sizes "$size" --concurrency "$CONCURRENCY" --duration "$DURATION" --rounds "$ROUNDS" --out-dir "$cell" ) + [[ -n "$COOLDOWN_SECS" ]] && args+=(--cooldown-secs "$COOLDOWN_SECS") [[ -n "$baseline_csv" ]] && args+=(--baseline-csv "$baseline_csv") run "$ENHANCED_BENCH" "${args[@]}" echo "$cell"