Skip to content

fix(bin): use conditional GitHub REST reads and stop sweeps below a quota floor - #88

Merged
MrGTV-love merged 30 commits into
mainfrom
fm/fm-github-conditional-reads-r3
Oct 10, 2026
Merged

MrGTV-love merged 30 commits into
mainfrom
fm/fm-github-conditional-reads-r3

Conversation

@MrGTV-love

Copy link
Copy Markdown
Owner

Intent

I would like all bugs to be fixed so tomorrow can be focused entirely to Vernant and not problems preventning Vernant from getting built.

Context: GitHub rate limiting has repeatedly stopped fleet work (no-mistakes push and CI steps failing on gh pr view, a Vernant lane PR report published incomplete with rows missing). The measured scout report data/fm-fleet-github-graphql-budget/report.md (in the main firstmate home) found: the core (REST) bucket runs at about 80 percent of 5000/hour with no unusual load; the open-work ledger in 7 lane homes spent 88 calls per run until those homes were updated to PR #56 (done 2026-10-08); the contributions poll spends about 1150 core calls/hour re-reading 12 unchanged PRs; conditional GETs with If-None-Match that return 304 do not count against the limit; nothing in tracked code reads the remaining quota or degrades when it is low; gh api rate_limit reads wrong on this account - use X-RateLimit-* headers. GraphQL was exhausted on 2026-10-06 ~21:26Z, 2026-10-08 02:53Z and ~04:45Z by a burst of about 8x baseline whose consumer is unknown (the ledger and no-mistakes are ruled out).

What Changed

  • Adds bin/fm-gh-rest.sh, a shared REST read helper with two commands: get and guard. get keeps a per-URL ETag cache in state/gh-rest-cache/ and sends If-None-Match. When GitHub replies 304, the helper returns the cached body. It follows Link rel="next" pagination. If a 304 has no Link header and the cached page is full, it reads that page again without a condition. It records the X-RateLimit-* response headers in state/gh-ratelimit.<resource>.json. Concurrent writers keep the lowest remaining value for the newest reset window. Before each request, the helper checks a fixed floor of 15% of the core limit. Below the floor, it exits 75 and prints no partial output.
  • bin/fm-contributions.sh now sends its REST reads through the helper, and it runs guard before its GraphQL gh reads. When the quota is below the floor, the poll stops reading the forge. It keeps the last observation of each owner that it did not measure, and it sets that record's error to the quota-reset reason. It announces this once per reset window. bin/fm_open_loops.py now reads PRs through fm-gh-rest.sh get --paginate --slurp, in place of gh-axi api with base64. On a quota refusal it drops the partial collection. It returns the last published ledger, with each row marked stale: true. It also sets complete: false, stale_reason, and stale_until_epoch, and adds a ledger stale coverage row. If no earlier ledger exists, it adds a ledger degraded row.
  • Adds tests: tests/fm-gh-rest.test.sh, an HTTP-faithful gh test double (tests/assets/gh-http-shim.sh, installed with fm_gh_http_shim in tests/lib.sh), and new quota and conditional-read cases in tests/fm-contributions.test.sh and tests/fm-open-loops.test.sh. Registers the new test in the bin/fm-test-run.sh family and path routing. The bounded watcher in tests/fm-pr-check-security.test.sh now unregisters the contributions observer before it starts. Documents the cache, quota recording, and degradation in docs/configuration.md.

Risk Assessment

⚠️ Medium: The change adds a new shared GitHub REST read path with an ETag cache, concurrent quota recording, and degraded-output modes for two sweeps; behavioral tests cover it well and no blocking defect was found, but one wake-suppression edge case and small leak/floor gaps are follow-ups.

Testing

I ran the real helper, the contributions poll, and the open-work ledger in a disposable lab FM_HOME. Each one used the machine's real gh login against real GitHub. A pass-through gh spy recorded every real call with its HTTP status and X-RateLimit-Used. Results: (1) warm reads were all 304 replies, and sequential 304s left X-RateLimit-Used unchanged. (2) Pagination and the full-last-page re-read worked, and real GitHub 304s carry no Link header, so that path is real. (3) With the recorded quota below the floor, the helper exited 75 and the poll and ledger made zero gh calls. They kept the last observations, marked them stale, and announced the episode once. (4) Both sweeps recovered after the window reset. (5) The R1 case (a real 404 after a quota episode still wakes firstmate) passed. (6) The R2 prune case passed. I could not make real GitHub report low quota on a 304, so R3 is untested live. The focused tests/fm-gh-rest.test.sh covers R3 with a shim and passed 17/17. This is a CLI change with no UI, so I captured CLI transcripts and no screenshots. I tore down the lab. The worktree is clean.

  • Live validation: ✅ go - 10 of 11 scenarios driven live against the product
