diff --git a/.github/workflows/budget-poller.yml b/.github/workflows/budget-poller.yml index a363c3b55..d19566239 100644 --- a/.github/workflows/budget-poller.yml +++ b/.github/workflows/budget-poller.yml @@ -15,12 +15,15 @@ # • Fail-open: a failed poll is a DEGRADED record + warning, never a red run. # ───────────────────────────────────────────────────────────────────────────── name: Budget Poller (dry-run) -# readme-report: Dry-run Claude budget poller — reads the usage windows hourly, logs what the token-budget breaker would do (never sets a variable), and proves the feed is alive (#2029). +# readme-report: Dry-run Claude budget poller — reads the usage windows twice hourly, logs what the token-budget breaker would do (never sets a variable), and proves the feed is alive (#2029). on: schedule: - # Hourly at :17 — off the top of the hour (schedule standard). + # Twice hourly at :17 and :47 — off the top of the hour (schedule standard). + # Two slots because GitHub delivers only ~40% of scheduled ticks in this repo + # (#2160); the concurrency group below keeps them from overlapping. - cron: '17 * * * *' + - cron: '47 * * * *' # No workflow_dispatch: a manual dispatch can run branch code that receives the # Claude OAuth secret. `schedule` only ever runs the default branch's workflow. @@ -99,6 +102,8 @@ jobs: CLAUDE_CODE_OAUTH_TOKEN: ${{ secrets.CLAUDE_CODE_OAUTH_TOKEN }} BUDGET_POLLER_PUBLIC_LIB: public/scripts/lib/agent-rate-limit.sh AGENT_RATE_LIMITS_CONFIG: public/standards/agent-rate-limits.json + # The cron that fired, recorded to measure delivery (#2160). + BUDGET_POLLER_CRON: ${{ github.event.schedule }} run: bash scripts/budget_poller.sh - name: Upload the poll log diff --git a/AGENTS.md b/AGENTS.md index b5afbeaaf..cd0ed5505 100644 --- a/AGENTS.md +++ b/AGENTS.md @@ -776,7 +776,9 @@ is to keep degrading from moving the outage onto an unmetered provider. plus the cooldowns recorded. **Dry-run budget poller (shipped, #2029: slice 2 of #1565). It is dry-run only and has no -write path.** `.github/workflows/budget-poller.yml` runs hourly (`:17`) with read-only `permissions:` (`contents: read`, `actions: read`). +write path.** `.github/workflows/budget-poller.yml` runs on two hourly cron slots (`:17` and `:47`) with read-only `permissions:` (`contents: read`, `actions: read`). +It is schedule-only (no `workflow_dispatch`). The second slot exists because GitHub delivers only about 40% of +scheduled ticks in this repo (#2160); the `budget-poller` concurrency group keeps the slots from overlapping. It authenticates with the existing `CLAUDE_CODE_OAUTH_TOKEN` secret. It does **not** set, clear, or write any Actions variable (org or repo) under any input, and there is no flag to make it do so. `tests/dev-lead/unit/test_budget_poller.bats` asserts @@ -794,7 +796,7 @@ pending the pause-vs-degrade decision. - **Where the log lives:** each run appends one JSON line to `budget-poller-log.jsonl` and uploads it as the **`budget-poller-log`** artifact (14-day retention). Each run downloads the previous artifact first, so the newest artifact holds the rolling - history (bounded to 720 records ≈ 30 days). The run's **job summary** shows the same + history (bounded to 720 records ≈ 15 days at two slots an hour). The run's **job summary** shows the same record as a table. - **How to read it:** each record carries `ts`, `http_status`, `retry_after`, `session_pct`, `weekly_all_pct`, both windows' `*_resets_at`, `session_decision`, @@ -809,12 +811,22 @@ pending the pause-vs-degrade decision. `http-`, `malformed-body`, `public-library-unavailable`). A degraded poll is a `::warning::`, never a red run (fail-open), and never reads as OK. Example: `jq -c 'select(.poll=="ok") | [.ts,.session_pct,.weekly_all_pct,.decision_window]' budget-poller-log.jsonl`. +- **Measured delivery (#2160):** each record also carries `trigger_event` (`GITHUB_EVENT_NAME`), + `trigger_cron` (the cron that fired, from `github.event.schedule`), `scheduled_for` / + `scheduled_epoch` (the `:17` or `:47` slot the run was meant for), and `start_delay_s` + (poll time `ts` minus that slot). A delay over an hour aliases onto a later slot, so it is a + lower bound. Records written before #2160 lack these fields and still parse. Example: + `jq -c '[.scheduled_for,.ts,.start_delay_s,.trigger_cron]' budget-poller-log.jsonl`. - **Fleet monitor:** `scripts/fleet_monitor.sh` reads the newest `budget-poller-log` artifact and adds a **Budget poller (dry-run)** section to its report. The section shows the age of the last OK record, the latest record, the dry-run decision (window and - percent), and the burn rate. When the last OK record is older than - `BUDGET_POLLER_STALE_HOURS` (default **3**), or there is none, it raises a - `::warning::`. + percent), and the burn rate. It also shows the runs received in the last 24 hours against + the 48 expected, with the median start delay. When the last OK record is older than + `BUDGET_POLLER_STALE_HOURS` (default **6**), or there is none, it raises a + `::warning::`. **Why 6 hours:** at about 40% tick delivery, a gap of more than 3 hours is + routine, so a 3-hour window would raise false alarms much of the time. The weekly window + moves slowly, so a 6-hour-old reading is still meaningful. A stale record still fails open: + a consumer that finds no fresh record proceeds as if there were no reading. ### Initiative Planner — blocking open-questions gate diff --git a/docs/agentic-interaction-model.md b/docs/agentic-interaction-model.md index a42e27ce7..3d98136d0 100644 --- a/docs/agentic-interaction-model.md +++ b/docs/agentic-interaction-model.md @@ -221,7 +221,7 @@ keeps its own file) carries **no** job qualifier and remains exactly one row. | `.github/workflows/premature-closure-audit.yml` | 3 | — | `schedule: '49 8 * * 1'` weekly premature-closure audit; cadence is the origin. | | `.github/workflows/auto-rebase-health.yml` | 3 | — | `schedule: '43 7 * * *'` daily auto-rebase health report; cadence is the origin. | | `.github/workflows/engine-token-liveness.yml` | 3 | — | `schedule: '23 7 * * *'` daily engine-token preflight liveness monitor (#1587); cadence is the origin. `workflow_dispatch` for ad-hoc runs. | -| `.github/workflows/budget-poller.yml` | 3 | — | `schedule: '17 * * * *'` hourly dry-run Claude budget poller (#2029); reads usage and logs what the breaker would do, writes no variable; cadence is the origin. | +| `.github/workflows/budget-poller.yml` | 3 | — | `schedule: '17 * * * *'` + `'47 * * * *'` twice-hourly dry-run Claude budget poller (#2029; second slot because ~60% of scheduled ticks are dropped here, #2160); reads usage and logs what the breaker would do, writes no variable; cadence is the origin. | > **Out-of-scope workflows (exclusion list).** The completeness check (§10) ignores the paths > below. A workflow absent from both this table and this list is a completeness failure. diff --git a/scripts/budget_poller.sh b/scripts/budget_poller.sh index 8f43b4293..f6a83c482 100755 --- a/scripts/budget_poller.sh +++ b/scripts/budget_poller.sh @@ -29,8 +29,11 @@ # AGENT_RATE_LIMITS_CONFIG — path to the public agent-rate-limits.json # (default: public/standards/agent-rate-limits.json) # BUDGET_POLLER_LOG — JSONL log path (default: budget-poller-log.jsonl) -# BUDGET_POLLER_MAX_RECORDS — log bound (default: 720 = 30 days hourly) +# BUDGET_POLLER_MAX_RECORDS — log bound (default: 720 ≈ 15 days at two slots an hour) # BUDGET_POLLER_NOW — epoch override (testability) +# GITHUB_EVENT_NAME — the trigger, recorded as trigger_event (#2160) +# BUDGET_POLLER_CRON — the cron that fired (github.event.schedule), +# recorded with the slot it was meant for (#2160) # GITHUB_STEP_SUMMARY — job summary (written when set) set -euo pipefail @@ -109,7 +112,8 @@ fi # 3. Build + append the record against the previous OK record (burn rate). prev_ok="$(bp_last_ok "$LOG_FILE")" record="$(bp_build_record "$NOW" "$http_status" "$retry_after" "$s_pct" "$w_pct" \ - "$s_reset" "$w_reset" "$s_dec" "$g_dec" "$g_enabled" "$reason_override" "$prev_ok")" + "$s_reset" "$w_reset" "$s_dec" "$g_dec" "$g_enabled" "$reason_override" "$prev_ok" \ + "${GITHUB_EVENT_NAME:-}" "${BUDGET_POLLER_CRON:-}")" bp_append_record "$LOG_FILE" "$record" "${BUDGET_POLLER_MAX_RECORDS:-720}" line="$(jq -r '.line' <<<"$record")" @@ -138,7 +142,9 @@ if [ -n "${GITHUB_STEP_SUMMARY:-}" ]; then ["weekly glide armed in public config", .weekly_glide_config_enabled], ["burn session (pp/h)", .burn_session_pph], ["burn weekly_all (pp/h)", .burn_weekly_all_pph], - ["burn basis", .burn_basis] ] + ["burn basis", .burn_basis], + ["Trigger", .trigger_event], ["Cron that fired", .trigger_cron], + ["Scheduled for", .scheduled_for], ["Start delay (s)", .start_delay_s] ] | .[] | "| \(.[0]) | \(v(.[1])) |"' <<<"$record" printf '\nDurable log: artifact `%s` (`%s`, one JSON record per poll).\n' \ "$BUDGET_POLLER_ARTIFACT" "$(basename "$LOG_FILE")" diff --git a/scripts/fleet_monitor.sh b/scripts/fleet_monitor.sh index d1305294d..a6cfc90bf 100755 --- a/scripts/fleet_monitor.sh +++ b/scripts/fleet_monitor.sh @@ -16,7 +16,7 @@ # LOOKBACK_DAYS — days of history to consider (default: 1) # BUDGET_POLLER_REPO — repo whose budget-poller-log artifact is read # (default: petry-projects/.github-private, #2029) -# BUDGET_POLLER_STALE_HOURS — warn when the last OK poll is older (default: 3) +# BUDGET_POLLER_STALE_HOURS — warn when the last OK poll is older (default: 6) # GITHUB_ENV — written by Actions runner # GITHUB_STEP_SUMMARY — written by Actions runner (1 MB hard limit per job) @@ -579,10 +579,11 @@ done # --------------------------------------------------------------------------- # 2f. Dry-run budget poller liveness (#2029, slice 2 of #1565) -# Read the newest `budget-poller-log` artifact the hourly Budget Poller uploads -# and report the age of the last OK telemetry record, the dry-run decision (which +# Read the newest `budget-poller-log` artifact the twice-hourly Budget Poller +# uploads and report the age of the last OK telemetry record, runs received in +# the last 24h against the 48 expected (#2160), the dry-run decision (which # window, what percent), and the burn rate. A last OK record older than -# BUDGET_POLLER_STALE_HOURS (default 3) — or none at all — raises a `::warning::` +# BUDGET_POLLER_STALE_HOURS (default 6) — or none at all — raises a `::warning::` # so a silently dead feed is visible. Best-effort and read-only: a missing # artifact or API error renders "no OK record", never fails the monitor. # --------------------------------------------------------------------------- diff --git a/scripts/lib/budget-poller.sh b/scripts/lib/budget-poller.sh index 497883820..42a68fae0 100644 --- a/scripts/lib/budget-poller.sh +++ b/scripts/lib/budget-poller.sh @@ -30,6 +30,12 @@ # would_pause, decision_window, decision_pct — the legible dry-run outcome # burn_session_pph, burn_weekly_all_pph, burn_basis — percentage points per hour # vs the previous OK record (logged only, no gate) +# trigger_event, trigger_cron — what started the run ($GITHUB_EVENT_NAME and +# the cron that fired, github.event.schedule), else null +# scheduled_for, scheduled_epoch, start_delay_s +# — the slot an hourly `M * * * *` cron was meant to run +# for (the latest :M at or before the poll) and the +# poll's delay past it; null for any other cron (#2160) # dry_run — always true # line — the greppable liveness / degraded line # @@ -40,8 +46,13 @@ # Sourced (`# shellcheck source=scripts/lib/budget-poller.sh`); runs nothing at # source time and calls `set` on nothing. -# Hours after the last OK record before the fleet monitor warns (AC #4). -BUDGET_POLLER_STALE_HOURS_DEFAULT=3 +# Hours after the last OK record before the fleet monitor warns (AC #4). 6, not +# 3: GitHub delivers only ~40% of scheduled ticks in this repo, so a 3h gap is +# routine (#2160). The weekly window moves slowly, and a stale record fails open. +BUDGET_POLLER_STALE_HOURS_DEFAULT=6 + +# Scheduled runs a day the workflow asks for: two hourly cron slots (:17, :47). +BUDGET_POLLER_EXPECTED_RUNS_PER_DAY=48 # Artifact name the workflow uploads and the fleet monitor reads. BUDGET_POLLER_ARTIFACT="${BUDGET_POLLER_ARTIFACT:-budget-poller-log}" @@ -112,11 +123,13 @@ bp_last_record() { # 1 now_epoch 2 http_status 3 retry_after 4 session_pct 5 weekly_pct # 6 session_resets_at 7 weekly_resets_at 8 session_decision # 9 glide_decision 10 glide_config_enabled 11 reason_override 12 prev_ok_record +# 13 trigger_event 14 trigger_cron (optional, #2160) # Empty strings mean "absent" (null in the record). # --------------------------------------------------------------------------- bp_build_record() { local now="$1" http="$2" retry="$3" s_pct="$4" w_pct="$5" s_reset="$6" w_reset="$7" local s_dec="$8" g_dec="$9" g_enabled="${10}" reason_override="${11}" prev="${12:-}" + local t_event="${13:-}" t_cron="${14:-}" [ -n "$prev" ] && jq -e 'type == "object"' <<<"$prev" >/dev/null 2>&1 || prev='null' # A malformed clock must not abort the record (`--argjson` would fail under set -e). [[ "$now" =~ ^[0-9]+$ ]] || now="$(date +%s)" @@ -128,6 +141,7 @@ bp_build_record() { --arg s_reset "$s_reset" --arg w_reset "$w_reset" \ --arg s_dec "$s_dec" --arg g_dec "$g_dec" \ --arg g_enabled "$g_enabled" --arg reason_override "$reason_override" \ + --arg t_event "$t_event" --arg t_cron "$t_cron" \ --argjson prev "$prev" ' def num($s): if ($s | test("^[0-9]+$")) then ($s | tonumber) else null end; def str($s): if $s == "" then null else $s end; @@ -141,6 +155,14 @@ bp_build_record() { elif $cur < $prev[$pk] then null else ((($cur - $prev[$pk]) / (($now - $prev.epoch) / 3600)) * 100 | round) / 100 end; + # The slot an hourly "M * * * *" cron was meant to run for: the latest :M at + # or before $now. A delay over an hour aliases onto a later slot, so it is + # a lower bound. Empty (null at the call site) for any other cron shape. + def scheduled($cron): + ($cron | capture("^(?[0-9]{1,2}) \\* \\* \\* \\*$")? | .m | tonumber) as $m + | select($m <= 59) + | ($now - ($now % 3600) + $m * 60) as $s + | if $s > $now then $s - 3600 else $s end; (num($http) // 0) as $status | num($s_pct) as $sp | num($w_pct) as $wp @@ -162,6 +184,7 @@ bp_build_record() { else null end ) as $dpct | burn($sp; $sr; "session_pct"; "session_resets_at") as $bs | burn($wp; $wr; "weekly_all_pct"; "weekly_all_resets_at") as $bw + | (scheduled($t_cron) // null) as $sched | { ts: ($now | todate), epoch: $now, @@ -183,6 +206,11 @@ bp_build_record() { burn_session_pph: $bs, burn_weekly_all_pph: $bw, burn_basis: (if $prev == null then "first-poll" else "previous-record" end), + trigger_event: str($t_event), + trigger_cron: str($t_cron), + scheduled_for: (if $sched == null then null else ($sched | todate) end), + scheduled_epoch: $sched, + start_delay_s: (if $sched == null then null else $now - $sched end), dry_run: true, line: ( if $poll == "ok" then "telemetry read OK, session=\($sp)% weekly_all=\($wp)%" @@ -213,7 +241,7 @@ bp_decision_text() { # --------------------------------------------------------------------------- # bp_append_record [max_records] — append and keep only the -# newest lines (default 720 = 30 days hourly). +# newest lines (default 720 ≈ 15 days at two slots an hour). # --------------------------------------------------------------------------- bp_append_record() { local log="$1" record="$2" max="${3:-720}" tmp @@ -281,8 +309,9 @@ bp_staleness_warning() { # --------------------------------------------------------------------------- # bp_fleet_section — markdown block for the fleet-monitor -# report: last OK age (STALE flag past the window), the latest record's line and -# HTTP status, the dry-run decision (window + percent), and the burn rate. +# report: last OK age (STALE flag past the window), scheduled delivery over the +# last 24h, the latest record's line and HTTP status, the dry-run decision +# (window + percent), and the burn rate. # --------------------------------------------------------------------------- bp_fleet_section() { local log="$1" now="$2" state hours latest @@ -305,6 +334,7 @@ bp_fleet_section() { "$(bp_age_text "${state#fresh }")" "$hours" ;; esac + bp_delivery_line "$log" "$now" if [ -n "$latest" ]; then jq -r '"- **Latest record:** `\(.line // "n/a")` (HTTP status \(.http_status // "n/a"), \(.ts // "n/a"))"' \ <<<"$latest" 2>/dev/null || true @@ -317,6 +347,29 @@ bp_fleet_section() { return 0 } +# --------------------------------------------------------------------------- +# bp_delivery_line — markdown bullet: runs received in +# the 24h before (every record, OK or degraded, is one run) against +# $BUDGET_POLLER_EXPECTED_RUNS_PER_DAY, plus the median start delay of those +# records that carry one (#2160). Older records without the field still count. +# --------------------------------------------------------------------------- +bp_delivery_line() { + local log="$1" now="$2" + [[ "$now" =~ ^[0-9]+$ ]] || now="$(date +%s)" + { [ -n "$log" ] && [ -s "$log" ] && cat "$log"; } 2>/dev/null \ + | jq -rRs --argjson now "$now" --argjson exp "$BUDGET_POLLER_EXPECTED_RUNS_PER_DAY" ' + [ split("\n")[] | fromjson? | select(type == "object" and (.epoch | type) == "number" + and .epoch > ($now - 86400) and .epoch <= $now) ] as $r + | ($r | length) as $n + | ([ $r[].start_delay_s | select(type == "number") ] | sort) as $d + | "- **Scheduled delivery (last 24h):** \($n) of \($exp) expected runs received" + + " (\(($n * 100 / $exp) | floor)%)" + + (if ($d | length) > 0 + then "; median start delay \(((if ($d | length) % 2 == 0 then ($d[(($d | length) / 2 | floor) - 1] + $d[($d | length) / 2 | floor]) / 2 else $d[($d | length) / 2 | floor] end) / 60) | floor)m" + else "" end)' 2>/dev/null || true + return 0 +} + # --------------------------------------------------------------------------- # bp_download_latest_log — fetch the newest unexpired # `$BUDGET_POLLER_ARTIFACT` artifact from (read-only `gh api`) and write diff --git a/tests/dev-lead/unit/test_budget_poller.bats b/tests/dev-lead/unit/test_budget_poller.bats index 45e7abc9b..f8662a3a9 100644 --- a/tests/dev-lead/unit/test_budget_poller.bats +++ b/tests/dev-lead/unit/test_budget_poller.bats @@ -287,10 +287,12 @@ _seed_degraded() { line:"telemetry read DEGRADED, status=503 reason=http-503"}' >> "$BUDGET_POLLER_LOG" } -@test "staleness: warning fires when the last OK record is older than the default 3h window" { +@test "staleness: warning fires when the last OK record is older than the default 6h window" { + # #2160: the default moved 3h -> 6h (GitHub drops ~60% of scheduled ticks + # here), so the seed moved from 4h to 7h old to stay past the default window. # shellcheck source=scripts/lib/budget-poller.sh source "$POLLER_LIB" - _seed_ok $((NOW_EPOCH - 4 * 3600)) + _seed_ok $((NOW_EPOCH - 7 * 3600)) _seed_degraded $((NOW_EPOCH - 600)) run bp_staleness_warning "$BUDGET_POLLER_LOG" "$NOW_EPOCH" [ "$status" -eq 0 ] @@ -340,12 +342,14 @@ _seed_degraded() { } @test "fleet section: flags STALE when the last OK record is past the window" { + # #2160: 5h is now inside the 6h default; the seed moved to 7h to stay stale. source "$POLLER_LIB" - _seed_ok $((NOW_EPOCH - 5 * 3600)) + _seed_ok $((NOW_EPOCH - 7 * 3600)) run bp_fleet_section "$BUDGET_POLLER_LOG" "$NOW_EPOCH" [ "$status" -eq 0 ] [[ "$output" == *"STALE"* ]] - [[ "$output" == *"5h 0m"* ]] + [[ "$output" == *"7h 0m"* ]] + [[ "$output" == *"> 6h window"* ]] } @test "fleet section: no log renders a NO OK RECORD line without erroring" { @@ -661,3 +665,166 @@ _chosen() { jq -r '.artifact' "$DL_DEST"; } [ "$status" -eq 0 ] [ "$(_chosen)" = "100" ] } + +# --------------------------------------------------------------------------- +# #2160 — two cron slots, a 6h staleness default, and measured delivery +# --------------------------------------------------------------------------- + +@test "workflow (#2160 AC1): exactly the two cron slots, no workflow_dispatch, unchanged read-only permissions" { + run yq '.on.schedule[].cron' "$WORKFLOW" + [ "${lines[0]}" = "17 * * * *" ] + [ "${lines[1]}" = "47 * * * *" ] + [ "${#lines[@]}" -eq 2 ] + # The only trigger key under `on:` is schedule (no dispatch, push, PR, ...). + run yq '.on | keys | join(",")' "$WORKFLOW" + [ "$output" = "schedule" ] + # The permissions block is exactly the two read scopes it had before. + run yq '.permissions | to_entries | map(.key + ":" + .value) | join(",")' "$WORKFLOW" + [ "$output" = "contents:read,actions:read" ] + # No job-level permissions widen it, and no write scope anywhere. + run yq '[.jobs[] | select(has("permissions"))] | length' "$WORKFLOW" + [ "$output" = "0" ] + run yq '[.. | select(tag == "!!str" and (. == "write" or . == "write-all"))] | length' "$WORKFLOW" + [ "$output" = "0" ] + # Still the existing secret only. + [ "$(grep -oE 'secrets\.[A-Z_]+' "$WORKFLOW" | sort -u)" = "secrets.CLAUDE_CODE_OAUTH_TOKEN" ] +} + +@test "workflow (#2160): the firing cron expression is forwarded to the poll step" { + run yq '[.. | select(tag == "!!map" and has("env")) | .env.BUDGET_POLLER_CRON | select(. != null)] | .[0]' "$WORKFLOW" + [[ "$output" == *'${{ github.event.schedule }}'* ]] +} + +@test "expected runs per day (#2160) matches the workflow's cron slots x 24" { + source "$POLLER_LIB" + local slots + slots="$(yq '.on.schedule | length' "$WORKFLOW")" + [ "$BUDGET_POLLER_EXPECTED_RUNS_PER_DAY" -eq $((slots * 24)) ] + [ "$BUDGET_POLLER_EXPECTED_RUNS_PER_DAY" -eq 48 ] +} + +@test "fleet section (#2160): median start delay averages the two middle values for an even sample" { + source "$POLLER_LIB" + local d + for d in 600 1200 1800 3600; do + jq -cn --argjson e "$((NOW_EPOCH - d))" --argjson d "$d" \ + '{epoch:$e, poll:"ok", http_status:200, start_delay_s:$d, line:"telemetry read OK"}' >> "$BUDGET_POLLER_LOG" + done + run bp_fleet_section "$BUDGET_POLLER_LOG" "$NOW_EPOCH" + [ "$status" -eq 0 ] + # Median of 600,1200,1800,3600 = (1200+1800)/2 = 1500s = 25m (not the upper 1800s = 30m). + [[ "$output" == *"median start delay 25m"* ]] +} + +@test "bp_stale_hours (#2160 AC2): the default is 6h and BUDGET_POLLER_STALE_HOURS still overrides it" { + run bash -c 'unset BUDGET_POLLER_STALE_HOURS; source scripts/lib/budget-poller.sh; bp_stale_hours' + [ "$output" = "6" ] + run bash -c 'source scripts/lib/budget-poller.sh; BUDGET_POLLER_STALE_HOURS=3 bp_stale_hours' + [ "$output" = "3" ] + run bash -c 'source scripts/lib/budget-poller.sh; BUDGET_POLLER_STALE_HOURS=0 bp_stale_hours' + [ "$output" = "6" ] + run bash -c 'source scripts/lib/budget-poller.sh; BUDGET_POLLER_STALE_HOURS=junk bp_stale_hours' + [ "$output" = "6" ] +} + +@test "staleness (#2160 AC2): a 5h-old OK record is fresh under the 6h default, stale under an override of 3" { + source "$POLLER_LIB" + _seed_ok $((NOW_EPOCH - 5 * 3600)) + run bp_staleness_warning "$BUDGET_POLLER_LOG" "$NOW_EPOCH" + [ -z "$output" ] + BUDGET_POLLER_STALE_HOURS=3 run bp_staleness_warning "$BUDGET_POLLER_LOG" "$NOW_EPOCH" + [[ "$output" == "::warning::"*"> 3h staleness window"* ]] +} + +@test "bp_build_record (#2160 AC3): records the trigger event, cron, scheduled time and start delay" { + source "$POLLER_LIB" + local now=$((NOW_EPOCH + 20 * 60 + 30)) r # 16:20:30Z, fired by the :17 slot + r="$(bp_build_record "$now" 200 "" 10 20 a b allow allow false "" "" schedule '17 * * * *')" + [ "$(jq -r .trigger_event <<<"$r")" = "schedule" ] + [ "$(jq -r .trigger_cron <<<"$r")" = "17 * * * *" ] + [ "$(jq -r .scheduled_epoch <<<"$r")" = "$((NOW_EPOCH + 17 * 60))" ] + [ "$(jq -r .scheduled_for <<<"$r")" = "2026-09-15T16:17:00Z" ] + [ "$(jq -r .start_delay_s <<<"$r")" = "210" ] + [ "$(jq -r .ts <<<"$r")" = "2026-09-15T16:20:30Z" ] +} + +@test "bp_build_record (#2160 AC3): a start before the slot's minute this hour is scheduled for the previous hour" { + source "$POLLER_LIB" + local now=$((NOW_EPOCH + 10 * 60)) r # 16:10Z, fired by the :47 slot (15:47) + r="$(bp_build_record "$now" 200 "" 10 20 a b allow allow false "" "" schedule '47 * * * *')" + [ "$(jq -r .scheduled_for <<<"$r")" = "2026-09-15T15:47:00Z" ] + [ "$(jq -r .start_delay_s <<<"$r")" = "1380" ] +} + +@test "bp_build_record (#2160 AC3): no event / non-hourly cron leaves the scheduled fields null, record intact" { + source "$POLLER_LIB" + local r + r="$(bp_build_record "$NOW_EPOCH" 200 "" 10 20 a b allow allow false "" "")" + [ "$(jq -r .poll <<<"$r")" = "ok" ] + [ "$(jq -r '[.trigger_event, .trigger_cron, .scheduled_for, .scheduled_epoch, .start_delay_s] | map(tostring) | join(",")' <<<"$r")" = "null,null,null,null,null" ] + r="$(bp_build_record "$NOW_EPOCH" 200 "" 10 20 a b allow allow false "" "" schedule '0 */2 * * *')" + [ "$(jq -r .trigger_event <<<"$r")" = "schedule" ] + [ "$(jq -r .trigger_cron <<<"$r")" = "0 */2 * * *" ] + [ "$(jq -r .scheduled_epoch <<<"$r")" = "null" ] + [ "$(jq -r .start_delay_s <<<"$r")" = "null" ] + r="$(bp_build_record "$NOW_EPOCH" 200 "" 10 20 a b allow allow false "" "" schedule '75 * * * *')" + [ "$(jq -r .scheduled_epoch <<<"$r")" = "null" ] +} + +@test "poller (#2160 AC3): an end-to-end run records GITHUB_EVENT_NAME and the firing cron" { + export MOCK_STATUS=200 + MOCK_BODY="$(_body 33 50)"; export MOCK_BODY + GITHUB_EVENT_NAME=schedule BUDGET_POLLER_CRON='47 * * * *' \ + BUDGET_POLLER_NOW=$((NOW_EPOCH + 49 * 60)) run bash "$POLLER" + [ "$status" -eq 0 ] + [ "$(_field .trigger_event)" = "schedule" ] + [ "$(_field .trigger_cron)" = "47 * * * *" ] + [ "$(_field .scheduled_for)" = "2026-09-15T16:47:00Z" ] + [ "$(_field .start_delay_s)" = "120" ] + grep -q 'Scheduled for' "$GITHUB_STEP_SUMMARY" + grep -q '47 \* \* \* \*' "$GITHUB_STEP_SUMMARY" +} + +@test "carry-forward (#2160 AC3): an older record without the scheduling fields still parses" { + source "$POLLER_LIB" + # A record exactly as PR 2031's poller wrote it (no trigger/scheduled fields). + _seed_ok $((NOW_EPOCH - 3600)) + local prev r + prev="$(bp_last_ok "$BUDGET_POLLER_LOG")" + [ "$(jq -r .poll <<<"$prev")" = "ok" ] + [ "$(jq -r '.scheduled_for // "absent"' <<<"$prev")" = "absent" ] + r="$(bp_build_record "$NOW_EPOCH" 200 "" 36 51 "" "" allow allow false "" "$prev" schedule '17 * * * *')" + [ "$(jq -r .burn_basis <<<"$r")" = "previous-record" ] + [ "$(jq -r .burn_session_pph <<<"$r")" = "3" ] + run bp_fleet_section "$BUDGET_POLLER_LOG" "$NOW_EPOCH" + [ "$status" -eq 0 ] + [[ "$output" == *"1h 0m ago"* ]] + [[ "$output" == *"1 of 48 expected"* ]] + [[ "$output" != *"null"* ]] +} + +@test "fleet section (#2160): reports runs received in the last 24h against the 48 expected" { + source "$POLLER_LIB" + local i + # 30 runs inside the window (ok and degraded both count), 2 outside it. + _seed_ok $((NOW_EPOCH - 25 * 3600)) + _seed_ok $((NOW_EPOCH - 24 * 3600 - 1)) + for i in $(seq 1 29); do + jq -cn --argjson e "$((NOW_EPOCH - i * 1800))" --argjson d "$((i * 60))" \ + '{epoch:$e, poll:"ok", http_status:200, trigger_event:"schedule", trigger_cron:"17 * * * *", start_delay_s:$d, + line:"telemetry read OK, session=1% weekly_all=1%"}' >> "$BUDGET_POLLER_LOG" + done + _seed_degraded $((NOW_EPOCH - 60)) + run bp_fleet_section "$BUDGET_POLLER_LOG" "$NOW_EPOCH" + [ "$status" -eq 0 ] + [[ "$output" == *"30 of 48 expected"*"(62%)"* ]] + # Median of 60..1740s over the 29 records that carry a delay = 900s = 15m. + [[ "$output" == *"median start delay 15m"* ]] +} + +@test "fleet section (#2160): no log reports 0 of 48 without erroring" { + source "$POLLER_LIB" + run bp_fleet_section "$BATS_TEST_TMPDIR/missing.jsonl" "$NOW_EPOCH" + [ "$status" -eq 0 ] + [[ "$output" == *"0 of 48 expected"* ]] +} diff --git a/tests/dev-lead/unit/test_dev_lead_retry_budget_hold.bats b/tests/dev-lead/unit/test_dev_lead_retry_budget_hold.bats index 9502fb0f8..40daf0326 100644 --- a/tests/dev-lead/unit/test_dev_lead_retry_budget_hold.bats +++ b/tests/dev-lead/unit/test_dev_lead_retry_budget_hold.bats @@ -352,7 +352,22 @@ _assert_fail_open() { } @test "fail-open (#2139 AC2): a record older than bp_stale_hours is ignored" { - # Default window is 3h: 3h01m old is stale, even though it says exhausted. + # Default window is 6h (raised from 3h so a dropped hourly cron tick does not + # make the record stale): 6h01m old is stale, even though it says exhausted. + _publish "$(_record $((NOW_EPOCH - 21660)) 40 100 "" 2026-10-12T16:00:00Z)" + _init + _assert_fail_open "stale record, poll 6h 1m old > 6h" +} + +@test "hold (#2139 AC2): a 3h01m-old record is FRESH under the 6h default, so the hold applies" { + _publish "$(_record $((NOW_EPOCH - 10860)) 40 100 "" 2026-10-12T16:00:00Z)" + _init + [ "$BUDGET_HOLD_UNTIL" = "2026-10-12T16:00:00Z" ] + grep -q '(poll 3h 1m old)' "$HOLD_LOG" +} + +@test "fail-open (#2139 AC2): a 3h01m-old record is STALE when BUDGET_POLLER_STALE_HOURS=3" { + export BUDGET_POLLER_STALE_HOURS=3 _publish "$(_record $((NOW_EPOCH - 10860)) 40 100 "" 2026-10-12T16:00:00Z)" _init _assert_fail_open "stale record, poll 3h 1m old > 3h"