Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
44 changes: 41 additions & 3 deletions internal/executor/podman.go
Original file line number Diff line number Diff line change
Expand Up @@ -345,6 +345,44 @@ func buildRemoveArgs(name string) []string {
return []string{"pod", "rm", name}
}

// podmanStopTimeout bounds a single podman invocation issued from the
// stop/delete path, independent of the caller's own context. The DELETE
// HTTP handler passes r.Context() straight through, which carries no
// deadline of its own -- it only ends if the client disconnects. Without
// a bound here, a wedged podman invocation blocks the calling goroutine
// (and the HTTP request) for as long as podman stays wedged (issue #88:
// a real ~7-minute stall, self-resolved, not guaranteed to always be).
const podmanStopTimeout = 20 * time.Second

// podmanWaitDelay bounds how long Cmd.Wait may keep blocking after the
// podman process is known to have exited (or podmanStopTimeout above
// fires), waiting for its stdout/stderr pipes to see EOF. This is the
// other half of issue #88's gap: `exec.CommandContext`'s own cancellation
// only signals the *direct* child. If that child forked a subprocess
// (e.g. podman's own conmon/netavark helpers) that inherited the pipe and
// is itself stuck on a storage/CDI lock, the direct child can already be
// a reaped-pending zombie -- exactly what `ps` showed on the DGX,
// `[podman] <defunct>` parented by spark's own PID -- while
// CombinedOutput() still blocks forever reading for EOF that never comes.
// Cmd.WaitDelay (Go 1.20+) is the stdlib's documented fix for precisely
// this class of hang: it force-closes the pipes after the delay, so Wait
// returns even if a grandchild is still holding them open.
const podmanWaitDelay = 5 * time.Second

// runPodmanBounded runs podman with its own timeout and WaitDelay,
// layered on top of ctx rather than replacing it -- if ctx already carries
// an earlier deadline, that still wins. See podmanStopTimeout and
// podmanWaitDelay for why both are needed: a timeout alone only bounds
// how long Spark waits *before signaling* the direct child; WaitDelay is
// what guarantees Wait() itself returns afterward (issue #88).
func runPodmanBounded(ctx context.Context, timeout, waitDelay time.Duration, args ...string) ([]byte, error) {
ctx, cancel := context.WithTimeout(ctx, timeout)
defer cancel()
cmd := exec.CommandContext(ctx, "podman", args...)
cmd.WaitDelay = waitDelay
return cmd.CombinedOutput()
}