Scenario Result Live Evidence
A repeated REST read of one PR is answered from the ETag cache with a 304 that does not spend core quota ✅ pass live s1-live-conditional-get.txt: call 1 status=200 used=1737; calls 2-3 status=304 used=1737; identical bodies; gh-ratelimit.core.json recorded from headers
A paginated read follows Link on a cold cache and serves every page from 304s on a warm cache with identical output ✅ pass live s2-live-paginated-conditional.txt: 3 pages [40,40,4] cold (200s), warm 3x 304, slurped output identical
A warm paginated read whose exactly-full last page gets a Link-less 304 re-reads that page once, so a newly added page is not missed ✅ pass live s3-live-full-last-page.txt: real GitHub 304 has no Link header; helper makes one unconditional 200 re-read of page 2; output identical
Below the 15% floor with an open window, guard and get refuse with exit 75, the reason, no stdout, and no gh call; at the floor, after reset, or with no record they proceed ✅ pass live s4-quota-floor-refusal.txt: 700/5000 -> guard exit 75 reason on stdout; get and paginated get exit 75, 0 stdout bytes, 0 gh calls; 750/5000 exit 0; expired window and no record exit 0 and real read su…
The contributions poll re-reading an unchanged open PR spends no counted REST calls on a warm cache ✅ pass live s5-live-contributions-poll-304.txt: poll 2 made 7 REST calls, all 304, plus the GraphQL head read; record fresh with error null
Below the floor the contributions poll makes no forge call, keeps the last observation and checked_at, marks it stale with the reset time, announces once per window, and recovers after reset ✅ pass live s6-live-contributions-quota-floor.txt: poll 3 printed one quota line, 0 gh calls, observation unchanged; poll 4 silent with updated reason; poll 5 after reset read normally and cleared the error
Adversarial R1: after a quota-stale mark, a genuine forge failure in the next window still prints 'observation unavailable' once and stays silent after that ✅ pass live s7-live-r1-failure-after-quota-episode.txt: poll A quota-stale mark; poll B real 404 -> 'contributions: observation unavailable for .../pull/999999'; poll C silent
The open-work ledger reads PRs through the helper; below the floor it publishes the last rows marked stale with stale_reason and stale_until_epoch, makes no gh call, and refreshes after reset ✅ pass live s8-live-ledger-quota-floor.txt: warm run 3/3 304 with used unchanged; low-quota run 0 calls, complete=false, stale=true, rows stale=true, generated_epoch kept, 'ledger stale' row; run 4 after reset co…
Adversarial: the ledger below the floor with no earlier published ledger reports 'ledger degraded' instead of an empty 'nothing owed' result ✅ pass live s9-live-ledger-no-prior.txt: 0 gh calls, one coverage 'ledger degraded' row carrying the quota reason, complete=false
R2: a normal get prunes staged .entry.* and .gh-ratelimit.* files older than 60 minutes and keeps fresh ones ✅ pass live s10-live-r2-prune-staged.txt: OLD111/OLD222 (2h old) removed, NEW333/NEW444 kept after a real get
R3: a 304 on a full cached last page that reports quota below the floor does not spend the unconditional re-read ⏸️ untested no The prior payload did not establish a live result for this scenario. It recorded only the shim-backed bash tests/fm-gh-rest.test.sh case ('ok - a full cached last page is not re-read once its 304 re…
Evidence: Live conditional GET: 200 then two uncounted 304s

Source: Live conditional GET: 200 then two uncounted 304s

$ fm-gh-rest.sh get repos/MrGTV-love/firstmate/pulls/81   # call 1 (cold cache)
exit=0
{"number":81,"state":"closed","title":"fix: deliver stranded and stuck-queue omp watcher wakes","head":"eb628794f0e7056a4256ee3123ec6d4742ad4419"}
$ fm-gh-rest.sh get repos/MrGTV-love/firstmate/pulls/81   # call 2 (warm cache)
exit=0
{"number":81,"state":"closed","title":"fix: deliver stranded and stuck-queue omp watcher wakes","head":"eb628794f0e7056a4256ee3123ec6d4742ad4419"}
$ fm-gh-rest.sh get repos/MrGTV-love/firstmate/pulls/81   # call 3 (warm cache)
exit=0
bodies identical across all 3 calls
--- spy log (real gh, real GitHub) ---
00:38:28 rc=0 status=200 used=1737 remaining=3263 argv=api -i repos/MrGTV-love/firstmate/pulls/81
00:38:29 rc=1 status=304 used=1737 remaining=3263 argv=api -i -H If-None-Match: W/"5218a5433b39821efd0b650fa1341fb83c1bd25f627ac5ce9a3bd448599e97c6" repos/MrGTV-love/firstmate/pulls/81
00:38:30 rc=1 status=304 used=1737 remaining=3263 argv=api -i -H If-None-Match: W/"5218a5433b39821efd0b650fa1341fb83c1bd25f627ac5ce9a3bd448599e97c6" repos/MrGTV-love/firstmate/pulls/81
--- state/gh-ratelimit.core.json (recorded from response headers) ---
{"resource":"core","limit":5000,"remaining":3263,"reset":1791592909,"observed":1791592710}
--- state/gh-rest-cache/ entry ---
total 80
drwxr-xr-x  4 charlesabrooker  staff    128 Oct  9 19:38 .
drwxr-xr-x  4 charlesabrooker  staff    128 Oct  9 19:38 ..
-rw-r--r--  1 charlesabrooker  staff      0 Oct  9 19:38 .pruned
-rw-------  1 charlesabrooker  staff  38330 Oct  9 19:38 add6d7898d8aadfee98025513b635392f25ef1c6f33c81a7932cba2961dcd589.json
{"etag":"W/\"5218a5433b39821efd0b650fa1341fb83c1bd25f627ac5ce9a3bd448599e97c6\"","next":null,"body_bytes":36048}
Evidence: Live paginated conditional read (3 pages)

Source: Live paginated conditional read (3 pages)

$ fm-gh-rest.sh get 'repos/MrGTV-love/firstmate/pulls?state=all&per_page=40' --paginate --slurp   # cold
exit=0
{"pages":3,"per_page":[40,40,4],"prs":84,"first":84,"last":1}
$ fm-gh-rest.sh get 'repos/MrGTV-love/firstmate/pulls?state=all&per_page=40' --paginate --slurp   # warm
exit=0
{"pages":3,"per_page":[40,40,4],"prs":84}
slurped output identical cold vs warm
--- spy log ---
00:38:52 rc=0 status=200 used=1759 remaining=3241 argv=api -i repos/MrGTV-love/firstmate/pulls?state=all&per_page=40
00:38:53 rc=0 status=200 used=1760 remaining=3240 argv=api -i repositories/1380859068/pulls?state=all&per_page=40&page=2
00:38:54 rc=0 status=200 used=1761 remaining=3239 argv=api -i repositories/1380859068/pulls?state=all&per_page=40&page=3
00:38:55 rc=1 status=304 used=1761 remaining=3239 argv=api -i -H If-None-Match: W/"c41308133feef3df7ee63ea029b11747746a55442b4873ee98512e44ecbd88c4" repos/MrGTV-love/firstmate/pulls?state=all&per_page
00:38:56 rc=1 status=304 used=1761 remaining=3239 argv=api -i -H If-None-Match: W/"6c1a8e75fade82de94806a9013133c7c188f4a0cf6462a52eae544a88f46b7bf" repositories/1380859068/pulls?state=all&per_page=40
00:38:57 rc=1 status=304 used=1763 remaining=3237 argv=api -i -H If-None-Match: W/"a2bdd814574773ccde285868d1f89a1c68cf0e2633d57cbf1cbef72ada4136ac" repositories/1380859068/pulls?state=all&per_page=40
Evidence: Live full-last-page re-read (real 304 omits Link)

Source: Live full-last-page re-read (real 304 omits Link)

$ fm-gh-rest.sh get 'repos/MrGTV-love/firstmate/pulls?state=all&per_page=42' --paginate --slurp   # cold (84 PRs = two exactly-full pages)
exit=0
{"pages":2,"per_page":[42,42]}
$ fm-gh-rest.sh get 'repos/MrGTV-love/firstmate/pulls?state=all&per_page=42' --paginate --slurp   # warm
exit=0
{"pages":2,"per_page":[42,42]}
identical
--- spy log ---
00:39:40 rc=0 status=200 used=1828 remaining=3172 argv=api -i repos/MrGTV-love/firstmate/pulls?state=all&per_page=42
00:39:42 rc=0 status=200 used=1830 remaining=3170 argv=api -i repositories/1380859068/pulls?state=all&per_page=42&page=2
00:39:43 rc=1 status=304 used=1833 remaining=3167 argv=api -i -H If-None-Match: W/"c49463871b84a825fc9cd77f9b6976868e9ce17cf61b1cfd50290fa6d0b41cab" repos/MrGTV-love/firstmate/pulls?state=all&per_page
00:39:44 rc=1 status=304 used=1834 remaining=3166 argv=api -i -H If-None-Match: W/"79371042b2ac94dc57d33e2449f5fd44648a05f51dbaba11a8839d85e4e9d595" repositories/1380859068/pulls?state=all&per_page=42
00:39:45 rc=0 status=200 used=1835 remaining=3165 argv=api -i repositories/1380859068/pulls?state=all&per_page=42&page=2
--- does a real GitHub 304 on the last page carry a Link header? ---
HTTP/2.0 304 Not Modified
Etag: "79371042b2ac94dc57d33e2449f5fd44648a05f51dbaba11a8839d85e4e9d595"
Evidence: Quota floor guard/get refusal, boundary, expiry

Source: Quota floor guard/get refusal, boundary, expiry

--- A: recorded core bucket below the 15% floor, window still open ---
{"resource":"core","limit":5000,"remaining":700,"reset":1791594615,"observed":1791592815}
$ fm-gh-rest.sh guard
GitHub core quota low (700 of 5000 left, below the 15% floor); network sweep skipped until the window resets at 2026-10-10T01:10:15Z
exit=75
$ fm-gh-rest.sh get repos/MrGTV-love/firstmate/pulls/81 (stdout below, stderr marked)
stdout bytes=0
exit=
stderr: GitHub core quota low (700 of 5000 left, below the 15% floor); network sweep skipped until the window resets at 2026-10-10T01:10:15Z
gh calls made while refused: 0
--- B: exactly at the floor (750 of 5000 = 15%) ---
guard exit=0
--- C: below floor but window already reset (expired) ---
guard exit=0 (silent)
{"number":81}
get exit=
--- recorded bucket after the real read replaced the expired one ---
{"resource":"core","limit":5000,"remaining":3156,"reset":1791592909,"observed":1791592816}
--- D: no quota record at all ---
guard exit=0
--- spy log (real gh calls in this scenario) ---
00:40:16 rc=1 status=304 used=1844 remaining=3156 argv=api -i -H If-None-Match: W/"5218a5433b39821efd0b650fa1341fb83c1bd25f627ac5ce9a3bd448599e97c6" repos/MrGTV
--- A (exit codes): below floor, window open ---
get exit=75 stdout bytes=0
paginated get exit=75 stdout bytes=0
gh calls while refused: 0
--- C (exit code): expired window ---
get exit=0 number=81
Evidence: Live contributions poll: warm poll is 7/7 REST 304

Source: Live contributions poll: warm poll is 7/7 REST 304

=== Live contributions poll, lab FM_HOME, backlog row owns https://github.com/MrGTV-love/firstmate/pull/84 ===
--- poll 1 (cold cache): every real gh call ---
00:40:59 rc=0 status=200 used=1879 remaining=3121 argv=api -i repos/MrGTV-love/firstmate/pulls/84
00:41:00 rc=0 status=200 used=1887 remaining=3113 argv=api -i repos/MrGTV-love/firstmate/pulls/84/comments?per_page=100
00:41:00 rc=0 status=200 used=1882 remaining=3118 argv=api -i repos/MrGTV-love/firstmate/commits/10b627526857970ec30d5a6153d1bdf5c51b8df1/statuses?per_page=100
00:41:00 rc=0 status=200 used=1880 remaining=3120 argv=api -i repos/MrGTV-love/firstmate
00:41:00 rc=0 status=200 used=1885 remaining=3115 argv=api -i repos/MrGTV-love/firstmate/issues/84/comments?per_page=100
00:41:00 rc=0 status=200 used=1886 remaining=3114 argv=api -i repos/MrGTV-love/firstmate/pulls/84/reviews?per_page=100
00:41:00 rc=0 status=200 used=1881 remaining=3119 argv=api -i repos/MrGTV-love/firstmate/commits/10b627526857970ec30d5a6153d1bdf5c51b8df1/check-runs?filter=all&per_page=1
00:41:02 rc=0 status=n/a used=n/a remaining=n/a argv=pr view https://github.com/MrGTV-love/firstmate/pull/84 --json headRefOid,reviewDecision
--- poll 2 (warm cache): every real gh call ---
00:41:12 rc=1 status=304 used=1887 remaining=3113 argv=api -i -H If-None-Match: W/"246304f84235c4b91018523780853eda378943af2a2aecba26f96426f17eb7bf" repos/MrGTV-love/firs
00:41:13 rc=1 status=304 used=1892 remaining=3108 argv=api -i -H If-None-Match: "01dd62d4e6434e367b176181b26144506c388fe8015134063ecb2c37a763c47f" repos/MrGTV-love/firstm
00:41:13 rc=1 status=304 used=1890 remaining=3110 argv=api -i -H If-None-Match: "01dd62d4e6434e367b176181b26144506c388fe8015134063ecb2c37a763c47f" repos/MrGTV-love/firstm
00:41:13 rc=1 status=304 used=1891 remaining=3109 argv=api -i -H If-None-Match: "01dd62d4e6434e367b176181b26144506c388fe8015134063ecb2c37a763c47f" repos/MrGTV-love/firstm
00:41:13 rc=1 status=304 used=1889 remaining=3111 argv=api -i -H If-None-Match: "01dd62d4e6434e367b176181b26144506c388fe8015134063ecb2c37a763c47f" repos/MrGTV-love/firstm
00:41:13 rc=1 status=304 used=1888 remaining=3112 argv=api -i -H If-None-Match: W/"9190e494cfd6fa39c8d04262e1bc94689d26ca6b8d3775e5c2e1327ff4e32969" repos/MrGTV-love/firs
00:41:13 rc=1 status=304 used=1887 remaining=3113 argv=api -i -H If-None-Match: W/"7198b37c6766490a31f131c227848bf758bb99ce0abc57fb039b02fec0836444" repos/MrGTV-love/firs
00:41:16 rc=0 status=n/a used=n/a remaining=n/a argv=pr view https://github.com/MrGTV-love/firstmate/pull/84 --json headRefOid,reviewDecision
--- poll 2 REST calls: 7 total, 7 answered 304 (uncounted), 0 answered 200 ---
--- saved record after poll 2 ---
{"url":"https://github.com/MrGTV-love/firstmate/pull/84","checked_at":"2026-10-10T00:41:10Z","error":null,"state":"open","head":"10b627526857970ec30d5a6153d1bdf5c51b8df1","checks":22}
Evidence: Live contributions poll below floor: zero calls, stale mark, one announcement, recovery

Source: Live contributions poll below floor: zero calls, stale mark, one announcement, recovery

=== Live contributions poll under the quota floor (lab FM_HOME) ===
recorded bucket: {"resource":"core","limit":5000,"remaining":600,"reset":1791594722,"observed":1791592922}
--- poll 3 (below floor) stdout ---
contributions: GitHub core quota low (600 of 5000 left, below the 15% floor); network sweep skipped until the window resets at 2026-10-10T01:12:02Z; last observations kept, marked stale
exit=0
gh calls: 0
{"checked_at":"2026-10-10T00:41:10Z","error":"GitHub core quota low (600 of 5000 left, below the 15% floor); network sweep skipped until the window resets at 2026-10-10T01:12:02Z","state":"open","head":"10b627526857970ec30d5a6153d1bdf5c51b8df1"}
observation kept unchanged: yes
--- poll 4 (still below floor, same window, remaining dropped further) stdout ---
exit=0 (expect no second announcement)
gh calls: 0
{"error":"GitHub core quota low (550 of 5000 left, below the 15% floor); network sweep skipped until the window resets at 2026-10-10T01:12:02Z"}
--- poll 5 (window reset: recorded reset is in the past) stdout ---
exit=0
gh calls: 8
00:42:05 rc=1 status=304 used=8 remaining=4992 argv=api -i -H If-None-Match: W/"246304f84235c4b91018523780853e
00:42:06 rc=1 status=304 used=15 remaining=4985 argv=api -i -H If-None-Match: "01dd62d4e6434e367b176181b261445
00:42:06 rc=1 status=304 used=14 remaining=4986 argv=api -i -H If-None-Match: "01dd62d4e6434e367b176181b261445
00:42:06 rc=1 status=304 used=13 remaining=4987 argv=api -i -H If-None-Match: "01dd62d4e6434e367b176181b261445
00:42:06 rc=1 status=304 used=11 remaining=4989 argv=api -i -H If-None-Match: W/"9190e494cfd6fa39c8d04262e1bc9
00:42:06 rc=1 status=304 used=12 remaining=4988 argv=api -i -H If-None-Match: "01dd62d4e6434e367b176181b261445
00:42:06 rc=1 status=304 used=10 remaining=4990 argv=api -i -H If-None-Match: W/"7198b37c6766490a31f131c227848
00:42:08 rc=0 status=n/a used=n/a remaining=n/a argv=pr view https://github.com/MrGTV-love/firstmate/pull/84 -
{"checked_at":"2026-10-10T00:42:03Z","error":null,"state":"open"}
recorded bucket now (from real headers): {"resource":"core","limit":5000,"remaining":4985,"reset":1791596511,"observed":1791592927}
Evidence: R1: real 404 after quota episode still prints observation unavailable

Source: R1: real 404 after quota episode still prints observation unavailable

=== R1 adversarial: quota-stale mark must not hide the next genuine forge failure ===
backlog now also owns https://github.com/MrGTV-love/firstmate/pull/999999 (does not exist on GitHub -> real 404)
--- poll A (below floor) ---
contributions: GitHub core quota low (300 of 5000 left, below the 15% floor); network sweep skipped until the window resets at 2026-10-10T01:12:42Z; last observations kept, marked stale
exit=0 gh calls=0
{"task":"ghostpr","records":[{"url":"https://github.com/MrGTV-love/firstmate/pull/999999","error":"GitHub core quota low (300 of 5000 left, below the 15% floor); network sweep skipped until the window resets at 2026-10-10T01:12:42Z"}]}
--- poll B (window reset, real forge answers 404 for the ghost PR) ---
contributions: observation unavailable for https://github.com/MrGTV-love/firstmate/pull/999999
exit=0
00:42:49 rc=1 status=404 used=43 remaining=4957 argv=api -i repos/MrGTV-love/firstmate/pulls/999999
{"task":"ghostpr","records":[{"url":"https://github.com/MrGTV-love/firstmate/pull/999999","error":"forge observation unavailable or changed during read"}]}
--- poll C (same failure persists: episode already announced, expect silence) ---
exit=0
Evidence: Live open-work ledger: 304s, retained stale result, recovery

Source: Live open-work ledger: 304s, retained stale result, recovery

=== Live open-work ledger (fm-open-loops.sh --json --heartbeat), lab FM_HOME owning MrGTV-love/firstmate#84 ===
--- run 1 (cold for pulls/check-runs) real gh calls ---
00:45:05 rc=0 status=200 used=146 remaining=4854 argv=api -i repos/MrGTV-love/firstmate/pulls?state=open&per_page=100
00:45:06 rc=0 status=200 used=147 remaining=4853 argv=api -i repos/MrGTV-love/firstmate/commits/10b627526857970ec30d5a6153d1bdf5c51b8df1/check-runs?pe
00:45:08 rc=1 status=304 used=147 remaining=4853 argv=api -i -H If-None-Match: "01dd62d4e6434e367b176181b26144506c388fe8015134063ecb2c37a763c47f" repo
--- run 2 (warm) real gh calls ---
00:45:43 rc=1 status=304 used=159 remaining=4841 argv=api -i -H If-None-Match: W/"db8a8441f52d936e31942a361c053765df3f8d99f6382c0c089f6265a7498296" re
00:45:44 rc=1 status=304 used=159 remaining=4841 argv=api -i -H If-None-Match: W/"7198b37c6766490a31f131c227848bf758bb99ce0abc57fb039b02fec0836444" re
00:45:45 rc=1 status=304 used=159 remaining=4841 argv=api -i -H If-None-Match: "01dd62d4e6434e367b176181b26144506c388fe8015134063ecb2c37a763c47f" repo
--- run 2 result ---
{"complete":true,"generated_epoch":1791593143,"rows":[{"category":"ready_not_started","subject":"livepr"},{"category":"red_check","subject":"https://github.com/MrGTV-love/firstmate/pull/84"}]}
--- run 3: recorded core bucket set below floor: {"resource":"core","limit":5000,"remaining":400,"reset":1791594945,"observed":1791593145} ---
real gh calls in run 3 (json + toon): 0
{
  "complete": false,
  "stale": true,
  "stale_reason": "GitHub core quota low (400 of 5000 left, below the 15% floor); network sweep skipped until the window resets at 2026-10-10T01:15:45Z",
  "stale_until_epoch": 1791594945,
  "expected_reset": 1791594945,
  "generated_epoch": 1791593143,
  "rows": [
    {
      "category": "coverage",
      "subject": "ledger stale",
      "stale": null,
      "evidence": "GitHub core quota low (400 of 5000 left, below the 15% floor); network sweep skipped until the window resets at 2026-10-10T01:15:45Z"
    },
    {
      "category": "ready_not_started",
      "subject": "livepr",
      "stale": true,
      "evidence": ""
    },
    {
      "category": "red_check",
      "subject": "https://github.com/MrGTV-love/firstmate/pull/84",
      "stale": true,
      "evidence": "Behavior portable serial 7; Behavior portable serial 8; Behavior portable serial 5; Behavior portable serial 9; Behavior portable serial 6; Behavior portable parallel 2"
    }
  ]
}
generated_epoch kept from run 2: 1791593143 == 1791593143
--- published state/open-loops.json after run 3 ---
{"complete":false,"stale":true,"stale_until_epoch":1791594945,"rows":3}
--- human (TOON) output in run 3 ---
bin: ~/.no-mistakes/worktrees/32d18ed9638d/01M4HGJ55Y75PRC7WXCK4XDB5E/bin/fm-open-loops.sh
description: Reconcile assigned work against live delivery evidence
complete: false
generated_epoch: 1791593143
rows[3]{category,subject,owner,next_action,age_seconds,overdue,evidence}:
  "coverage","ledger stale","firstmate","wait for the GitHub quota window to reset; the next run refreshes every row",null,false,"GitHub core quota low (400 of 5000 left, below the 15% floor); network sweep skipped until the window resets at 2026-10-10T01:15:45Z"
  "ready_not_started","livepr","firstmate","informational: queued and not selected for dispatch",null,false,""
  "red_check","https://github.com/MrGTV-love/firstmate/pull/84","firstmate","diagnose: code or test",1284,true,"Behavior portable serial 7; Behavior portable serial 8; Behavior portable serial 5; Behavior portable serial 9; Behavior portable serial 6; Behavior portable parallel 2"
help: Run bin/fm-open-loops.sh --json for age limits and structured rows
--- run 4: recorded window has reset ({"remaining":4818,"reset":1791596511} before the run) ---
real gh calls:
00:46:19 rc=1 status=304 used=178 remaining=4822 argv=api -i -H If-None-Match: W/"db8a8441f52d936e31942a361c053765df3f8d
00:46:21 rc=1 status=304 used=178 remaining=4822 argv=api -i -H If-None-Match: W/"7198b37c6766490a31f131c227848bf758bb99
00:46:23 rc=1 status=304 used=182 remaining=4818 argv=api -i -H If-None-Match: "01dd62d4e6434e367b176181b26144506c388fe8
{"complete":true,"stale":null,"stale_reason":null,"generated_epoch":1791593178,"rows":[{"category":"ready_not_started","subject":"livepr","stale":null},{"category":"red_check","subject":"https://github.com/MrGTV-love/firstmate/pull/84","stale":null}]}
recorded bucket after run 4 (real headers): {"resource":"core","limit":5000,"remaining":4818,"reset":1791596511,"observed":1791593183}
(note: the bucket shown on the run-4 header line was read after the run; before the run it was {remaining:400, reset: now-5})
Evidence: Ledger below floor with no prior ledger: degraded row

Source: Ledger below floor with no prior ledger: degraded row

=== Ledger below floor with no earlier published ledger ===
exit=0 gh calls=0
{"complete":false,"stale":true,"rows":[{"category":"coverage","subject":"ledger degraded","evidence":"GitHub core quota low (100 of 5000 left, below the 15% floor); network sweep skipped until the window resets at 2026-10-10T01:16:47Z"}]}
Evidence: R2: aged staged temp files pruned, fresh kept

Source: R2: aged staged temp files pruned, fresh kept

=== R2: leaked staged temp files older than 60 min are pruned by a normal get ===
before:
-rw-r--r--   1 charlesabrooker  staff       9 Oct  9 19:46 .entry.NEW333
-rw-r--r--   1 charlesabrooker  staff       7 Oct  9 17:46 .entry.OLD111
-rw-r--r--   1 charlesabrooker  staff     9 Oct  9 19:46 .gh-ratelimit.NEW444
-rw-r--r--   1 charlesabrooker  staff     7 Oct  9 17:46 .gh-ratelimit.OLD222
{"number":81}
after:
-rw-r--r--   1 charlesabrooker  staff       9 Oct  9 19:46 .entry.NEW333
-rw-r--r--   1 charlesabrooker  staff       0 Oct  9 19:46 .pruned
-rw-r--r--   1 charlesabrooker  staff     9 Oct  9 19:46 .gh-ratelimit.NEW444
real gh call:
00:46:48 rc=0 status=200 used=214 remaining=4786 argv=api -i repos/MrGTV-love/firstmate/pu
Evidence: tests/fm-gh-rest.test.sh output (17/17 ok)

Source: tests/fm-gh-rest.test.sh output (17/17 ok)

ok - a 304 serves the cached body without a new counted call
ok - changed data is fetched once and the refreshed entry is reused
ok - a missing, corrupt, or unparsable cache falls back to a normal GET
ok - pagination follows Link and every page rides the cache
ok - 304 pagination metadata adds and removes pages, and survives omitted headers
ok - a full cached last page whose 304 omits Link is re-read, so comment 101 is found
ok - a concurrent 304 serves its ETag generation without rewriting the replacement body or links
ok - a failed read exits nonzero, names the error, and caches nothing
ok - unwritable state and contended recording locks preserve prompt reads and forge errors
ok - the floor comes from response headers and ends at the reset
ok - concurrent responses retain the lowest remaining quota
ok - older windows cannot replace newer quota, and newer windows replace it
ok - a 304 response still updates the recorded quota
ok - get refuses below the floor before any network call
ok - fresh and cached pages stop pagination at the quota floor without partial output
ok - a full cached last page is not re-read once its 304 reports quota below the floor
ok - the prune pass removes staged files a killed helper left behind and keeps fresh ones

Pipeline

Updates from git push no-mistakes

✅ **intent** - passed

✅ No issues found.

✅ **Rebase** - passed

✅ No issues found.

⚠️ **Review** - 3 issues (1 warning, 2 infos)
  • ⚠️ bin/fm-contributions.sh:461 - A quota-stale mark hides the next real failure. mark_quota_stale (bin/fm-contributions.sh:252-278) writes the quota reason into each owner's .error. The once-per-episode wake check at bin/fm-contributions.sh:461-463 prints 'observation unavailable' only when every owner has .error == null. Concrete sequence: poll N runs below the floor and marks PR 8 stale. The window resets. In poll N+1, guard returns empty, observe() gets a real HTTP 502, and no quota-low file exists. The all(.error == null) test is false because the quota reason is still saved. So the new genuine failure episode is never announced and firstmate is not woken. The row is still written with the generic error, so later polls also stay silent. Fix at the same boundary: in the jq test at line 461-463, treat a saved quota-reason error (one whose text contains ' quota low (') as no prior failure. The same invariant must hold in the announce check in mark_quota_stale at bin/fm-contributions.sh:257-263, which already scopes itself to quota errors and needs no change.
  • ℹ️ bin/fm-gh-rest.sh:92 - Staged temp files can leak forever. fetch_page stages cache entries as $CACHE/.entry.XXXXXX (bin/fm-gh-rest.sh:165, :182). record_rate stages $STATE/.gh-ratelimit.XXXXXX (:72). These files are removed only on the normal path. Callers kill the helper on purpose: contributions forge() wraps it in fm_run_timed with a bound of 5 s or less, and the ledger's stop_command sends SIGKILL. The staged entry also lives through record_response's lock wait of up to 2 s (:113), so a kill inside that window is reachable. prune_cache (:92) deletes only *.json, so each leaked full-body .entry.* copy stays in state/gh-rest-cache for good. Fix: in the same prune pass, also delete .entry.* in $CACHE and .gh-ratelimit.* in $STATE that are older than a short age (for example -mmin +60).
  • ℹ️ bin/fm-gh-rest.sh:161 - The full-last-page re-read skips the quota floor. A 304 with no Link header for a full cached last page records that 304's headers (:159), then at once makes a counted unconditional GET (:161). It does not return to cmd_get's per-page quota_low check (:224). If the 304 reported quota below the floor, the helper still spends one more counted call. docs/configuration.md says 'every REST read checks the floor before each page'. Fix: call quota_low core after record_response at :159, and exit 75 with the reason before the unconditional fetch_page.
  • ℹ️ bin/fm-contributions.sh:316 - GraphQL quota is still not tracked. The intent says GraphQL was used up by a burst from an unknown consumer. This change records and enforces only the REST core bucket. The contributions poll's per-PR GraphQL read (gh pr view at :316) is gated on the core bucket, not the graphql bucket. This does not contradict the intent, because the burst consumer is unknown and the documented scope is REST. It only means this change does not prevent the GraphQL exhaustion that broke no-mistakes gh pr view.

🔧 Fix applied.
3 issues (1 warning, 2 infos) still open:

  • ⚠️ bin/fm-contributions.sh:461 - A quota-stale mark hides the next real failure. mark_quota_stale (bin/fm-contributions.sh:252-278) writes the quota reason into each owner's .error. The once-per-episode wake check at bin/fm-contributions.sh:461-463 prints 'observation unavailable' only when every owner has .error == null. Concrete sequence: poll N runs below the floor and marks PR 8 stale. The window resets. In poll N+1, guard returns empty, observe() gets a real HTTP 502, and no quota-low file exists. The all(.error == null) test is false because the quota reason is still saved. So the new genuine failure episode is never announced and firstmate is not woken. The row is still written with the generic error, so later polls also stay silent. Fix at the same boundary: in the jq test at line 461-463, treat a saved quota-reason error (one whose text contains ' quota low (') as no prior failure. The same invariant must hold in the announce check in mark_quota_stale at bin/fm-contributions.sh:257-263, which already scopes itself to quota errors and needs no change.
  • ℹ️ bin/fm-contributions.sh:316 - GraphQL quota is still not tracked. The intent says GraphQL was used up by a burst from an unknown consumer. This change records and enforces only the REST core bucket. The contributions poll's per-PR GraphQL read (gh pr view at :316) is gated on the core bucket, not the graphql bucket. This does not contradict the intent, because the burst consumer is unknown and the documented scope is REST. It only means this change does not prevent the GraphQL exhaustion that broke no-mistakes gh pr view.
  • ℹ️ bin/fm-contributions.sh:463 - Round 1 fix R1 is correct. It has one side effect. Sequence: a real forge failure wakes firstmate. Then a quota-low episode replaces the saved error with the quota reason (mark_quota_stale, bin/fm-contributions.sh:275). Then the window resets and the forge still fails. The poll now prints 'observation unavailable' a second time for the same outage. This is at most one more wake per quota window, and it is the safe direction (no hidden failure). Two comments still state the old rule 'no prior owner has an error': bin/fm-contributions.sh:75-76 and bin/fm-contributions.sh:460. No action is necessary.
✅ **Test** - passed

✅ No issues found.

  • Live validation: ✅ go - 10 of 11 scenarios driven live against the product
Scenario Result Live Evidence
A repeated REST read of one PR is answered from the ETag cache with a 304 that does not spend core quota ✅ pass live s1-live-conditional-get.txt: call 1 status=200 used=1737; calls 2-3 status=304 used=1737; identical bodies; gh-ratelimit.core.json recorded from headers
A paginated read follows Link on a cold cache and serves every page from 304s on a warm cache with identical output ✅ pass live s2-live-paginated-conditional.txt: 3 pages [40,40,4] cold (200s), warm 3x 304, slurped output identical
A warm paginated read whose exactly-full last page gets a Link-less 304 re-reads that page once, so a newly added page is not missed ✅ pass live s3-live-full-last-page.txt: real GitHub 304 has no Link header; helper makes one unconditional 200 re-read of page 2; output identical
Below the 15% floor with an open window, guard and get refuse with exit 75, the reason, no stdout, and no gh call; at the floor, after reset, or with no record they proceed ✅ pass live s4-quota-floor-refusal.txt: 700/5000 -> guard exit 75 reason on stdout; get and paginated get exit 75, 0 stdout bytes, 0 gh calls; 750/5000 exit 0; expired window and no record exit 0 and real read su…
The contributions poll re-reading an unchanged open PR spends no counted REST calls on a warm cache ✅ pass live s5-live-contributions-poll-304.txt: poll 2 made 7 REST calls, all 304, plus the GraphQL head read; record fresh with error null
Below the floor the contributions poll makes no forge call, keeps the last observation and checked_at, marks it stale with the reset time, announces once per window, and recovers after reset ✅ pass live s6-live-contributions-quota-floor.txt: poll 3 printed one quota line, 0 gh calls, observation unchanged; poll 4 silent with updated reason; poll 5 after reset read normally and cleared the error
Adversarial R1: after a quota-stale mark, a genuine forge failure in the next window still prints 'observation unavailable' once and stays silent after that ✅ pass live s7-live-r1-failure-after-quota-episode.txt: poll A quota-stale mark; poll B real 404 -> 'contributions: observation unavailable for .../pull/999999'; poll C silent
The open-work ledger reads PRs through the helper; below the floor it publishes the last rows marked stale with stale_reason and stale_until_epoch, makes no gh call, and refreshes after reset ✅ pass live s8-live-ledger-quota-floor.txt: warm run 3/3 304 with used unchanged; low-quota run 0 calls, complete=false, stale=true, rows stale=true, generated_epoch kept, 'ledger stale' row; run 4 after reset co…
Adversarial: the ledger below the floor with no earlier published ledger reports 'ledger degraded' instead of an empty 'nothing owed' result ✅ pass live s9-live-ledger-no-prior.txt: 0 gh calls, one coverage 'ledger degraded' row carrying the quota reason, complete=false
R2: a normal get prunes staged .entry.* and .gh-ratelimit.* files older than 60 minutes and keeps fresh ones ✅ pass live s10-live-r2-prune-staged.txt: OLD111/OLD222 (2h old) removed, NEW333/NEW444 kept after a real get
R3: a 304 on a full cached last page that reports quota below the floor does not spend the unconditional re-read ⏸️ untested no The prior payload did not establish a live result for this scenario. It recorded only the shim-backed bash tests/fm-gh-rest.test.sh case ('ok - a full cached last page is not re-read once its 304 re…
  • bin/fm-lab-home.sh create $LAB (disposable marked lab FM_HOME, removed with rm -rf $LAB at the end)
  • Pass-through gh spy on PATH that runs the real /opt/homebrew/bin/gh and logs HTTP status plus X-RateLimit-Used/Remaining for each call
  • FM_HOME=$LAB bin/fm-gh-rest.sh get repos/MrGTV-love/firstmate/pulls/81 x3 (cold then warm) against real GitHub
  • bin/fm-gh-rest.sh get &#39;repos/MrGTV-love/firstmate/pulls?state=all&amp;per_page=40&#39; --paginate --slurp cold and warm (3 pages)
  • bin/fm-gh-rest.sh get &#39;repos/MrGTV-love/firstmate/pulls?state=all&amp;per_page=42&#39; --paginate --slurp cold and warm (exactly-full last page)
  • bin/fm-gh-rest.sh guard and get with a lab quota record below, at, and above the floor, with an expired window, and with no record
  • bin/fm-contributions.sh poll in the lab home (private TMUX_TMPDIR) owning real PR MrGTV-love/firstmate#84: cold, warm, below floor x2, after window reset
  • R1 sequence: fm-contributions.sh poll owning nonexistent PR #999999: quota-stale poll, then reset poll with a real 404, then repeat poll
  • bin/fm-open-loops.sh --json --heartbeat in the lab home: cold, warm, below floor (JSON and TOON), after reset, and below floor with no prior ledger
  • R2: aged .entry.* and .gh-ratelimit.* staged files plus fresh ones, then a real fm-gh-rest.sh get
  • bash tests/fm-gh-rest.test.sh (17/17 ok, including the R3 case: a 304 that reports low quota on a full last page; this is a shim-backed test, not a live run)
✅ **Document** - passed

✅ No issues found.

🔧 **Lint** - 1 issue found → no changes applied ✅
  • ⚠️ linter found issues (exit code 143)

🔧 No changes applied.
✅ Re-checked - no issues remain.

✅ **Push** - passed

✅ No issues found.

…and contributions sweeps

Add bin/fm-gh-rest.sh: GET with If-None-Match from a per-URL ETag cache under
state/ (a 304 serves the cached body and is not counted against the rate
limit), recording X-RateLimit-* from every response. Route fm-contributions,
fm_open_loops, fm-pr-state and fm-pr-reviewers REST reads through it.

Below the floor (FM_GH_RATE_FLOOR_PERCENT, default 15) the contributions poll
keeps each row's last observation marked stale with the reset time, and the
ledger republishes its last rows marked stale instead of publishing partial
rows.
…and contributions sweeps

Add bin/fm-gh-rest.sh: GET with If-None-Match from a per-URL ETag cache under
state/ (a 304 serves the cached body and is not counted against the rate
limit), recording X-RateLimit-* from every response. Route fm-contributions,
fm_open_loops, fm-pr-state and fm-pr-reviewers REST reads through it.

Below the floor (FM_GH_RATE_FLOOR_PERCENT, default 15) the contributions poll
keeps each row's last observation marked stale with the reset time, and the
ledger republishes its last rows marked stale instead of publishing partial
rows.
…s-observer unregistration to the shared bounded-watcher fixture, preventing unrelated observer wakes from preempting PR-security scenarios. Removed redundant per-case cleanup and documented the isolation. The previously failing self-merge scenario and focused transition, retry, and concurrent-publication scenarios pass. Check-unregister tests, shell syntax, and documentation audience checks pass. The scoped CI runner progressed through the reported failure and subsequent retirement/authority cases, but the full security suite remains red at a later, separate teardown fixture failure: it records a nonexistent project, preventing nested-worktree ownership verification. That fixture and teardown implementation are unchanged from the base commit; they were left untouched. Production behavior was not changed
…and contributions sweeps

Add bin/fm-gh-rest.sh: GET with If-None-Match from a per-URL ETag cache under
state/ (a 304 serves the cached body and is not counted against the rate
limit), recording X-RateLimit-* from every response. Route fm-contributions,
fm_open_loops, fm-pr-state and fm-pr-reviewers REST reads through it.

Below the floor (FM_GH_RATE_FLOOR_PERCENT, default 15) the contributions poll
keeps each row's last observation marked stale with the reset time, and the
ledger republishes its last rows marked stale instead of publishing partial
rows.
…s-observer unregistration to the shared bounded-watcher fixture, preventing unrelated observer wakes from preempting PR-security scenarios. Removed redundant per-case cleanup and documented the isolation. The previously failing self-merge scenario and focused transition, retry, and concurrent-publication scenarios pass. Check-unregister tests, shell syntax, and documentation audience checks pass. The scoped CI runner progressed through the reported failure and subsequent retirement/authority cases, but the full security suite remains red at a later, separate teardown fixture failure: it records a nonexistent project, preventing nested-worktree ownership verification. That fixture and teardown implementation are unchanged from the base commit; they were left untouched. Production behavior was not changed
@MrGTV-love
MrGTV-love merged commit 38817c5 into main Oct 10, 2026
22 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant