Files
Cheviiot f6b9a0811a Prevent and recover from wedged Wine-hosted processes
Prompted by a real incident: an MSBuild node-reuse worker (its own
/nodeReuse:true default) survived a build getting interrupted, came
back deadlocked, and got reused by the next `msbuild` invocation -
which then failed with a confusing, unrelated-looking
`System.TypeLoadException` on Microsoft.VisualStudio.Telemetry on
every call for hours, until the stale process was killed by hand.
That's exactly the "unrelated blocker" noted in this repo's own
earlier session notes (CLAUDE.md) while debugging a real project's
build - it wasn't a missing dependency, it was a corrupted reused
process.

Two changes:

- vintner now forces /nodeReuse:false on every msbuild invocation
  (unless the caller already passed their own /nodeReuse or /nr
  switch), so a wedged worker can never poison a later, unrelated
  build in the first place. Costs each invocation the couple-hundred-
  ms/node startup time node reuse exists to save.

- VINTNER_TIMEOUT (a duration string, e.g. "30m") bounds how long any
  single tool invocation is allowed to run, for the case something
  wedges that isn't MSBuild-specific. Every exec.Command site in
  internal/wrapper now goes through a shared newToolCommand
  constructor that, when the timeout is set, kills the *whole*
  process group (not just the immediate `wine` process - a wedged
  child surviving under it is exactly the scenario this needs to
  reach) via a context deadline, and reports a clear "timed out after
  Xm" message (exit 124, matching the timeout(1) convention) instead
  of a bare "signal: killed". Unset by default - every real build
  observed stays unbounded, matching Windows' own behavior.

Verified end-to-end, not just at the unit level: a real `sleep 30`
through the `cmd` native wrapper with VINTNER_TIMEOUT=1s was killed
within the deadline and reported the timeout clearly (exit 124); a
real `cl` invocation with the same 1s timeout finished normally
(0.26s) without being mistaken for a hang.
2026-07-25 15:58:22 +10:00

83 lines
2.3 KiB
Go

package wrapper
import (
"syscall"
"testing"
"time"
)
func TestCommandTimeout(t *testing.T) {
for _, tc := range []struct {
name string
env string
want time.Duration
}{
{"unset", "", 0},
{"valid", "30m", 30 * time.Minute},
{"invalid unit-less number", "30", 0},
{"zero", "0s", 0},
{"negative", "-5m", 0},
} {
t.Run(tc.name, func(t *testing.T) {
t.Setenv("VINTNER_TIMEOUT", tc.env)
if got := commandTimeout(); got != tc.want {
t.Errorf("commandTimeout() with VINTNER_TIMEOUT=%q = %v, want %v", tc.env, got, tc.want)
}
})
}
}
// TestNewToolCommandKillsOnTimeout is the real end-to-end check: start a
// process that would otherwise run far longer than the timeout (mimicking
// a wedged Wine-hosted tool), and confirm newToolCommand's deadline
// actually kills it - not just that timedOut() would report true in
// principle, but that Wait() actually returns, promptly, with the process
// gone.
func TestNewToolCommandKillsOnTimeout(t *testing.T) {
t.Setenv("VINTNER_TIMEOUT", "300ms")
tc, cleanup := newToolCommand("sleep", "30")
defer cleanup()
if err := tc.Start(); err != nil {
t.Fatalf("starting sleep: %v", err)
}
pid := tc.Process.Pid
done := make(chan error, 1)
go func() { done <- tc.Wait() }()
select {
case err := <-done:
if err == nil {
t.Fatal("expected sleep 30 to be killed by the timeout, but it exited successfully")
}
if !tc.timedOut() {
t.Errorf("Wait() returned an error (%v) but timedOut() = false", err)
}
case <-time.After(5 * time.Second):
t.Fatal("newToolCommand's timeout did not kill the process within 5s of a 300ms deadline")
}
// Belt-and-suspenders: the process should genuinely be gone, not just
// reported as such. Signal 0 sends nothing but still fails with ESRCH
// once the pid is gone - the standard Unix way to probe existence.
if err := syscall.Kill(pid, 0); err == nil {
t.Errorf("pid %d still exists after the timeout killed it", pid)
}
}
func TestNewToolCommandNoTimeoutByDefault(t *testing.T) {
t.Setenv("VINTNER_TIMEOUT", "")
tc, cleanup := newToolCommand("true")
defer cleanup()
if err := tc.Run(); err != nil {
t.Fatalf("running `true` with no VINTNER_TIMEOUT set: %v", err)
}
if tc.timedOut() {
t.Error("timedOut() = true for a command that finished well within any reasonable time, with no timeout configured")
}
}