fix(bin): stop transient forge read timeouts from waking the contributions watcher

[belyaev-den]

Intent

Stop the repeating "contributions: observation unavailable" wake for a healthy watched issue.

Observed on 2026-09-26 in one home: https://github.com/mvdlabtech/manvaig/issues/56 (open, unchanged, 3 comments) produced a check: contributions: observation unavailable wake roughly every hour for most of a day. Every manual gh api read of the issue, its comments and its events succeeded, typically in 0.7-1 s, but one events read in eighteen took 5.2 s. bin/fm-contributions.sh caps every forge read at 5 s, a slow read counts as a genuine failure, and each later successful poll ends the failure "episode", so every occasional slow read starts a new episode and wakes the supervisor again. The wake carries no contribution signal; it is noise that costs a supervisor turn each time.

What Changed

• bin/fm-contributions.sh: a forge read that hits the 5 s timeout outside the budget deadline is now tracked separately (forge-timeout marker) from a genuine forge failure. If the URL still has a fresh prior good observation (error-free, within FM_CONTRIBUTIONS_MAX_AGE), the poll keeps that record untouched and retries next poll, with no observation unavailable error and no wake.
• A timeout with no prior observation, or with a stale one, still records the unavailable error and wakes once per failure episode. Non-timeout forge failures take the same path as before.
• tests/fm-contributions.test.sh: adds coverage for both cases. A timeout with a fresh observation is suppressed. A timeout once the observation has gone stale still records the error and wakes.

Risk Assessment

✅ Low: This is a small change. It only suppresses a wake when a single non-budget forge read times out (rc 124), no genuine failure happened in the same observation, and some owner still has an error-free observation within FM_CONTRIBUTIONS_MAX_AGE. Stale, missing or errored evidence still records an error and wakes once per episode, and behavioral tests cover both paths.

Testing

I ran the six targeted contribution tests; all pass on this change, and the two new ones fail on the base commit. I then ran fm-contributions.sh poll live, seven times, in a disposable lab home. It used the real GitHub issue from the report with the real gh login, with the events read slowed past the 5 s cap. On the base script, one-off slow reads between healthy polls woke the supervisor each time; on the fixed script they stay silent and the saved observation is left unchanged. Once the observation goes stale, a real outage still wakes exactly once, and the next healthy poll ends the failure episode. Both transcripts are in the evidence directory. This is a CLI/check change, so there is no visual UI to capture. The unit-test-only scenarios are reported as untested for live purposes.

• Live validation: ✅ go - 3 of 5 scenarios driven live against the product

