Proxy watchdog fails queued jobs before execution; late Solstice success leaves Forgejo falsely red #7

New issue

Open

opened 2026-09-14 17:53:18 +00:00 by toasterson · 0 comments

toasterson commented

2026-09-14 17:53:18 +00:00

Owner

Reproduction and observed evidence

Production on 2026-09-14 UTC, proxy image revision b307005, executor revision 8479c8f. An executor image-cache rollout delayed admission; the recovered executor became Ready at15:41UTC. The queue delay continued behind admitted work.

Repository: toasterson/Anima; PR toasterson/Anima#720
Exact head: 4694527ed1958633785da5db86bd065454214b53
Solstice request: 2a6ccfc8-79dc-4f9c-bd80-bd8fc53848d0
Forgejo task25535; run4469 (Actions API id8678), test job: https://code.aopc.cloud/toasterson/Anima/actions/runs/4469/jobs/1
15:21:21.164950: proxy2 published the JobRequest.
15:56:20.357431: proxy2 logged pruning stale in-flight task (no JobResult received), age_secs=2099; Forgejo marked the test failed after35m.
16:20:04.795265: Solstice actually started execution, after the proxy had failed it.
16:30:05.337832: Solstice completed succeeded, exit_code=0, no failure summary.
16:30:06.963143: proxy logged JobResult for unknown request_id; reporting via embedded creds.
16:30:07.082399: proxy logged reported result via embedded creds (cross-runner fallback), success=true, exit_code=0.
Subsequent Forgejo exact-head status remains failure, updated15:56:20; its successful fallback report did not repair the terminal status.

Solstice logs prove the workload passed: workspace examples build281s, workspace lib/bin tests122s, workspace all-target Clippy134s, followed by ALL CHECKS PASSED. The conflict-check request 1e9a953f-e670-4954-bac7-dc290ff2d690 also succeeded at the same head. Solstice is the execution source of truth; the Forgejo status is a stale projection.

Suspected cause

crates/runner-integration/src/watchdog.rs compares wall time since local in-flight admission against stale_after, removes the request, stops streaming, calls report_failure, and releases the permit without first checking authoritative Solstice queue/execution state. Queue delay is therefore treated as terminal execution failure. reporter.rs subsequently uses cross-runner fallback for the removed request, but an accepted UpdateTask call is not proof that Forgejo changed a terminal job.

Expected behavior and regression coverage

Distinguish queued/admitted/executing/completed states and queue-age from execution timeout. A live queued request must not be reported as a failed test merely because the executor was unavailable or busy.
Reconcile exact request/task/head against authoritative Solstice state before stale cleanup. Keep cleanup bounded for genuinely lost work, preserving explicit unknown/infrastructure failure rather than inventing a test result.
Reconcile late terminal results and verify downstream state. If Forgejo cannot revise a terminal attempt, expose the mismatch and a supported recovery/retry path; do not log delivery as full reconciliation success.
Regression tests: queue longer than watchdog threshold then success; genuine lost request; executor restart; duplicate/late JobResult; watchdog/reporter race; permit accounting exactly once. Verify the final external status or explicit mismatch, not only HTTP success.

This report does not propose disabling timeout protection, editing production SQL, forging green statuses, or weakening review gates. It also does not claim the two-minute CI target: this exact integration workload took approximately10m of execution plus queue delay.

The Forgejo proxy watchdog terminally fails jobs that are still queued in Solstice. When the job subsequently succeeds, the proxy reports success but Forgejo retains the earlier failure. This creates false-red CI and blocks recovery PRs despite successful execution. ## Reproduction and observed evidence Production on 2026-09-14 UTC, proxy image revision b307005, executor revision 8479c8f. An executor image-cache rollout delayed admission; the recovered executor became Ready at15:41UTC. The queue delay continued behind admitted work. - Repository: toasterson/Anima; PR https://code.aopc.cloud/toasterson/Anima/pulls/720 - Exact head: `4694527ed1958633785da5db86bd065454214b53` - Solstice request: `2a6ccfc8-79dc-4f9c-bd80-bd8fc53848d0` - Forgejo task25535; run4469 (Actions API id8678), test job: https://code.aopc.cloud/toasterson/Anima/actions/runs/4469/jobs/1 - 15:21:21.164950: proxy2 published the JobRequest. - 15:56:20.357431: proxy2 logged `pruning stale in-flight task (no JobResult received)`, `age_secs=2099`; Forgejo marked the test failed after35m. - 16:20:04.795265: Solstice actually started execution, after the proxy had failed it. - 16:30:05.337832: Solstice completed `succeeded`, `exit_code=0`, no failure summary. - 16:30:06.963143: proxy logged `JobResult for unknown request_id; reporting via embedded creds`. - 16:30:07.082399: proxy logged `reported result via embedded creds (cross-runner fallback)`, `success=true`, `exit_code=0`. - Subsequent Forgejo exact-head status remains failure, updated15:56:20; its successful fallback report did not repair the terminal status. Solstice logs prove the workload passed: workspace examples build281s, workspace lib/bin tests122s, workspace all-target Clippy134s, followed by `ALL CHECKS PASSED`. The conflict-check request `1e9a953f-e670-4954-bac7-dc290ff2d690` also succeeded at the same head. Solstice is the execution source of truth; the Forgejo status is a stale projection. ## Suspected cause `crates/runner-integration/src/watchdog.rs` compares wall time since local in-flight admission against `stale_after`, removes the request, stops streaming, calls `report_failure`, and releases the permit without first checking authoritative Solstice queue/execution state. Queue delay is therefore treated as terminal execution failure. `reporter.rs` subsequently uses cross-runner fallback for the removed request, but an accepted UpdateTask call is not proof that Forgejo changed a terminal job. ## Expected behavior and regression coverage 1. Distinguish queued/admitted/executing/completed states and queue-age from execution timeout. A live queued request must not be reported as a failed test merely because the executor was unavailable or busy. 2. Reconcile exact request/task/head against authoritative Solstice state before stale cleanup. Keep cleanup bounded for genuinely lost work, preserving explicit unknown/infrastructure failure rather than inventing a test result. 3. Reconcile late terminal results and verify downstream state. If Forgejo cannot revise a terminal attempt, expose the mismatch and a supported recovery/retry path; do not log delivery as full reconciliation success. 4. Regression tests: queue longer than watchdog threshold then success; genuine lost request; executor restart; duplicate/late JobResult; watchdog/reporter race; permit accounting exactly once. Verify the final external status or explicit mismatch, not only HTTP success. This report does not propose disabling timeout protection, editing production SQL, forging green statuses, or weakening review gates. It also does not claim the two-minute CI target: this exact integration workload took approximately10m of execution plus queue delay.

No labels

No milestone

No project

No assignees

1 participant

Notifications

Due date

The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set

Reference

CloudNebulaProject/solstice-ci#7

No description provided.

Rows
Columns