fix: stop apply checks hanging when a stack status update hits SQLITE_BUSY - #248
Merged
Merged
Conversation
An apply hung in 'report' with one stack 'running': that stack's terminal /api/update 500'd in 18ms and the runner dropped it, and driveApply concludes only when every stack is terminal. - store: open with _txlock=immediate so read-then-write transactions (EventStore.Append, claims) take the write lock up front, where busy_timeout applies; set busy_timeout before journal_mode. - runner: retry Update on transport errors and 5xx; log a tick that still is not recorded instead of discarding it. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
A non-failed Finalize received while an apply execution is in the report phase is the runner's terminal success signal: PhaseReport is emitted only after the terramate apply script returns, and the final Finalize carries Failed = (applyErr != nil). The mid-apply classify Finalize is also non-failed but lands before PhaseApplying. On that signal, tick every still-non-terminal stack to safe and drive the check to its conclusion. A failed finalize is unchanged: it still folds those stacks to aborted and concludes failure. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
Code Coverage OverviewLanguages: Go Go / code-coverage/goThe overall line coverage in commit a2a80f4 in the Show a line coverage summary of the most impacted files.
|
ivank
approved these changes
Sep 23, 2026
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Summary
A post-merge apply can hang forever in the
reportphase with one stack stuck atrunning. The apply itself finished, and terraform state holds the new resources. The execution record and theapply/<env>check just never conclude.This PR fixes it in three layers:
Root cause
Measured, on a real 3-stack apply, from serve's request logs, the build log and the stored execution:
POST /api/update→ 500 in 18 ms. It came at the moment the third stack finished applying, while a sibling stack's update and two/api/logsposts were in flight.running./api/phase(report) and/api/finalizeboth returned 200 afterwards. The apply check still never concluded, becausedriveApplyreports success only when every stack is terminal. A non-failed applyFinalizedid nothing about a stack still marked running, even though the comment inrun applysays it covers a missed tick._ = client.Update(...), 10 s timeout, no retry), so the build log showed nothing./api/*500s appear regularly under concurrent stack updates. On a plan run, the non-failed finalize concludes the run regardless of a missing tick. On an apply, any one of them lost on a stack's terminal update strands the check.In short: under concurrent stack status updates, the event store's read-then-write deferred transaction fails with
SQLITE_BUSYimmediately (busy_timeoutdoesn't apply to a deferred-to-write upgrade), the runner drops the error, and the apply check never completes.Inferred, because the handler doesn't log the error text, then reproduced in a test:
EventStore.Appendopens a DEFERRED transaction and reads (SELECT MAX(version)) before it writes.INSERT, SQLite returnsSQLITE_BUSYat once and never calls thebusy_timeouthandler, because waiting cannot refresh a stale read snapshot.busy_timeout(5000)therefore never helped this path. The per-stream mutex andEventStore.mudon't help either, since other tables (logs, claims, projections) are written on other pool connections.Changes
internal/store/db.go: open with_txlock=immediate. Everydb.BeginbecomesBEGIN IMMEDIATE, so a read-then-write transaction takes the write lock up front.busy_timeoutapplies there, so the transaction waits instead of failing.busy_timeoutis now set beforejournal_mode(WAL), so a new pool connection's pragma waits too.internal/runner/client.go:Client.Updateretries on transport errors and 5xx, 3 attempts with linear backoff (0.5 s, 1 s). A 4xx is returned at once. Re-sending a tick is idempotent, since the fold just sets the status again.run wrapnow prints a status it failed to record instead of discarding the error.internal/server/handlers.go: a successful apply finalize concludes stacks whose tick was lost.run applyemitsPhaseReportonly after the terramate apply script returns, thenFinalize{Failed: applyErr != nil}. The mid-apply classifyFinalizeis also non-failed, but it lands beforePhaseApplying.Finalizereceived while the execution's phase isreportis the success signal.safe, with a detail saying so, and drives the check to its conclusion.abortedand the check concludesfailure.Tests
internal/store/busy_test.go,TestAppendSurvivesConcurrentWriters: concurrentAppends racing autocommit writers on the same file DB.mainit fails every run withdatabase is locked (5) (SQLITE_BUSY)._txlock=immediatemakes it fail again.internal/runner/client_retry_test.go,TestUpdateRetriesTransient5xx: covers one 500 then ok (2 calls), a persistent 500 (3 calls, then an error) and a 4xx (1 call, no retry).internal/server/apply_lost_tick_test.goreplays the failing sequence: init with 3 stacks, a classify finalize, applying, all three running, two terminal ticks, report, then finalize.TestSuccessfulApplyFinalizeConcludesLostTick: 3 of 3 stackssafe, executionsuccess, check runsuccess. Against the old handler it reproduces the stuck state exactly: the third stackrunning,in_progress, no conclusion.TestFailedApplyFinalizeDoesNotConcludeLostTick: the unreported stack becomesabortedrather thansafe; execution and check both endfailure.go vet ./...is clean.go test ./...passes.cmd/tfstackplantests each failed once across about 6 local full-suite runs:TestApplyPhaseEmittedAfterGateon an IPv6 dial tooauth2.googleapis.com, andTestRunPlanAbortsDeferredFinalize.main.cmd/tfstackplanpackage 8 of 8 clean on both.Risks and limitations
BEGIN IMMEDIATEon every transaction, including any that only read, serializes transactions against each other. That's fine for a single-instance serve with a small write rate. A transaction held across a network call would now block writers for up to 5 s instead of failing fast. I found none, but reviewers should keep an eye out.safe. Terramate runs every stack it was given or exits non-zero, so this shouldn't happen, but it is now an assumption. A stack concluded this way carries the detail text, and a realnochangestack whose tick was lost will readsafe.🤖 Generated with Claude Code