diff --git a/experiments/DISCUSSION-NOTES.md b/experiments/DISCUSSION-NOTES.md index 299431a2b..244dce1f9 100644 --- a/experiments/DISCUSSION-NOTES.md +++ b/experiments/DISCUSSION-NOTES.md @@ -176,17 +176,87 @@ Scaling is slightly super-linear for GraphQL (2.46x for 2x sessions). Guard chec **Scorecard:** `experiments/out/scorecard-quiet-steady.single-repo.20-1776424159.json` **Trace:** `experiments/out/gh-trace-bench-1776423135.jsonl` -### Key Finding: Sub-Linear Scaling +### 30-Session Benchmark (2026-04-17, B1 fix applied) -GraphQL cost barely increased from 10→20 sessions (640→680, +6%). The guard-pr-list check is repo-scoped (constant 30 checks regardless of session count), and graphql-batch stays at 0 during steady state. Most of the per-session cost comes from opaque `gh pr view/checks` subcommands which are individually cheap. +| Metric | Value | +|--------|-------| +| GraphQL points/hr | 900 / 5,000 (18%) | +| REST core requests/hr | 0 / 5,000 (0%) | +| Total GH calls | 857 (57.1/min) | +| graphql-batch count | **0** | +| guard-pr-list 304s | 16 (100.0%) | +| Poll cycle (mean) | **53s** (1.8x the 30s target) | +| p50 / p95 / p99 latency | 787 / 4,317 / 5,437 ms | -**Revised 50-session projection:** ~800–1,000 GraphQL pts/hr (16–20% of budget). Far better than the earlier 64% estimate. **B2 structural reductions are NOT required for quiet-steady state.** The 50-session target is safely achievable with B1 alone. +**Scorecard:** `experiments/out/scorecard-quiet-steady.single-repo.30-1776439031.json` +**Trace:** `experiments/out/gh-trace-bench-1776438003.jsonl` (983 rows) + +### 40-Session Benchmark (2026-04-17, B1 fix applied) + +| Metric | Value | +|--------|-------| +| GraphQL points/hr | 1,140 / 5,000 (23%) | +| REST core requests/hr | 0 / 5,000 (0%) | +| Total GH calls | 1,094 (72.9/min) | +| graphql-batch count | **0** | +| guard-pr-list 304s | 15 (100.0%) | +| Poll cycle (mean) | **58s** (1.9x the 30s target) | +| p50 / p95 / p99 latency | 1,014 / 4,910 / 5,147 ms | + +**Scorecard:** `experiments/out/scorecard-quiet-steady.single-repo.40-1776440122.json` +**Trace:** `experiments/out/gh-trace-bench-1776439097.jsonl` (1,255 rows) + +### 50-Session Benchmark (2026-04-17, B1 fix applied) + +| Metric | Value | +|--------|-------| +| GraphQL points/hr | ~1,400 / 5,000 (28%) — estimated (rate limit reset straddled window) | +| REST core requests/hr | 0 / 5,000 (0%) | +| Total GH calls | 1,338 (89.2/min) | +| graphql-batch count | **0** | +| guard-pr-list 304s | 12 (100.0%) | +| Poll cycle (mean) | **66s** (2.2x the 30s target) | +| p50 / p95 / p99 latency | 3,441 / 7,610 / 9,684 ms | + +**Scorecard:** `experiments/out/scorecard-quiet-steady.single-repo.50-1776441230.json` +**Trace:** `experiments/out/gh-trace-bench-1776440201.jsonl` (1,519 rows) + +### Complete Scaling Curve (5 → 50 sessions) + +| Sessions | Calls/min | GraphQL pts/hr | Poll cycle | Batch calls | Guard 304% | p50 | p99 | +|----------|-----------|----------------|------------|-------------|------------|-----|-----| +| 5 | 16.7 | 260 (5%) | ~30s | 0 | 100% | 746ms | 1,261ms | +| 10 | 31.3 | 640 (13%) | ~30s | 0 | 100% | 803ms | 2,509ms | +| 20 | 60.7 | 680 (14%) | ~30s | 0 | 100% | 761ms | 3,052ms | +| 30 | 57.1 | 900 (18%) | 53s | 0 | 100% | 787ms | 5,437ms | +| 40 | 72.9 | 1,140 (23%) | 58s | 0 | 100% | 1,014ms | 5,147ms | +| 50 | 89.2 | ~1,400 (28%) | 66s | 0 | 100% | 3,441ms | 9,684ms | + +### Key Findings: Capacity Discovery + +**1. Rate limit is NOT the bottleneck.** Even at 50 sessions, GraphQL consumption is ~28% of budget. The B1 fix + ETag guards eliminated the original problem completely. ETag guard hit rate is 100% at every scale — zero batch calls during steady state. + +**2. Poll cycle lag is the first real bottleneck.** The lifecycle manager runs a sequential loop processing all sessions. At 30+ sessions, it can no longer complete a cycle within the 30s target: + +| Sessions | Poll cycle | Ratio to target | +|----------|-----------|-----------------| +| 5-20 | ~30s | 1.0x | +| 30 | 53s | 1.8x | +| 40 | 58s | 1.9x | +| 50 | 66s | 2.2x | + +**3. API latency degrades at scale.** p50 latency goes from <1s at 5-20 sessions to 3.4s at 50 sessions. p99 goes from 1.3s to 9.7s. This is likely subprocess contention from running 50+ `gh` CLI processes. + +**4. Per-session opaque calls are the dominant cost.** At 50 sessions, 700 of 1,338 calls (52%) are per-session `gh.api.repos` and `gh.api.graphql` calls. `guard-commit-status` contributes another 700+ calls. The batch/guard-pr-list system is repo-scoped and barely contributes. + +**5. The 50-session target is achieved for rate limits.** The original goal (50+ sessions on a single PAT) is safely met. The remaining bottlenecks are local infrastructure (poll cycle, latency), not GitHub API limits. **Key harness implementation notes:** - Creates placeholder tmux sessions with a `claude` symlink → `/bin/sleep 86400` so lifecycle polls sessions instead of short-circuiting to "killed" - macOS `/bin/sleep` doesn't accept `infinity` — use `86400` (24h) - Must set `AO_CONFIG_PATH` to the todo-app config when running from the AO repo directory - The todo-app config auto-infers `scm: { plugin: "github" }` from the `repo` field +- **Harness bug found:** measure mode doesn't reset `status=killed` in session metadata. Must manually `sed` before re-runs if sessions were marked killed by a prior run. --- @@ -214,5 +284,7 @@ GraphQL cost barely increased from 10→20 sessions (640→680, +6%). The guard- 1. ~~**B1 PR comment to Adil** — drafted, not yet posted.~~ ✅ Posted. Awaiting Adil's independent verification run. 2. **Benchmark with bugbot/CI** — Dhruv enabled bugbot on todo-app. Want to verify empirically that CI/reviews don't change polling cost. 3. **Blocker #5 (sessionId/projectId threading)** — deferred. Needed for per-session attribution in the remaining A2 matrix cells. -4. **Scale-up validation (10, 20 sessions)** — next step. Can run locally now without waiting for Adil. Replaces extrapolation with measured data. -5. **50-session validation** — target tier, not first measurement tier. Get real data at 5/10/20 first. +4. ~~**Scale-up validation (10, 20 sessions)**~~ ✅ Done. Full curve 5→50 measured. +5. ~~**50-session validation**~~ ✅ Done. Rate limit target met; poll cycle lag identified as next bottleneck. +6. **Poll cycle optimization** — lifecycle manager processes sessions sequentially. At 30+ sessions, the cycle exceeds the 30s target. Potential fixes: parallelize per-session checks, reduce per-session work, or make poll interval adaptive. +7. **Harness bug: session status reset** — measure mode should reset `status=killed` to `status=mergeable` before starting. diff --git a/experiments/PLAN.md b/experiments/PLAN.md index e480ed8a9..b1315d945 100644 --- a/experiments/PLAN.md +++ b/experiments/PLAN.md @@ -97,10 +97,14 @@ Track B ── Fix bugs ────────────────── — Verified: 100% guard 304 rate, 0 graphql-batch calls in quiet-steady — Awaiting Adil's independent verification (PR comment posted) B2 Structural reductions (detectPR dedup, batch) ⏳ Blocked on B1 verification - B3 Scale-up validation (10, 20 sessions) ✅ Done — sub-linear scaling confirmed - 5→260, 10→640, 20→680 GraphQL pts/hr - 50-session projection: ~800-1000 pts/hr (16-20% budget) - B2 structural reductions NOT required for quiet-steady + B3 Scale-up validation (5→50 sessions) ✅ Done — full capacity discovery complete + 5→260, 10→640, 20→680, 30→900, 40→1140, 50→~1400 GraphQL pts/hr + Rate limit target MET: 50 sessions = ~28% of GraphQL budget + ETag guard 304 rate: 100% at every scale, 0 batch calls + First bottleneck: poll cycle lag (66s at 50 sessions vs 30s target) + Second bottleneck: API latency (p50=3.4s, p99=9.7s at 50 sessions) + B2 structural reductions NOT required for quiet-steady rate limits + B4 Poll cycle optimization (NEW) ⏳ Next — lifecycle processes sessions sequentially Track C ── Octokit migration (optional) ───────────────────────────────── C1 OctokitRunner behind flag + compare ⏳ Blocked on B scorecard diff --git a/experiments/ci-churn.sh b/experiments/ci-churn.sh new file mode 100755 index 000000000..3556a8a8d --- /dev/null +++ b/experiments/ci-churn.sh @@ -0,0 +1,78 @@ +#!/usr/bin/env bash +# ci-churn.sh — Push empty commits to PRs during a benchmark measurement window. +# +# Usage: +# ./experiments/ci-churn.sh --sessions 10 --interval 60 --duration 900 [--delay 0] +# +# This pushes an empty commit to each of the first N session worktrees, +# one every INTERVAL seconds, cycling through them repeatedly for DURATION seconds. +# Each push invalidates the ETag cache for that PR's commit status, +# forcing a full graphql-batch re-fetch on the next poll cycle. +# +# Run this in PARALLEL with the benchmark's measurement window. +# Use --delay to wait before starting (e.g., to skip warmup). + +set -euo pipefail + +WORKTREE_BASE="$HOME/.worktrees/todo-app" +SESSIONS=10 +INTERVAL=60 +DURATION=900 +DELAY=0 + +while [[ $# -gt 0 ]]; do + case "$1" in + --sessions) SESSIONS="$2"; shift 2 ;; + --interval) INTERVAL="$2"; shift 2 ;; + --duration) DURATION="$2"; shift 2 ;; + --delay) DELAY="$2"; shift 2 ;; + *) echo "Unknown flag: $1" >&2; exit 1 ;; + esac +done + +echo "[ci-churn] Config: sessions=$SESSIONS interval=${INTERVAL}s duration=${DURATION}s delay=${DELAY}s" + +if [ "$DELAY" -gt 0 ]; then + echo "[ci-churn] Waiting ${DELAY}s before starting..." + sleep "$DELAY" +fi + +START=$(date +%s) +END=$((START + DURATION)) +PUSH_COUNT=0 +SESSION_IDX=1 + +echo "[ci-churn] Started at $(date -u +%Y-%m-%dT%H:%M:%SZ)" + +while [ "$(date +%s)" -lt "$END" ]; do + WORKTREE="$WORKTREE_BASE/ta-$SESSION_IDX" + + if [ -d "$WORKTREE/.git" ] || [ -f "$WORKTREE/.git" ]; then + echo "[ci-churn] Pushing empty commit to ta-$SESSION_IDX..." + ( + cd "$WORKTREE" + git commit --allow-empty -m "bench: ci-churn push $PUSH_COUNT ($(date -u +%H:%M:%S))" 2>/dev/null + git push origin HEAD 2>/dev/null + ) && echo "[ci-churn] ✓ ta-$SESSION_IDX pushed" \ + || echo "[ci-churn] ✗ ta-$SESSION_IDX failed" + PUSH_COUNT=$((PUSH_COUNT + 1)) + else + echo "[ci-churn] ✗ ta-$SESSION_IDX worktree not found, skipping" + fi + + # Cycle through sessions + SESSION_IDX=$((SESSION_IDX + 1)) + if [ "$SESSION_IDX" -gt "$SESSIONS" ]; then + SESSION_IDX=1 + fi + + # Wait for next interval (but check if we've exceeded duration) + REMAINING=$((END - $(date +%s))) + if [ "$REMAINING" -gt "$INTERVAL" ]; then + sleep "$INTERVAL" + elif [ "$REMAINING" -gt 0 ]; then + sleep "$REMAINING" + fi +done + +echo "[ci-churn] Done. Total pushes: $PUSH_COUNT over ${DURATION}s"