Scenario	Result	Live	Evidence
Healthy watched issue with one slow (>5 s) events read between successful polls: poll prints nothing, keeps the prior observation, and the next healthy poll refreshes it	✅ pass	live	live-poll-transcript-after.txt polls B-D: stdout empty, checked_at unchanged at the prior good time, error null; base transcript polls B and D print 'contributions: observation unavailable for https:/…
Adversarial: reads keep timing out until the last good observation is past FM_CONTRIBUTIONS_MAX_AGE, so poll records the error and wakes	✅ pass	live	live-poll-transcript-after.txt poll E (16 min later): stdout is the unavailable line and the record error is 'forge observation unavailable or changed during read'
A continued outage wakes only once per failure episode, and a healthy poll ends the episode	✅ pass	live	live-poll-transcript-after.txt poll F silent with the error kept; poll G healthy, error cleared, silent
Regression tests reproduce the defect before the fix and pass after it	⏸️ untested	no	The prior payload only established this through unit tests (targeted-tests-before-base.txt vs targeted-tests-after.txt), not a live product run, so no live result was recorded.
Genuine (non-timeout) forge failures and budget-exhaustion handling are unchanged	⏸️ untested	no	The prior payload only covered this with unit tests (test_unavailable_forge_records_error_and_wakes_once_per_episode, test_genuine_failure_near_deadline_is_unavailable, test_budget_bounded_call_timeou…

Evidence: Live poll transcript with the fix (real issue #56, events read delayed 6 s)

Source: Live poll transcript with the fix (real issue #56, events read delayed 6 s)

== poll A healthy first observation (clock 2026-09-27T01:55:06Z, events read normal)
rc=0 elapsed=2s stdout=[]
record: {"checked_at":"2026-09-27T01:55:06Z","error":null,"state":"open","comments":0}
wake-queue lines: 0

== poll B one slow events read, prior observation 60s old (clock 2026-09-27T01:56:06Z, events read delayed 6s > 5s cap)
rc=0 elapsed=7s stdout=[]
record: {"checked_at":"2026-09-27T01:55:06Z","error":null,"state":"open","comments":0}
wake-queue lines: 0

== poll C healthy recovery (clock 2026-09-27T01:57:06Z, events read normal)
rc=0 elapsed=2s stdout=[]
record: {"checked_at":"2026-09-27T01:57:06Z","error":null,"state":"open","comments":0}
wake-queue lines: 0

== poll D slow events read again (the hourly-noise pattern) (clock 2026-09-27T01:58:06Z, events read delayed 6s > 5s cap)
rc=0 elapsed=7s stdout=[]
record: {"checked_at":"2026-09-27T01:57:06Z","error":null,"state":"open","comments":0}
wake-queue lines: 0

== poll E slow events read, last good observation 16 min old (stale) (clock 2026-09-27T02:13:06Z, events read delayed 6s > 5s cap)
rc=0 elapsed=163s stdout=[contributions: observation unavailable for https://github.com/mvdlabtech/manvaig/issues/56]
record: {"checked_at":"2026-09-27T02:13:06Z","error":"forge observation unavailable or changed during read","state":"open","comments":0}
wake-queue lines: 0

== poll F still timing out, same failure episode (clock 2026-09-27T02:14:06Z, events read delayed 6s > 5s cap)
rc=0 elapsed=6s stdout=[]
record: {"checked_at":"2026-09-27T02:14:06Z","error":"forge observation unavailable or changed during read","state":"open","comments":0}
wake-queue lines: 0

== poll G healthy recovery ends episode (clock 2026-09-27T02:15:06Z, events read normal)
rc=0 elapsed=2s stdout=[]
record: {"checked_at":"2026-09-27T02:15:06Z","error":null,"state":"open","comments":0}
wake-queue lines: 0

Evidence: Live poll transcript on base commit (reproduces the repeated wake)

Source: Live poll transcript on base commit (reproduces the repeated wake)

== poll A healthy first observation (clock 2026-09-27T01:58:33Z, events read normal)
rc=0 elapsed=2s stdout=[]
record: {"checked_at":"2026-09-27T01:58:33Z","error":null,"state":"open","comments":0}
wake-queue lines: 0

== poll B one slow events read, prior observation 60s old (clock 2026-09-27T01:59:33Z, events read delayed 6s > 5s cap)
rc=0 elapsed=6s stdout=[contributions: observation unavailable for https://github.com/mvdlabtech/manvaig/issues/56]
record: {"checked_at":"2026-09-27T01:59:33Z","error":"forge observation unavailable or changed during read","state":"open","comments":0}
wake-queue lines: 0

== poll C healthy recovery (clock 2026-09-27T02:00:33Z, events read normal)
rc=0 elapsed=2s stdout=[]
record: {"checked_at":"2026-09-27T02:00:33Z","error":null,"state":"open","comments":0}
wake-queue lines: 0

== poll D slow events read again (the hourly-noise pattern) (clock 2026-09-27T02:01:33Z, events read delayed 6s > 5s cap)
rc=0 elapsed=366s stdout=[contributions: observation unavailable for https://github.com/mvdlabtech/manvaig/issues/56]
record: {"checked_at":"2026-09-27T02:01:33Z","error":"forge observation unavailable or changed during read","state":"open","comments":0}
wake-queue lines: 0

== poll E slow events read, last good observation 16 min old (stale) (clock 2026-09-27T02:16:33Z, events read delayed 6s > 5s cap)
rc=0 elapsed=7s stdout=[]
record: {"checked_at":"2026-09-27T02:16:33Z","error":"forge observation unavailable or changed during read","state":"open","comments":0}
wake-queue lines: 0

== poll F still timing out, same failure episode (clock 2026-09-27T02:17:33Z, events read delayed 6s > 5s cap)
rc=0 elapsed=6s stdout=[]
record: {"checked_at":"2026-09-27T02:17:33Z","error":"forge observation unavailable or changed during read","state":"open","comments":0}
wake-queue lines: 0

== poll G healthy recovery ends episode (clock 2026-09-27T02:18:33Z, events read normal)
rc=0 elapsed=2s stdout=[]
record: {"checked_at":"2026-09-27T02:18:33Z","error":null,"state":"open","comments":0}
wake-queue lines: 0

Evidence: Targeted regression tests on this change

Source: Targeted regression tests on this change

ok - one issue read timeout between successes retains the prior observation without a wake
ok - persistent issue timeouts wake after the last good observation expires
ok - a genuinely unavailable forge records an error and wakes once per failure episode
ok - budget exhausted mid-observation (hang) keeps the prior record and stays silent
ok - a genuine forge failure inside the budget still records the error and wakes
ok - a late owner does not restart a shared forge failure episode

Evidence: New regression tests failing on base commit

Source: New regression tests failing on base commit

not ok - a transient issue-events timeout printed a wake: contributions: observation unavailable for https://github.com/o/r/issues/9
not ok - a timeout within the freshness bound woke: contributions: observation unavailable for https://github.com/o/r/issues/9
not ok - 2 contribution regressions

- Outcome: ⚠️ 1 info across 1 run (4m29s)

Pipeline

Updates from git push no-mistakes

✅ **intent** - passed

✅ No issues found.

✅ **Rebase** - passed

✅ No issues found.

✅ **Review** - passed

✅ No issues found.

⚠️ **Test** - 1 info

• ℹ️ In both the base run and the fixed run, one poll right after two earlier slow-read polls stalled for about 160-370 s before finishing. The stall also happens with the base script, so this change did not cause it. It may come from the test shim's killed sleep or from local lock/snapshot timing; it is outside the scope of this change and worth a separate look.
• Live validation: ✅ go - 3 of 5 scenarios driven live against the product

Scenario	Result	Live	Evidence
Healthy watched issue with one slow (>5 s) events read between successful polls: poll prints nothing, keeps the prior observation, and the next healthy poll refreshes it	✅ pass	live	live-poll-transcript-after.txt polls B-D: stdout empty, checked_at unchanged at the prior good time, error null; base transcript polls B and D print 'contributions: observation unavailable for https:/…
Adversarial: reads keep timing out until the last good observation is past FM_CONTRIBUTIONS_MAX_AGE, so poll records the error and wakes	✅ pass	live	live-poll-transcript-after.txt poll E (16 min later): stdout is the unavailable line and the record error is 'forge observation unavailable or changed during read'
A continued outage wakes only once per failure episode, and a healthy poll ends the episode	✅ pass	live	live-poll-transcript-after.txt poll F silent with the error kept; poll G healthy, error cleared, silent
Regression tests reproduce the defect before the fix and pass after it	⏸️ untested	no	The prior payload only established this through unit tests (targeted-tests-before-base.txt vs targeted-tests-after.txt), not a live product run, so no live result was recorded.
Genuine (non-timeout) forge failures and budget-exhaustion handling are unchanged	⏸️ untested	no	The prior payload only covered this with unit tests (test_unavailable_forge_records_error_and_wakes_once_per_episode, test_genuine_failure_near_deadline_is_unavailable, test_budget_bounded_call_timeou…

• tests/fm-contributions.test.sh subset: test_issue_read_timeout_between_successes_stays_silent, test_persistent_issue_read_timeout_wakes_when_stale, test_unavailable_forge_records_error_and_wakes_once_per_episode, test_budget_bounded_call_timeout, test_genuine_failure_near_deadline_is_unavailable, test_late_owner_keeps_failure_episode_suppressed (all pass at cd9d463)
• Same two new regression tests against a base-commit (30ef650) bin/ export: both fail with the spurious wake line, which confirms they reproduce the defect
• Live: disposable lab home from bin/fm-lab-home.sh create, backlog row watching https://github.com/mvdlabtech/manvaig/issues/56, real gh behind a PATH shim that sleeps 6 s on the events read when enabled, bin/fm-contributions.sh poll run seven times (healthy / slow within freshness / recovery / slow / slow after 16 min / slow again / recovery)
• Same seven-poll live sequence against the base-commit script for a before/after comparison

✅ **Document** - passed

✅ No issues found.

✅ **Lint** - passed

✅ No issues found.

✅ **Push** - passed

✅ No issues found.

[belyaev-den]

Superseded by #5900, which already treats read-bound forge timeouts as non-evidence; closing.