// StopPod stops a pod with the given grace period in seconds and removes it.
// StartContainer starts an exited container in place (same config,
// same filesystem) via `podman start`. Used for per-container restarts:
Expand All @@ -362,14 +400,14 @@ func (p *PodmanExecutor) StartContainer(ctx context.Context, containerName strin
func (p *PodmanExecutor) StopPod(ctx context.Context, name string, gracePeriod int) error {
args := buildStopArgs(name, gracePeriod)
slog.Info("stopping pod", "cmd", "podman", "args", args)
out, err := exec.CommandContext(ctx, "podman", args...).CombinedOutput()
out, err := runPodmanBounded(ctx, podmanStopTimeout, podmanWaitDelay, args...)
if err != nil {
return fmt.Errorf("podman pod stop: %w: %s", err, out)
}

rmArgs := buildRemoveArgs(name)
slog.Info("removing pod", "cmd", "podman", "args", rmArgs)
out, err = exec.CommandContext(ctx, "podman", rmArgs...).CombinedOutput()
out, err = runPodmanBounded(ctx, podmanStopTimeout, podmanWaitDelay, rmArgs...)
if err != nil {
if strings.Contains(string(out), "no such pod") {
return nil
Expand Down Expand Up @@ -490,7 +528,7 @@ func derivePodStatus(containers []ContainerStatus) Status {
func (p *PodmanExecutor) RemovePod(ctx context.Context, name string) error {
args := []string{"pod", "rm", "-f", name}
slog.Info("removing pod", "cmd", "podman", "args", args)
out, err := exec.CommandContext(ctx, "podman", args...).CombinedOutput()
out, err := runPodmanBounded(ctx, podmanStopTimeout, podmanWaitDelay, args...)
if err != nil {
return fmt.Errorf("podman pod rm: %w: %s", err, out)
}
Expand Down
151 changes: 151 additions & 0 deletions internal/executor/podman_wait_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,151 @@
package executor

import (
"context"
"os"
"path/filepath"
"runtime"
"testing"
"time"
)

// writeFakePodman drops an executable script named "podman" into dir and
// points PATH at dir for the duration of the test, so exec.Command("podman",
// ...) in production code resolves to it instead of touching real podman or
// the DGX. Unix-only (matches the project's linux/arm64 DGX target and
// darwin dev hosts); skips on other platforms.
func writeFakePodman(t *testing.T, script string) {
t.Helper()
if runtime.GOOS == "windows" {
t.Skip("fake podman script requires a POSIX shell")
}
dir := t.TempDir()
path := filepath.Join(dir, "podman")
if err := os.WriteFile(path, []byte(script), 0o755); err != nil {
t.Fatalf("writing fake podman script: %v", err)
}
// Prepend rather than replace: the fake script's own shebang still
// needs to resolve real coreutils (sh, sleep, ...) from the rest of PATH.
t.Setenv("PATH", dir+string(os.PathListSeparator)+os.Getenv("PATH"))
}

// TestRunPodmanBounded_OrphanedGrandchildHangsWithoutWaitDelay reproduces
// issue #88's exact mechanism without touching real podman or the DGX: a
// child process that backgrounds a long-lived grandchild inheriting its
// stdout/stderr pipe, then exits immediately itself. Go's os/exec
// Wait()/CombinedOutput() cannot tell that apart from "still running" --
// it reads stdout/stderr until EOF, which doesn't arrive until every
// process holding the pipe's write end closes it, including the orphaned
// grandchild. That leaves the calling goroutine blocked long after the
// direct child has already exited and become a zombie under the caller's
// PID -- exactly what issue #88 observed on the DGX (`[podman] <defunct>`
// parented by spark's own PID, while CombinedOutput() never returned).
//
// This is the RED half of the red/green pair: with waitDelay=0 (the
// behavior of every podman.go call site before this fix), the call blocks
// for the grandchild's full sleep, not the direct child's near-instant
// exit -- proving a context timeout alone (podmanStopTimeout) is not
// sufficient; WaitDelay is the other required half of the fix.
func TestRunPodmanBounded_OrphanedGrandchildHangsWithoutWaitDelay(t *testing.T) {
writeFakePodman(t, "#!/bin/sh\n(sleep 5 &)\nexit 0\n")

// A generous timeout here is deliberate: this test isolates the
// pipe/EOF half of the gap from the context-cancellation half. Under a
// loaded, parallel `-race` run, a tight timeout can fire before the
// shell even gets scheduled to fork and detach its background sleep,
// killing it pre-fork and returning fast for an unrelated reason (a
// scheduling race, not evidence the gap doesn't exist). 20s keeps the
// context out of the way so only the orphaned-pipe mechanism governs
// the result; the call still returns in ~5s in practice, bounded by
// the grandchild's own sleep, not by this timeout.
start := time.Now()
_, err := runPodmanBounded(context.Background(), 20*time.Second, 0, "pod", "stop", "--time", "1", "irrelevant")
elapsed := time.Since(start)

// The direct child (the shell) exits in milliseconds. If the call
// returned anywhere near that, WaitDelay isn't needed and this test's
// premise is wrong. It should instead track the grandchild's ~5s sleep.
if elapsed < 4*time.Second {
t.Fatalf("expected the call to block for the orphaned grandchild's sleep (~5s) with waitDelay=0, returned after %s (err=%v) -- the gap this test exists to demonstrate did not reproduce", elapsed, err)
}
if elapsed > 15*time.Second {
t.Fatalf("expected the call to unblock once the grandchild's sleep finishes (~5s), took %s -- did the fake script change?", elapsed)
}
}

// TestRunPodmanBounded_WaitDelayBoundsTheHang is the GREEN half: the same
// orphaned-grandchild scenario, but with WaitDelay set (as StopPod/RemovePod
// now do). Cmd.Wait force-closes the pipes once waitDelay elapses after the
// direct child is observed to have exited, unblocking the call long before
// the grandchild's sleep finishes.
func TestRunPodmanBounded_WaitDelayBoundsTheHang(t *testing.T) {
writeFakePodman(t, "#!/bin/sh\n(sleep 5 &)\nexit 0\n")

start := time.Now()
_, err := runPodmanBounded(context.Background(), time.Second, 300*time.Millisecond, "pod", "stop", "--time", "1", "irrelevant")
elapsed := time.Since(start)

if elapsed >= 4*time.Second {
t.Fatalf("expected WaitDelay to bound the wait to well under the grandchild's 5s sleep, took %s (err=%v)", elapsed, err)
}
if err == nil {
t.Fatalf("expected an error once WaitDelay force-closes the pipes on the still-open grandchild, got nil")
}
}

// TestStopPod_BoundedDespiteOrphanedGrandchild exercises the real
// production method (not just the helper) end-to-end via a fake podman on
// PATH, proving the actual stop/delete code path -- not just the isolated
// mechanism above -- is bounded. Uses the production podmanStopTimeout /
// podmanWaitDelay constants, so this also documents their real-world
// worst-case wall-clock bound.
func TestStopPod_BoundedDespiteOrphanedGrandchild(t *testing.T) {
writeFakePodman(t, `#!/bin/sh
case "$*" in
*"pod stop"*) (sleep 30 &) ; exit 0 ;;
*) exit 0 ;;
esac
`)

p := NewPodmanExecutor("test-net")
start := time.Now()
err := p.StopPod(context.Background(), "irrelevant-pod", 1)
elapsed := time.Since(start)

// Worst case for a single call: podmanStopTimeout to notice the direct
// child has nothing left to signal, then podmanWaitDelay to force the
// pipes closed. Generous slack for scheduling jitter.
maxBound := podmanStopTimeout + podmanWaitDelay + 3*time.Second
if elapsed > maxBound {
t.Fatalf("StopPod took %s against a wedged (orphaned-grandchild) podman invocation, expected it bounded near %s (issue #88)", elapsed, maxBound)
}
if err == nil {
t.Fatalf("expected StopPod to surface an error once the wedged podman invocation is force-timed-out, got nil")
}
}

// TestRemovePod_BoundedDespiteOrphanedGrandchild is RemovePod's counterpart
// to the StopPod test above -- exercised separately since it's a distinct
// call site (used directly by the reconciler, housekeeper, and shutdown
// drain path, not only via StopPod).
func TestRemovePod_BoundedDespiteOrphanedGrandchild(t *testing.T) {
writeFakePodman(t, `#!/bin/sh
case "$*" in
*"pod rm"*) (sleep 30 &) ; exit 0 ;;
*) exit 0 ;;
esac
`)

p := NewPodmanExecutor("test-net")
start := time.Now()
err := p.RemovePod(context.Background(), "irrelevant-pod")
elapsed := time.Since(start)

maxBound := podmanStopTimeout + podmanWaitDelay + 3*time.Second
if elapsed > maxBound {
t.Fatalf("RemovePod took %s against a wedged (orphaned-grandchild) podman invocation, expected it bounded near %s (issue #88)", elapsed, maxBound)
}
if err == nil {
t.Fatalf("expected RemovePod to surface an error once the wedged podman invocation is force-timed-out, got nil")
}
}
Loading