Skip to content

Poller: step timeouts so a hang fails the run; status.py --live alerts on timeouts and a missing bot-state branch - #65

Merged
Deicyde merged 3 commits into
mainfrom
claude/poller-timeout-alerts
Oct 17, 2026
Merged

Deicyde merged 3 commits into
mainfrom
claude/poller-timeout-alerts

Conversation

@Deicyde

@Deicyde Deicyde commented Oct 15, 2026 •

Copy link
Copy Markdown
Owner

Follow-up to #61 (closed). The review of #61 found the timeout blind spot this PR fixes. 209 of the poller's 210 cancelled runs lasted 30 minutes or more: they were ticks killed by the job's timeout-minutes: 30, not runs the concurrency group dropped. A job timeout ends a run as cancelled, and both #61's checker and manage/status.py skipped every cancelled run. Replayed on the 2026-08 stall, five timed-out ticks in a row fill status.py's five-run window, and --live prints a silent CI ? with no alert. As both reviewers asked, this PR keeps a single engine (manage/status.py) and fixes the problem at its source.

Changes

.github/workflows/wikidata-poll.yml: step-level timeouts on the long steps:

  • Install pinned Claude CLI: 10 min
  • Clone mathlib4: 10 min
  • Poll tick (apply): 50 min

The job limit goes from 30 to 60 min. A batch open spends most of its tick in bot/refresh_tagged.py: in 2026-08 the 30-minute limit cancelled 200 of 221 batch-open ticks while it was still running, and the 21 that got past it took 19 to 30 minutes in the tick step.

  • The runner marks a step that hits its own timeout-minutes as failed ("The action '…' has timed out after N minutes."). Only the job-level limit produces cancelled. So a hang now ends the run as an ordinary failure.
  • In every timed-out run sampled (18 of the 209), Poll tick (apply) was the step running when the job limit hit. The steps before it take about a minute and the steps after it a few seconds, so a timed-out tick still leaves time for Commit poll state (always()) inside the job limit. Settle ticks take under 2 minutes.
  • bot/README.md ("A poller run is red") lists the new message.
  • A test in bot/test_state_branch.py keeps each of these step timeouts below the job's.

