fix(config): make the provider-command timeout an upper bound (#811) - #813
Conversation
providerCommandTimeout bounded only the wait, so the call could take arbitrarily longer than the 5s its error text promised. Two phases sat outside it. Starting the process ran before the clock began. On Windows that is CREATE_SUSPENDED, job-object creation and assignment, and a system-wide thread snapshot, none of it fast on a cold or contended machine. The deadline is now armed first and the start races it, so process creation is inside the budget. Draining after termination was unbounded too: the timer path called Terminate and then received on the wait with no limit. Terminate normally makes that immediate, which is exactly why it survived unnoticed, but a tree that resists termination held the call open long past the deadline that had just expired. That receive is now bounded, and a call that gives up leaves cmd.Wait running, so the output buffers are synchronised: the I/O pump keeps writing into buffers the caller already holds, which a plain bytes.Buffer cannot survive. The timeout error also carried nothing actionable. It was a bare string with the underlying error and the command's stderr both dropped, so a user whose provider command was slow got no clue which phase ran out or what the command had said. It now names the phase, wraps the cause, and includes the redacted output the failure path already had. Both bounds are asserted on extracted helpers rather than end to end, because end to end they are untestable: a terminated command stops writing and its wait returns at once, so an unbounded drain and an unsynchronised buffer both pass a whole-call test. The first version of these tests did exactly that and proved nothing. Removing either bound now fails, as does arming the deadline after the start, which reports the wrong phase.
Zero automated PR reviewVerdict: No blockers found Blockers
Validation
ScopeHead: This deterministic review checks validation status and basic diff hygiene. A human reviewer still owns product judgment and design quality. |
|
No actionable comments were generated in the recent review. 🎉 ℹ️ Recent review info⚙️ Run configurationConfiguration used: Path: .coderabbit.yaml Review profile: CHILL Plan: Pro Run ID: 📒 Files selected for processing (2)
WalkthroughProvider-command execution now enforces a deadline across startup, execution, termination, and output draining. Timeout errors wrap the sentinel and include diagnostics. Mutex-protected buffers prevent concurrent output access, with tests covering timing, cleanup, diagnostics, and race safety. ChangesProvider-command timeout handling
Estimated code review effort: 4 (Complex) | ~45 minutes Possibly related PRs
Suggested reviewers: Sequence Diagram(s)sequenceDiagram
participant LoadProviderCommand
participant runProviderCommand
participant ProviderProcess
LoadProviderCommand->>runProviderCommand: execute provider command with deadline
runProviderCommand->>ProviderProcess: start process
ProviderProcess-->>runProviderCommand: stdout and stderr
runProviderCommand->>ProviderProcess: terminate when deadline expires
ProviderProcess-->>runProviderCommand: bounded exit and drain
runProviderCommand-->>LoadProviderCommand: result or diagnostic timeout error
🚥 Pre-merge checks | ✅ 5✅ Passed checks (5 passed)
✨ Finishing Touches📝 Generate docstrings
🧪 Generate unit tests (beta)
Comment |
![coderabbitai[bot]](https://avatars.githubusercontent.com/in/347564?s=60&v=4){kind=small}
gnanam1990
left a comment
gnanam1990
left a comment
There was a problem hiding this comment.
Verdict
Approve.
Reviewed at 945eb06d2b92, base 5d1869e, re-confirmed against the live head before posting.
This is a good change and an unusually honest one. The section on discarding your first set of tests is the most valuable part of the description, and I want to record that I checked those claims rather than taking them.
All three mutation claims hold, verified independently.
Making the drain unbounded again — replacing the select in awaitWithGrace with a bare <-done — hangs TestAwaitWithGraceGivesUp to the test timeout: panic: test timed out after 15s / TestAwaitWithGraceGivesUp (15s).
Removing both locks from syncBuffer trips -race on TestSyncBufferAllowsConcurrentWriteAndSnapshot, twice.
Arming the deadline after the start instead of before fails TestRunProviderCommandCountsProcessStartAgainstTheDeadline with exactly the message you predicted: error = "provider command timeout: the command did not finish within 1ns", want the start phase to be the one that exceeded the deadline. That assertion is well-built — it discriminates on which phase reported, not merely that something timed out, which is what makes it bind.
The bound is real, measured on a platform you did not test. On darwin/arm64, driving runProviderCommand with sleep 30 & echo hi — a background descendant holding the inherited pipes, which is the shape that made the wait-only bound overshoot:
budget=200ms elapsed=202ms overshoot=2ms
budget=1s elapsed=1.002s overshoot=2ms
One honest correction to the scope of my verification. I could not reproduce the pathological overshoot on macOS. The same scenario on base gives overshoot=10ms at both budgets, not 19.7s. That is consistent with your diagnosis — CREATE_SUSPENDED, job-object assignment and the thread snapshot are the expensive phases and none of them exists on POSIX — but it means the headline measurement rests on your Windows numbers and the passing windows-latest job, not on anything I ran. A reader should not take my approval as independent confirmation of the 19.7s/106s figures.
What I can confirm on darwin is the diagnostics half, and it is a clear improvement: base returns a bare provider command timeout, this returns provider command timeout: the command did not finish within 200ms and carries the redacted output through.
Two non-blocking observations.
awaitWithGrace returns a bool that the caller discards, so the error text is the same whether the drain completed or gave up. Those are different situations — the second means a tree survived Terminate — and the return value is already there. Saying so in the message would cost a line and would tell an operator something real.
On POSIX the bounded drain is followed by defer proc.Close(), which calls p.anchor.Wait() unbounded (internal/config/process_posix.go). In practice Terminate SIGKILLs the whole group including the anchor, so it returns immediately, and I could not make it hang. But it is an unbounded wait sitting directly after a bound you just added deliberately, and it would be worth either bounding it too or noting why it cannot block.
On the class, since this file is load-bearing. internal/config/command.go was already the one place in the tree that handles exec.ErrWaitDelay explicitly rather than collapsing it, and this makes it stronger still. It remains one site: exec.Cmd construction without WaitDelay, a process group and a tree-killing Cancel is repeated across roughly forty files, and the shared construction point at internal/sandbox/runner.go:103 is unhardened, so every sandboxed command inherits the older shape. Not this PR's job — #811 is scoped to the provider command and the fix matches the issue — but this file is now the natural reference implementation to extract from, and I would rather say that than have the pattern copied by hand a fifth time.
Process note. #811 carries no issue-approved label, unlike #534 and #447 on your other pull requests. You are a collaborator so this is not a gate, but the inconsistency is worth tidying so the label stays meaningful as a signal.
Verification. On macOS (darwin/arm64): gofmt -l clean, go vet ./... clean, git diff --check clean, ./internal/config/... passing, -race -count=10 clean on the new tests. All nine checks pass on the live head, including windows-latest.
Limitations. macOS only. The Windows phases this change exists for — CREATE_SUSPENDED, job-object creation and assignment, resumeMainThread's thread snapshot — were read, not executed.
Merge is kevin's call per the program gate.
anandh8x
left a comment
anandh8x
left a comment
There was a problem hiding this comment.
Review at 945eb06
PR #813 — make the provider-command timeout an upper bound (#811). 2 files, +115/-16, single commit.
Verdict: approve. The fix is correct, the tests bind (verified by mutation), and the diagnostics are a real improvement.
The problem
providerCommandTimeout bounded only the wait, so the call could take arbitrarily longer than the 5s its error text promised. Two phases sat outside the deadline: process creation (before the clock started) and the post-termination drain (unbounded bare receive). On Windows, the start phase is CREATE_SUSPENDED + job-object creation + a system-wide thread snapshot — not fast on a cold/AV-heavy machine. The PR body measured 19.7s and 106s against a 5s budget.
What's good
- Deadline armed before the start. The start races the deadline in a goroutine; if the deadline fires first, cleanup is handed off (the goroutine reaps the process when it eventually lands).
TestRunProviderCommandCountsProcessStartAgainstTheDeadlineuses a 1ns budget so the only phase that can exceed it is the start — the error says "starting the command" not "did not finish", which discriminates the two orderings. - Bounded drain.
awaitWithGrace(done, providerCommandDrainGrace)replaces the bare<-done.TestAwaitWithGraceGivesUpuses a channel that never fires — making the drain unbounded again hangs this test to the test timeout. syncBufferfor the timeout path. The I/O pump keeps writing after the caller has returned, so a plainbytes.Bufferwould race.snapshot()copies under the mutex.TestSyncBufferAllowsConcurrentWriteAndSnapshotoverlaps 2000 writes and 2000 snapshots; removing the lock trips-race. Verified clean under-racein my run.- Diagnostics. The timeout error now names the phase and includes redacted stderr.
TestLoadProviderCommandTimeoutReportsDiagnosticschecks the phase name anderrors.Isagainst the sentinel. The old bare string is gone. cmd.WaitDelay = time.Secondbounds how longcmd.Waitspends draining I/O pipes after the process exits, in case an orphaned descendant holds the write ends open. This is theexec.ErrWaitDelaypath, which the code already handled but now can't hang either.- Tests are honest about what they pin. The PR body has a section titled "the first version of them was worthless" explaining why whole-call tests don't bind the drain or the race, and which extracted-helper tests do. gnanam independently verified all three mutation claims. The end-to-end duration test is kept as a regression guard with a comment saying it does NOT pin the drain bound.
Verification
go vet ./internal/config/...— cleango build ./internal/config/...— clean- Full
internal/configpackage — pass (14.3s, the 5s timeouts are real) -raceon the new tests — clean- All 12 PR-related tests pass
gnanam's non-blocking observations (noting, not blocking)
awaitWithGracereturns a bool the caller discards. The error text is the same whether the drain completed or gave up. The second means a tree survivedTerminate— worth saying in the message. One line.defer proc.Close()callsp.anchor.Wait()unbounded on POSIX. In practiceTerminateSIGKILLs the group including the anchor so it returns immediately, but it's an unbounded wait sitting directly after a deliberately bounded one. Worth bounding or noting why it can't block.
Both are real but minor. Neither changes the contract this PR ships.
Verdict
Approve. The timeout is now an upper bound, the tests pin the two phases that were outside it, the syncBuffer makes the early-return path race-safe, and the diagnostics are a clear improvement. gnanam's two non-blocking observations are worth follow-ups but don't change the verdict.
|
@kevincodex1 ready to merge when you are. Three approvals on the current head ( Fixes #811. One behaviour change worth your eye before it lands: the timeout error text now names the phase that ran out and includes the command's redacted stderr. Nothing in the tree matches the old exact string, No caveats beyond that. Test-and-one-file change, no unexercised paths. |
|
@kevincodex1 nudging this one specifically, because it is the only PR of mine that is actually mergeable right now. Still For contrast, so you can set the rest aside for the moment: #808 needs a CodeRabbit re-run before the ruleset will pass it, #812 is stacked behind #808, and #814 and #816 are waiting on @gnanam1990 to re-approve after my own follow up pushes dismissed them. This is the one with nothing left in front of it. The only thing on it I would still want you to see before merging is the user-visible change I flagged earlier: the timeout error text now names the phase that ran out and carries the command's redacted stderr. Nothing in the tree matches the old exact string. |
anandh8x
left a comment
anandh8x
left a comment
There was a problem hiding this comment.
Reviewed the latest head 945eb06. The deadline now covers process startup and the post-termination drain, the early-return output path is synchronized, and the tests bind those three failure modes. The config package passes under the race detector locally. Good to merge.
4 participants
Fixes #811.
The problem
providerCommandTimeoutbounded only the wait, so the call could take arbitrarily longer than the 5s its error text promises. I measured 19.7s and then 106s against that 5s while reproducing the Windows flakes fixed in #810. Two phases sat outside the deadline.Process creation ran before the clock started.
startCommandProcesswas called, and only then was the timer armed. On Windows that phase isCREATE_SUSPENDED, job-object creation and assignment, and a system-wide thread snapshot inresumeMainThread, none of it fast on a cold or AV-heavy machine.The drain after termination was unbounded. The timer path called
Terminate()and then did a bare receive on the wait. Terminate normally makes that immediate, which is exactly why it went unnoticed, but a tree that resists termination held the call open long past the deadline that had just expired.This is on the startup path, so a user with a slow provider command sees Zero appear to hang for far longer than the message admits, and gets no diagnostics: the timeout branch returned a bare string with the underlying error and the command's stderr both dropped.
What this does
The deadline is armed first and the start races it, so process creation counts against the budget. The drain is bounded by a grace period. A call that gives up leaves
cmd.Waitrunning, so the output buffers are now synchronised: the I/O pump keeps writing into buffers the caller already holds, which a plainbytes.Buffercannot survive.The timeout error names the phase that ran out, wraps the cause so
errors.Isstill classifies it, and includes the redacted output the non-timeout path already reported.On the tests, because the first version of them was worthless
Both bounds are asserted on extracted helpers rather than end to end. That is not a stylistic choice. End to end they are untestable: a terminated command stops writing and its wait returns at once, so an unbounded drain and an unsynchronised buffer both pass a whole-call test.
I wrote the whole-call versions first and checked them against mutations. The duration test passed with the drain unbounded again. The race test passed with the buffer's lock removed, even under
-race, because the command was never writing at the moment the snapshot was taken. Neither proved anything.What replaced them does bind:
TestAwaitWithGraceGivesUpdrives a channel that never fires. Making the drain unbounded hangs it to the test timeout.TestSyncBufferAllowsConcurrentWriteAndSnapshotoverlaps writes and snapshots. Removing the lock trips-race.TestRunProviderCommandCountsProcessStartAgainstTheDeadlineuses a budget that is already spent, so the only phase that can exceed it is the start. Arming the deadline after the start instead makes it fail withthe command did not finish, naming the wrong phase.The end-to-end duration test is kept as a guard against gross regressions, with a comment saying plainly that it does not pin the drain bound and which test does.
Checks
gofmt,go vet, and builds for linux, darwin and windows are clean. The fullinternal/configpackage passes under-race. Existing coverage is untouched: the 5s message mapping, exit-status wrapping and secret redaction all still assert what they did.One behaviour change worth naming for review: the timeout error text now includes the phase and the command's stderr, so anything matching on the exact old string would need updating. Nothing in the tree does;
LoadProviderCommandis matched on witherrors.Isand on thetimed outsubstring, both of which still hold.Summary by CodeRabbit