manage/status.py

  • ci_gate lists 20 runs (was 5) and reads startedAt,updatedAt.
    • A cancelled run that lasted 25 minutes or more counts as a red run: wikidata-poll run N timed out (cancelled after 31 min). This still matters after the workflow change, for older runs and for hangs in steps without their own timeout. Short cancellations and skipped runs are still passed over.
    • When no listed run qualifies, it now raises an alert (no finished wikidata-poll run on main (…); the gate is unknown) instead of a silent CI ?.
  • batch_pr: a failed gh pr view now raises an alert (could not read batch PR #N (…); its merge state is unknown), where before it only printed a gh unavailable line.
  • live_section / ci_bot_state: since Make the wikidata poller fail closed #48, the bot-state branch is mandatory.
    • A 404 now raises an alert: every run fails at restore. The alert points at the one-time bootstrap_state dispatch, which applies only if the branch never existed, and otherwise at bot/README.md "Restore failed".
    • On a 404 only, a second read (branches/bot-state) tells a missing branch apart from a branch that lacks bot/state/bot_state.json. The second case is reported as unreadable state, and the batch PR is not checked (the same handling as other read failures).
  • Not duplicated: status.py health alerts #59's alerts for a failed gh run list and for non-404 bot-state read failures are unchanged.

Testing

  • manage/test_status.py: 25 passed. Three tests are new: long-cancelled runs count as timeouts, the no-qualifying-run alert, and the missing bot-state branch alert. Three are updated to cover the batch-PR read failure, the 20-run listing fields, and the branch-without-file and branch-read-failure cases. Against main's status.py, six of them fail.
  • bot/test_state_branch.py (19) and bot/test_poll.py (43) pass. Both parse the workflow.
  • scripts/ci-python.sh: every check passes except the Brain activation integration test, which needs Node 22 and fails only in a local environment with a different Node version. The checks after it were run one by one and pass.
  • Read-only run of live_section against GitHub today: it now shows the missing-branch alert next to run … ended 'failure'. Replaying the 2026-08-16 run listing gives timed out (cancelled after 52 min) where main gave a silent CI ?.

Notes

  • Nothing deploys. The workflow change takes effect on the next poller run after merge. status.py is a local operator tool.
  • Not included, from the earlier review's optional list: naming the failed step from the jobs API, and limiting the merge-conflict label alert to when GitHub's mergeable state is not MERGEABLE.
  • Separate from this PR: the poller fails at restore until the one-time bootstrap_state dispatch creates bot-state (see bot/README.md). Also confirm that GitHub Actions failure notifications reach the account that owns the schedule. The SessionStart hook runs status.py without --live, so those emails are the only unattended signal.

🤖 Generated with Claude Code

… a missing bot-state branch

Follow-up to #61 (closed). Its review found that the poller's long
cancelled runs were hangs, not concurrency noise: 209 of its 210 cancelled
runs lasted 30 minutes or more, the job's timeout. A job timeout ends the run
as cancelled, and status.py skipped every cancelled run, so five hung
ticks in a row left a silent "CI ?".

- wikidata-poll.yml: Install pinned Claude CLI and Clone mathlib4 get a
  10-minute step timeout and Poll tick (apply) 20 minutes, inside the
  job's 30. The runner marks a step that hits its own timeout as failed,
  so a hang ends the run as a failure instead of a cancellation, with
  time left for Commit poll state. bot/README.md lists the message, and
  a wiring test keeps the step timeouts below the job's.
- status.py ci_gate reads 20 runs with startedAt/updatedAt. A cancelled
  run that lasted 25 minutes or more counts as timed out and alerts;
  that covers older runs and hangs in the steps without a timeout of
  their own. When no listed run qualifies it alerts instead of printing
  a silent "CI ?".
- batch_pr: a failed read is an alert, not only a "gh unavailable" line.
- live_section: since #48 the bot-state branch is mandatory, so its 404
  is an alert that points at the one-time bootstrap_state dispatch and
  bot/README.md 'Restore failed'. A second read, only on a 404, tells a
  missing branch from a branch without bot_state.json; the latter is
  reported as unreadable state and the batch PR is not checked.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@Deicyde

Deicyde commented Oct 17, 2026 •

Copy link
Copy Markdown
Owner Author

Ready to merge after one timeout change and a wording fix (reviewed at a457c77f). The status.py alerts are correct and tested, and the missing-branch alert is right today. The problem is the 20-minute cap on "Poll tick (apply)" (wikidata-poll.yml:172). Batch opens spend most of their time in refresh_tagged.py, whose fetch-and-grep runs in a blobless clone, and the August opens that got past it took about 19 to 29 minutes in that step (the review below has the per-run numbers). Raise both the job limit and the tick cap well above that (for example 60 and 50), or drop the tick cap. Then say that the August stalls were slow opens, not hangs, in the body, bot/README.md:180-182 and manage/status.py:50-52. The slow refresh itself predates this PR and needs an owner before #42608 merges. Release-neutral; merge any time. After merging, the missing-branch alert fires until #48's one-time bootstrap_state dispatch.

Posted by the WikiLean PR swarm (lead); updated 2026-10-17.

@Deicyde

Deicyde commented Oct 17, 2026

Copy link
Copy Markdown
Owner Author

Verdict: merge after one small fix. The status.py half is correct and tested: manage/test_status.py 25/25 and bot/test_state_branch.py 19/19 pass at the head, and 6 of the new tests fail against main's status.py, as the PR says. There is no conflict with current main, and both touched test files are already run by scripts/ci-python.sh.

  • Fix before merge: timeout-minutes: 20 on Poll tick (.github/workflows/wikidata-poll.yml:172) is shorter than a batch open takes.
    • The cancelled August runs were not hung. They were in bot/refresh_tagged.py (fetching …mathlib4 master (shallow)…), called from open_batch.py:228.
    • In August, 15 batch-open ticks got past the refresh (they then failed for other reasons). Their Poll tick step took 19.4 to 29.0 minutes, 18.4 to 27.7 of it in refresh_tagged.py. Only one finished under 20: run 31604080427 took 19.4, 31450148197 took 27.6 and 31591501628 took 29.0.
    • Another 203 August ticks were cancelled at the 30-minute job limit, with the step at 29.3 to 29.6 minutes.
    • So the next batch open, after #42608 merges, would likely time out on every attempt. No step limit fits under the current job limit either, since setup takes about 0.8 minutes. Raise both (for example, job 45 and Poll tick 40) or make the refresh faster first.
    • The body's "the tick step itself took under 2 minutes" holds only for settle ticks.
  • Docs: the new bot/README.md bullet (lines 180-182) and the workflow comment call this a hang and advise dispatching again, which just repeats the slow refresh. The real fix is to make refresh_tagged.py faster. A likely, unverified cause: git grep on FETCH_HEAD in a --filter=blob:none clone fetches missing blobs one at a time.
  • Minor, rare: startedAt equals createdAt for these runs, so the reported duration includes queue time. A run that queued for 25 minutes or more and was then dropped from the concurrency queue is reported as "timed out". The body's "cancelled after 52 min" example includes about 22 minutes of queueing.

@Deicyde

Deicyde commented Oct 17, 2026 •

Copy link
Copy Markdown
Owner Author

Recommendation: merge (at 8e4da106, CI green). The requested changes are in:

  • 026578ee raises the job limit to 60 minutes and the poll tick cap to 50, which gives a batch open room; the August opens took 19 to 29 minutes in that step.
  • 8e4da106 replaces the "hung" wording in bot/README.md and the test docstring, and tells the operator to read the step's last line before dispatching again.

Optional: with the job limit at 60, POLL_TIMEOUT_MINUTES could rise toward 55, so a queued run dropped after 25 minutes isn't reported as a timeout. Release-neutral; merge any time. After merging, the missing-branch alert fires until #48's one-time bootstrap_state dispatch.

Posted by the WikiLean PR swarm (lead); updated 2026-10-17.

The 20-minute Poll tick limit was shorter than a batch open takes. In
2026-08 the 30-minute job limit cancelled 200 of 221 batch-open ticks
while bot/refresh_tagged.py was still running, and the 21 that got past
it spent 19 to 30 minutes in the tick step. A step limit under 30 would
have failed every one of them.

The job limit goes to 60 minutes and Poll tick to 50, so a step timeout
still fails the run before the job limit cancels it, with time left for
Commit poll state. Settle and conflict ticks are unaffected. status.py's
25-minute threshold still catches job-limit cancellations, which now last
60 minutes or more; only its comment changes.
@Deicyde

Deicyde commented Oct 17, 2026 •

Copy link
Copy Markdown
Owner Author

Pushed 026578ee with the fix from my review above: job limit 60 minutes, Poll tick 50. I went higher than the 45/40 I suggested because the full August logs show the 30-minute limit cancelled 200 of 221 batch-open ticks while refresh_tagged.py was still running. We don't know how long a refresh can take, so 50 leaves room. A limit only delays how soon a real hang shows up, and ticks run about every 4 hours. The other changes are comments: the workflow's job comment, status.py's POLL_TIMEOUT_MINUTES note (25 still catches a job-limit cancellation) and one test docstring. I've updated the PR body to match.

bot/test_state_branch.py, bot/test_poll.py and manage/test_status.py (25/25) pass locally, and CI is green on 026578ee.

Edit: 8e4da106 also fixes the wording. The README bullet now says a timed-out step ran past its limit, and it says to read the step's last line before dispatching again, because a long refresh just repeats. The test docstring and the body no longer say "hung". Still unchanged: the queue-time point, and the refresh itself. A 50-minute limit still fails if a refresh runs longer.

…atching

The August cancellations were batch opens still inside refresh_tagged.py,
not hangs, and dispatching again only repeats the slow refresh. The
README bullet now says to read the step's last line first and names the
refresh case. The matching test docstring drops "hung".
@Deicyde
Deicyde merged commit ab9e869 into main Oct 17, 2026
4 checks passed
Deicyde added a commit that referenced this pull request Oct 17, 2026
Poller: step timeouts so a hang fails the run; status.py --live alerts on timeouts and a missing bot-state branch
@Deicyde

Deicyde commented Oct 19, 2026

Copy link
Copy Markdown
Owner Author

Re-review on main (eaa5950b): follow-up needed (comment numbers and one threshold). The timeouts are safe; no revert.

First: the poller has been down since 2026-10-14. Every scheduled run since (latest: 39093078411) fails in about 20 s at Restore bot state with "origin/bot-state does not exist", and bot-state returns 404. The last success was 38593451765 (2026-10-14T15:54Z). Nothing shows the branch ever existed: no poller dispatch since 2026-08-08, and no create or delete event for it in the repo's event history. So the one-time gh workflow run wikidata-poll.yml -f bootstrap_state=true from bot/README.md is still pending. That is the owner's call: its first live tick acts on mathlib4#42608. The timeouts in this PR have therefore never run on main.

Follow-ups:

  • The job comment's August numbers are slightly off. Counting every August heavy-tick log (224), there were 223 batch-open ticks.
    • 200 were cancelled inside refresh_tagged.py (that part is right).
    • 23 got past it, not 21, with tick steps of 4.8 to 29.5 minutes, not 19 to 30.
    • Two of those refreshes finished in 4 to 5 minutes but found only 20 and 19 tagged QIDs instead of about 145 (runs 31543433430 and 32036060643). They wrote those truncated lists anyway, because refresh_tagged.py fails closed only on empty output. That's a separate bug worth a guard.
  • Git 2.55: every August log shows git 2.54.0. The runner moved to 2.55.0 around 2026-08-19, and 2.55's git grep fetches a lazy clone's missing blobs in bulk. The comment and the bot/README.md timeout bullet ("another dispatch only repeats it") rest on 2.54-era data and should say so.
  • POLL_TIMEOUT_MINUTES = 25 in manage/status.py is now wrong. With a 60-minute job limit, a cancelled run lasting 25 to 60 minutes is a dropped queued run or a manual cancel, never a timeout. No 30-minute-era cancellation is still within the 20 runs status.py reads. Raise it to about 55, and update the comment and test data.

Checked and fine:

  • The steps before the tick take about 45-50 s.
  • Commit poll state (always()) still ran after August's job-limit cancels.
  • The README's quoted log line matches.

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