diff --git a/cli/commands/global.go b/cli/commands/global.go index 532acd712..aecb37c14 100644 --- a/cli/commands/global.go +++ b/cli/commands/global.go @@ -8,6 +8,7 @@ import ( "log/slog" "os" "os/signal" + "sync" "golang.org/x/sys/unix" "miren.dev/runtime/clientconfig" @@ -40,6 +41,13 @@ type Context struct { cancels []func() + // states are the RPC states this command opened. Close shuts them down so + // the server hears the connection end; a process that just exits leaves the + // server holding it until QUIC's idle timeout, and a server shutting down + // waits on it. + statesMu sync.Mutex + states []*rpc.State + ClientConfig *clientconfig.Config ClusterConfig *clientconfig.ClusterConfig ClusterName string @@ -239,6 +247,15 @@ func setup(ctx context.Context, flags *GlobalFlags, opts any, commandName string } func (c *Context) Close() error { + c.statesMu.Lock() + states := c.states + c.states = nil + c.statesMu.Unlock() + + for _, cs := range states { + _ = cs.Close() + } + for _, cancel := range c.cancels { cancel() } @@ -246,6 +263,12 @@ func (c *Context) Close() error { return nil } +func (c *Context) trackState(cs *rpc.State) { + c.statesMu.Lock() + c.states = append(c.states, cs) + c.statesMu.Unlock() +} + func (c *Context) SetExitCode(code int) { c.exitCode = code } @@ -341,6 +364,7 @@ func (c *Context) rpcClient(rpcCtx context.Context, name string) (*rpc.NetworkCl if err != nil { return nil, c.unusableClusterError(c.ClusterName, err) } + c.trackState(cs) client, err := cs.Client(name) if err != nil { @@ -361,6 +385,7 @@ func (c *Context) rpcClient(rpcCtx context.Context, name string) (*rpc.NetworkCl cs, err = c.ClientConfig.State(rpcCtx, opts...) if err == nil { + c.trackState(cs) client, err := cs.Client(name) if err != nil { return nil, c.wrapRPCError(err) @@ -388,6 +413,7 @@ func (c *Context) rpcClient(rpcCtx context.Context, name string) (*rpc.NetworkCl if err != nil { return nil, err } + c.trackState(cs) client, err := cs.Connect(c.Config.ServerAddress, name) if err != nil { diff --git a/components/containerd/containerd.go b/components/containerd/containerd.go index 065510894..e301a2a90 100644 --- a/components/containerd/containerd.go +++ b/components/containerd/containerd.go @@ -2,6 +2,7 @@ package containerd import ( "context" + "errors" "fmt" "log/slog" "net" @@ -51,6 +52,7 @@ type ContainerdComponent struct { client *containerd.Client running bool waitDone chan struct{} + owner *os.File } // NewContainerdComponent creates a new containerd component @@ -73,8 +75,37 @@ func (c *ContainerdComponent) populateDefaults(config *Config) { } } +// lockBaseDir takes an exclusive flock that this process holds for as long as +// it owns the daemon under baseDir. The kernel drops it when the process dies, +// however it dies, so holding it means no live server owns whatever containerd +// is still running there. +func lockBaseDir(baseDir string) (*os.File, error) { + path := filepath.Join(baseDir, "owner.lock") + f, err := os.OpenFile(path, os.O_RDWR|os.O_CREATE, 0644) + if err != nil { + return nil, fmt.Errorf("opening %s: %w", path, err) + } + if err := syscall.Flock(int(f.Fd()), syscall.LOCK_EX|syscall.LOCK_NB); err != nil { + f.Close() + if errors.Is(err, syscall.EWOULDBLOCK) { + return nil, fmt.Errorf("another server process is already managing containerd in %s", baseDir) + } + return nil, fmt.Errorf("locking %s: %w", path, err) + } + return f, nil +} + +func (c *ContainerdComponent) releaseOwner() { + c.mu.Lock() + defer c.mu.Unlock() + if c.owner != nil { + c.owner.Close() + c.owner = nil + } +} + // Start starts the containerd daemon -func (c *ContainerdComponent) Start(ctx context.Context, config *Config) error { +func (c *ContainerdComponent) Start(ctx context.Context, config *Config) (err error) { // Populate defaults c.populateDefaults(config) @@ -97,6 +128,19 @@ func (c *ContainerdComponent) Start(ctx context.Context, config *Config) error { return fmt.Errorf("failed to create base directory: %w", err) } + owner, err := lockBaseDir(config.BaseDir) + if err != nil { + return err + } + c.mu.Lock() + c.owner = owner + c.mu.Unlock() + defer func() { + if err != nil { + c.releaseOwner() + } + }() + // Setup directories stateDir := filepath.Join(config.BaseDir, "state") rootDir := filepath.Join(config.BaseDir, "root") @@ -118,6 +162,22 @@ func (c *ContainerdComponent) Start(ctx context.Context, config *Config) error { return fmt.Errorf("failed to generate config: %w", err) } + survivors, err := findSurvivors(config.SocketPath, config.ConfigPath) + if err != nil { + return fmt.Errorf("looking for containerd left by a previous server: %w", err) + } + if len(survivors) > 0 { + pids := make([]int, len(survivors)) + for i, proc := range survivors { + pids[i] = proc.Pid + } + c.log.Warn("stopping containerd left running by a previous server process", + "pids", pids, "socket", config.SocketPath) + if err := stopSurvivors(survivors, 30*time.Second); err != nil { + return err + } + } + // Build command cmd := exec.Command(config.BinaryPath, "--address", config.SocketPath, @@ -154,17 +214,18 @@ func (c *ContainerdComponent) Start(ctx context.Context, config *Config) error { } // Update state with lock + waitDone := make(chan struct{}) c.mu.Lock() c.cmd = cmd c.running = true - c.waitDone = make(chan struct{}) + c.waitDone = waitDone c.mu.Unlock() c.log.Info("containerd started", "pid", cmd.Process.Pid) // Monitor the process in background go func() { - defer close(c.waitDone) + defer close(waitDone) if err := cmd.Wait(); err != nil { c.log.Error("containerd exited with error", "error", err) @@ -183,12 +244,16 @@ func (c *ContainerdComponent) Start(ctx context.Context, config *Config) error { }() // Wait for socket to be available (no lock held) - if err := c.waitForSocket(ctx, config.SocketPath); err != nil { + err = c.waitForSocket(ctx, config.SocketPath, waitDone) + if err == nil { + err = checkSocketOwner(config.SocketPath, cmd.Process.Pid) + } + if err != nil { // Clean up on failure cmd.Process.Kill() // Wait for the monitoring goroutine to finish - <-c.waitDone + <-waitDone return fmt.Errorf("containerd failed to start: %w", err) } @@ -221,6 +286,7 @@ func (c *ContainerdComponent) Start(ctx context.Context, config *Config) error { // Stop stops the containerd daemon func (c *ContainerdComponent) Stop(ctx context.Context) error { + defer c.releaseOwner() c.mu.Lock() if !c.running || c.cmd == nil { @@ -325,10 +391,29 @@ func (c *ContainerdComponent) Client() (*containerd.Client, error) { return c.client, nil } +// checkSocketOwner confirms the daemon answering on socketPath is the one we +// just started. Anything else answering means a daemon we don't own is still +// serving there, and ours will never come up. +func checkSocketOwner(socketPath string, pid int) error { + owner, err := socketOwner(socketPath) + if errors.Is(err, errors.ErrUnsupported) { + return nil + } + if err != nil { + return fmt.Errorf("checking containerd socket owner: %w", err) + } + if owner != pid { + return fmt.Errorf("containerd socket %s is served by pid %d, not the daemon we started (pid %d)", socketPath, owner, pid) + } + return nil +} + // waitForSocket waits for the containerd socket to be accepting connections. // Checking file existence alone is insufficient — containerd creates the // socket file before it starts listening, causing a race on fast machines. -func (c *ContainerdComponent) waitForSocket(ctx context.Context, socketPath string) error { +// exited closes if the daemon dies first, so a crash fails fast rather than +// waiting out the timeout. +func (c *ContainerdComponent) waitForSocket(ctx context.Context, socketPath string, exited <-chan struct{}) error { ticker := time.NewTicker(100 * time.Millisecond) defer ticker.Stop() @@ -339,6 +424,8 @@ func (c *ContainerdComponent) waitForSocket(ctx context.Context, socketPath stri select { case <-ctx.Done(): return ctx.Err() + case <-exited: + return fmt.Errorf("containerd exited before its socket was ready") case <-timeout: return fmt.Errorf("timeout waiting for containerd socket at %s", socketPath) case <-ticker.C: diff --git a/components/containerd/survivors_linux.go b/components/containerd/survivors_linux.go new file mode 100644 index 000000000..0db4a5691 --- /dev/null +++ b/components/containerd/survivors_linux.go @@ -0,0 +1,163 @@ +package containerd + +import ( + "errors" + "fmt" + "net" + "os" + "path/filepath" + "slices" + "strconv" + "strings" + "syscall" + "time" + + "golang.org/x/sys/unix" +) + +// findSurvivors returns the containerd processes running from configPath. A +// server process that dies without running its stop hooks (a panic, SIGKILL) +// leaves its daemon running, reparented to init. That daemon keeps the socket +// and the metadata store's lock, so every daemon started after it blocks +// forever opening the store while the old one keeps answering on the socket. +// Both kinds turn up here. +// +// Candidates are matched on the config file's identity, not its path: a +// containerd in a container can use the same path for an unrelated file. +// Callers must hold the base directory's owner lock, or a live server's daemon +// would count as a survivor too. +func findSurvivors(socketPath, configPath string) ([]*os.Process, error) { + ours, err := os.Stat(configPath) + if err != nil { + return nil, err + } + entries, err := os.ReadDir("/proc") + if err != nil { + return nil, err + } + var procs []*os.Process + for _, entry := range entries { + pid, err := strconv.Atoi(entry.Name()) + if err != nil || !isContainerd(pid, socketPath, ours) { + continue + } + // The handle is a pidfd, so signals sent through it cannot reach + // an unrelated process that later reuses the pid. Check again once + // it is open in case that already happened. + proc, err := os.FindProcess(pid) + if err != nil { + continue + } + if !isContainerd(pid, socketPath, ours) { + proc.Release() + continue + } + procs = append(procs, proc) + } + return procs, nil +} + +func isContainerd(pid int, socketPath string, config os.FileInfo) bool { + dir := filepath.Join("/proc", strconv.Itoa(pid)) + comm, err := os.ReadFile(filepath.Join(dir, "comm")) + if err != nil || strings.TrimSpace(string(comm)) != "containerd" { + return false + } + raw, err := os.ReadFile(filepath.Join(dir, "cmdline")) + if err != nil { + return false + } + args := strings.Split(strings.TrimRight(string(raw), "\x00"), "\x00") + if flagValue(args, "--address") != socketPath { + return false + } + theirs := flagValue(args, "--config") + if theirs == "" { + return false + } + // Resolve the path the way the process sees it, through its own root + // and working directory. + if filepath.IsAbs(theirs) { + theirs = filepath.Join(dir, "root", theirs) + } else { + theirs = filepath.Join(dir, "cwd", theirs) + } + info, err := os.Stat(theirs) + return err == nil && os.SameFile(info, config) +} + +func flagValue(args []string, flag string) string { + if i := slices.Index(args, flag); i >= 0 && i+1 < len(args) { + return args[i+1] + } + return "" +} + +// stopSurvivors sends SIGTERM to every process and waits up to timeout for +// them all to exit, then SIGKILLs any that remain. Shims are separate +// processes, so the containers they run outlive their daemon. +func stopSurvivors(procs []*os.Process, timeout time.Duration) error { + defer func() { + for _, proc := range procs { + proc.Release() + } + }() + for _, proc := range procs { + if err := proc.Signal(syscall.SIGTERM); err != nil && !errors.Is(err, os.ErrProcessDone) { + return fmt.Errorf("signalling containerd %d: %w", proc.Pid, err) + } + } + if waitGone(procs, timeout) { + return nil + } + for _, proc := range procs { + if err := proc.Signal(syscall.SIGKILL); err != nil && !errors.Is(err, os.ErrProcessDone) { + return fmt.Errorf("killing containerd %d: %w", proc.Pid, err) + } + } + if !waitGone(procs, 5*time.Second) { + return fmt.Errorf("containerd processes still running after SIGKILL") + } + return nil +} + +func waitGone(procs []*os.Process, timeout time.Duration) bool { + deadline := time.Now().Add(timeout) + for { + if !slices.ContainsFunc(procs, alive) { + return true + } + if time.Now().After(deadline) { + return false + } + time.Sleep(50 * time.Millisecond) + } +} + +func alive(proc *os.Process) bool { + return proc.Signal(syscall.Signal(0)) == nil +} + +// socketOwner returns the PID of the process listening on socketPath. +func socketOwner(socketPath string) (int, error) { + conn, err := net.DialTimeout("unix", socketPath, 500*time.Millisecond) + if err != nil { + return 0, err + } + defer conn.Close() + raw, err := conn.(*net.UnixConn).SyscallConn() + if err != nil { + return 0, err + } + var cred *unix.Ucred + var credErr error + if err := raw.Control(func(fd uintptr) { + cred, credErr = unix.GetsockoptUcred(int(fd), unix.SOL_SOCKET, unix.SO_PEERCRED) + }); err != nil { + return 0, err + } + if credErr != nil { + return 0, credErr + } + return int(cred.Pid), nil +} diff --git a/components/containerd/survivors_linux_test.go b/components/containerd/survivors_linux_test.go new file mode 100644 index 000000000..767a10ef3 --- /dev/null +++ b/components/containerd/survivors_linux_test.go @@ -0,0 +1,199 @@ +package containerd + +import ( + "context" + "log/slog" + "net" + "os" + "os/exec" + "path/filepath" + "testing" + "time" + + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" +) + +// fakeContainerd writes a script named containerd, so the kernel reports +// "containerd" as its comm just as it does for the real daemon. The script +// ignores its arguments and sleeps; trapTerm controls whether SIGTERM ends it. +func fakeContainerd(t *testing.T, trapTerm bool) string { + t.Helper() + trap := "trap 'exit 0' TERM" + if !trapTerm { + trap = "trap '' TERM" + } + path := filepath.Join(t.TempDir(), "containerd") + script := "#!/bin/sh\n" + trap + "\nwhile :; do sleep 0.05; done\n" + require.NoError(t, os.WriteFile(path, []byte(script), 0755)) + return path +} + +// startSurvivor runs a fake daemon the way a previous server would have. The +// returned channel closes once it has exited and been reaped. +func startSurvivor(t *testing.T, binary, socketPath, configPath string) (int, <-chan struct{}) { + t.Helper() + cmd := exec.Command(binary, "--address", socketPath, "--config", configPath) + require.NoError(t, cmd.Start()) + done := make(chan struct{}) + go func() { + cmd.Wait() + close(done) + }() + t.Cleanup(func() { + cmd.Process.Kill() + <-done + }) + // Give the shell time to install its trap. + time.Sleep(200 * time.Millisecond) + return cmd.Process.Pid, done +} + +func writeConfig(t *testing.T) string { + t.Helper() + path := filepath.Join(t.TempDir(), "config.toml") + require.NoError(t, os.WriteFile(path, nil, 0644)) + return path +} + +func TestFindSurvivors(t *testing.T) { + binary := fakeContainerd(t, true) + socketPath := filepath.Join(t.TempDir(), "containerd.sock") + configPath := writeConfig(t) + + ours, _ := startSurvivor(t, binary, socketPath, configPath) + startSurvivor(t, binary, filepath.Join(t.TempDir(), "other.sock"), configPath) + // Same socket path, different config file: what a containerd in a + // container looks like from the host. + startSurvivor(t, binary, socketPath, writeConfig(t)) + + procs, err := findSurvivors(socketPath, configPath) + require.NoError(t, err) + require.Len(t, procs, 1) + assert.Equal(t, ours, procs[0].Pid) +} + +func TestStopSurvivors(t *testing.T) { + socketPath := filepath.Join(t.TempDir(), "containerd.sock") + configPath := writeConfig(t) + + t.Run("SIGTERM", func(t *testing.T) { + _, done := startSurvivor(t, fakeContainerd(t, true), socketPath, configPath) + procs, err := findSurvivors(socketPath, configPath) + require.NoError(t, err) + require.Len(t, procs, 1) + + require.NoError(t, stopSurvivors(procs, 5*time.Second)) + <-done + }) + + t.Run("falls back to SIGKILL", func(t *testing.T) { + _, done := startSurvivor(t, fakeContainerd(t, false), socketPath, configPath) + procs, err := findSurvivors(socketPath, configPath) + require.NoError(t, err) + require.Len(t, procs, 1) + + start := time.Now() + require.NoError(t, stopSurvivors(procs, 300*time.Millisecond)) + <-done + assert.Less(t, time.Since(start), 5*time.Second) + }) +} + +func TestSocketOwner(t *testing.T) { + socketPath := filepath.Join(t.TempDir(), "owner.sock") + l, err := net.Listen("unix", socketPath) + require.NoError(t, err) + defer l.Close() + + owner, err := socketOwner(socketPath) + require.NoError(t, err) + assert.Equal(t, os.Getpid(), owner) +} + +// TestStart_SocketServedByAnotherProcess reproduces the leak: a daemon this +// component didn't start answers on the socket, and the one it did start never +// comes up. Start must notice rather than adopt the stranger. +func TestStart_SocketServedByAnotherProcess(t *testing.T) { + baseDir := t.TempDir() + socketPath := filepath.Join(baseDir, "containerd.sock") + l, err := net.Listen("unix", socketPath) + require.NoError(t, err) + defer l.Close() + + c := NewContainerdComponent(slog.New(slog.NewTextHandler(os.Stderr, nil)), baseDir) + ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second) + defer cancel() + + err = c.Start(ctx, &Config{ + BinaryPath: fakeContainerd(t, true), + BaseDir: baseDir, + SocketPath: socketPath, + }) + require.Error(t, err) + assert.Contains(t, err.Error(), "not the daemon we started") + assert.False(t, c.IsRunning()) +} + +func TestStart_StopsSurvivors(t *testing.T) { + baseDir := t.TempDir() + socketPath := filepath.Join(baseDir, "containerd.sock") + binary := fakeContainerd(t, true) + _, done := startSurvivor(t, binary, socketPath, filepath.Join(baseDir, "config.toml")) + + c := NewContainerdComponent(slog.New(slog.NewTextHandler(os.Stderr, nil)), baseDir) + ctx, cancel := context.WithTimeout(context.Background(), 2*time.Second) + defer cancel() + + // The fake never listens, so Start still fails, but only after it has + // cleared the survivor out of the way. + err := c.Start(ctx, &Config{BinaryPath: binary, BaseDir: baseDir, SocketPath: socketPath}) + require.Error(t, err) + select { + case <-done: + default: + t.Fatal("survivor still running after Start") + } +} + +func TestStart_DaemonExitsEarly(t *testing.T) { + baseDir := t.TempDir() + binary := filepath.Join(t.TempDir(), "containerd") + require.NoError(t, os.WriteFile(binary, []byte("#!/bin/sh\nexit 1\n"), 0755)) + + c := NewContainerdComponent(slog.New(slog.NewTextHandler(os.Stderr, nil)), baseDir) + start := time.Now() + err := c.Start(context.Background(), &Config{BinaryPath: binary, BaseDir: baseDir}) + require.Error(t, err) + assert.Contains(t, err.Error(), "exited before its socket was ready") + assert.Less(t, time.Since(start), 5*time.Second) +} + +// A second server pointed at the same data directory must not mistake the +// first server's live daemon for a survivor. +func TestStart_LeavesLiveOwnersDaemonAlone(t *testing.T) { + baseDir := t.TempDir() + socketPath := filepath.Join(baseDir, "containerd.sock") + binary := fakeContainerd(t, true) + _, done := startSurvivor(t, binary, socketPath, filepath.Join(baseDir, "config.toml")) + + owner, err := lockBaseDir(baseDir) + require.NoError(t, err) + defer owner.Close() + + c := NewContainerdComponent(slog.New(slog.NewTextHandler(os.Stderr, nil)), baseDir) + err = c.Start(context.Background(), &Config{BinaryPath: binary, BaseDir: baseDir, SocketPath: socketPath}) + require.Error(t, err) + assert.Contains(t, err.Error(), "already managing containerd") + select { + case <-done: + t.Fatal("live owner's daemon was stopped") + case <-time.After(200 * time.Millisecond): + } + + // Once the owner is gone, the lock is free again. + owner.Close() + relock, err := lockBaseDir(baseDir) + require.NoError(t, err) + relock.Close() +} diff --git a/components/containerd/survivors_other.go b/components/containerd/survivors_other.go new file mode 100644 index 000000000..fe714e861 --- /dev/null +++ b/components/containerd/survivors_other.go @@ -0,0 +1,20 @@ +//go:build !linux + +package containerd + +import ( + "errors" + "os" + "time" +) + +// Survivor detection reads /proc and SO_PEERCRED, so off Linux there is +// nothing to find and no owner to check. + +func findSurvivors(string, string) ([]*os.Process, error) { return nil, nil } + +func stopSurvivors([]*os.Process, time.Duration) error { return nil } + +func socketOwner(string) (int, error) { + return 0, errors.ErrUnsupported +} diff --git a/docs/docs/changelog.md b/docs/docs/changelog.md index 5dd31e2ea..2bbd063a2 100644 --- a/docs/docs/changelog.md +++ b/docs/docs/changelog.md @@ -11,8 +11,16 @@ All notable changes to Miren Runtime will be documented in this file. ## Unreleased *release/0.17* +--- + +## v0.17.3 +*2026-11-04* + **Bug Fixes** - **Busy autoscaled services keep serving at capacity instead of hanging** - When every sandbox hit its `requests_per_instance` target, requests parked in the activator waiting for a new sandbox, and failed with "no sandbox became available within 120 seconds" even when the sandboxes had room. Once a service reached its maximum of 20 instances, no new sandbox could come, so requests hung until they timed out. Requests now go to the least-loaded sandbox and the pool grows in the background. At the maximum, requests keep spreading across the sandboxes a service has. A response cut off partway, by a client hanging up or a silent stream timing out, also no longer leaks capacity for the life of the sandbox, and a scale-down can no longer overwrite a scale-up that happened at the same moment. ([#1387](https://github.com/mirendev/runtime/pull/1387)) +- **Metrics forwarding refuses certificates from the compromised eMudhra intermediates** - vmagent was the last component Miren ships that still verified public certificates on a Go release without the distrust. It sends metrics with a bearer token, so a certificate chained through those intermediates could have captured that token. Miren now ships vmagent v1.155.0, built on Go 1.27.3, with no change to how vmagent behaves. ([#1425](https://github.com/mirendev/runtime/pull/1425)) +- **Servers clean up leftover containerd daemons** - If Miren exited without running its stop hooks, after a panic for example, its containerd kept running. Every containerd started after that hung waiting for the lock while the old one kept answering, so a host could quietly run a months-old containerd and collect a stuck daemon for each restart. Miren now stops leftovers before starting its own, and a second server on the same data directory refuses to start. Sandboxes keep running throughout. The first restart on this release cleans up a host that's already in this state. ([#1416](https://github.com/mirendev/runtime/pull/1416)) +- **Servers stop promptly instead of stalling on dead connections** - Every upgrade sat idle for about 16 seconds after SIGTERM with public ingress already down, waiting on connections whose peers had gone away. Shutdown now waits only for handlers that are still running, and `miren` CLI commands close their connections when they exit. ([#1408](https://github.com/mirendev/runtime/pull/1408)) --- diff --git a/pkg/imagerefs/imagerefs.go b/pkg/imagerefs/imagerefs.go index d88e9e277..0fc9c2f45 100644 --- a/pkg/imagerefs/imagerefs.go +++ b/pkg/imagerefs/imagerefs.go @@ -34,7 +34,7 @@ const ( VictoriaMetrics = "oci.miren.cloud/victoria-metrics:v1.106.1" // vmagent Prometheus scraper and remote-write forwarder (docker.io/victoriametrics/vmagent) - VMagent = "oci.miren.cloud/vmagent:v1.150.0" + VMagent = "oci.miren.cloud/vmagent:v1.155.0" // Miren runtime server Miren = "oci.miren.cloud/miren:latest" diff --git a/pkg/rpc/drain.go b/pkg/rpc/drain.go index e015398d4..233c64247 100644 --- a/pkg/rpc/drain.go +++ b/pkg/rpc/drain.go @@ -47,27 +47,44 @@ const drainPollInterval = 25 * time.Millisecond // Healthy drains finish well inside it, so it costs nothing on a clean stop. const drainCensusDelay = 5 * time.Second +// drainSettle is how long every handler must have been finished before a drain +// stops waiting on the connections still open. A handler that has returned has +// handed its response to QUIC, but closing the connection discards whatever has +// not been delivered yet, so the last response gets time to reach its caller. +// Callers include CLIs across the internet, where one lost packet costs a +// retransmission timeout of several round trips. A second covers that, and +// shutdown latency is the only thing it trades away. +const drainSettle = time.Second + // WebTransport's raw HTTP/3 connections are not managed by http3.Shutdown. // Clients that understand /_rpc/drain retire themselves after reading their -// responses. Older and plain HTTP/3 clients have only the deadline fallback. +// responses, but a client that goes away without closing its connection (a CLI +// killed mid-command, an older CLI, a peer whose network drops) leaves the +// server holding a dead peer until the QUIC idle timeout, 30s after its last +// packet. Waiting for those turned shutdowns into 20-30s stalls with nothing +// running. By the time the drain starts, Shutdown has cancelled s.top, so new +// requests are refused and the only work left is handlers already running. +// Once they have finished there is nothing to drain, and Shutdown closes the +// remaining connections. func (s *State) drainWebTransport(ctx context.Context) error { _ = s.li.Close() // Stabilize the census before observing zero: Accept may have returned a // connection just before listener closure and not counted it yet. <-s.acceptDone - return waitForIdle(ctx, s.log, "HTTP/3", s.li) + return waitForIdle(ctx, s.log, "HTTP/3", s.li, s.server.requests) } -// waitForIdle polls until every connection ln accepted has closed or ctx ends. -// If the wait outlasts drainCensusDelay it logs the connections still open, -// once: a wait that ends just inside its deadline returns nil, and this line is -// then the only record of which peer held the shutdown up. -func waitForIdle(ctx context.Context, log *slog.Logger, surface string, ln *countingListener) error { +// waitForIdle polls until every connection ln accepted has closed, or until +// requests (when given) has had no handler running for drainSettle, or ctx +// ends. If the wait outlasts drainCensusDelay it logs the connections still +// open, once: a wait that ends just inside its deadline returns nil, and this +// line is then the only record of which peer held the shutdown up. +func waitForIdle(ctx context.Context, log *slog.Logger, surface string, ln *countingListener, requests *requestCounter) error { ticker := time.NewTicker(drainPollInterval) defer ticker.Stop() census := time.NewTimer(drainCensusDelay) defer census.Stop() - for !ln.idle() { + for !ln.idle() && !requests.settled(time.Now()) { select { case <-ctx.Done(): return context.Cause(ctx) @@ -82,6 +99,38 @@ func waitForIdle(ctx context.Context, log *slog.Logger, surface string, ln *coun return nil } +// requestCounter tracks the handlers running on a server and when the last +// one finished. +type requestCounter struct { + active atomic.Int64 + lastDone atomic.Int64 // unix nanoseconds +} + +// begin and end tolerate a nil counter, which a Server built without +// NewServer has. +func (c *requestCounter) begin() { + if c != nil { + c.active.Add(1) + } +} + +func (c *requestCounter) end() { + if c != nil { + c.lastDone.Store(time.Now().UnixNano()) + c.active.Add(-1) + } +} + +// settled reports that no handler is running and none has finished within +// drainSettle of now. A nil counter is never settled, so a drain without one +// waits for its connections as before. +func (c *requestCounter) settled(now time.Time) bool { + if c == nil || c.active.Load() > 0 { + return false + } + return now.Sub(time.Unix(0, c.lastDone.Load())) >= drainSettle +} + // countingListener wraps the QUIC listener handed to an http3.Server so we can // tell whether a drain still has work to do. It costs one atomic increment per // accepted connection, on a path that has just finished a QUIC handshake. @@ -191,7 +240,7 @@ func drainQUIC(ctx context.Context, log *slog.Logger, surface string, shutdown f // context and closes its listeners before it looks at the context, so the // teardown happens in full and only the waiting is skipped. go func() { - if waitForIdle(drainCtx, log, surface, ln) == nil { + if waitForIdle(drainCtx, log, surface, ln, nil) == nil { cancel() } }() diff --git a/pkg/rpc/drain_client_test.go b/pkg/rpc/drain_client_test.go index f5731206a..04693c2b1 100644 --- a/pkg/rpc/drain_client_test.go +++ b/pkg/rpc/drain_client_test.go @@ -5,6 +5,7 @@ import ( "crypto/tls" "errors" "io" + "net" "net/http" "strings" "sync/atomic" @@ -210,3 +211,48 @@ func TestHTTPDrainRetriesWatchAfterPreparationFailure(t *testing.T) { s.cancel() require.Eventually(t, s.li.idle, time.Second, time.Millisecond) } + +// A peer that vanishes without CONNECTION_CLOSE, as an exiting CLI used to, +// leaves the server holding its connection until the 30s idle timeout. The +// drain must not wait for that once nothing is running on it. +func TestHTTPDrainDoesNotWaitOnAVanishedPeer(t *testing.T) { + s, err := NewState(t.Context(), WithSkipVerify, + WithHTTPHandler("GET /payload", http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) { + _, _ = io.WriteString(w, "ok") + }))) + require.NoError(t, err) + t.Cleanup(func() { _ = s.Close() }) + + udp, err := net.ListenUDP("udp", &net.UDPAddr{IP: net.IPv4(127, 0, 0, 1)}) + require.NoError(t, err) + tr := &quic.Transport{Conn: udp} + client := &http3.Transport{ + TLSClientConfig: &tls.Config{InsecureSkipVerify: true}, + Dial: func(ctx context.Context, addr string, tlsCfg *tls.Config, cfg *quic.Config) (*quic.Conn, error) { + raddr, err := net.ResolveUDPAddr("udp", addr) + if err != nil { + return nil, err + } + return tr.DialEarly(ctx, raddr, tlsCfg, cfg) + }, + } + + req, err := http.NewRequestWithContext(t.Context(), http.MethodGet, "https://"+s.LoopbackAddr()+"/payload", nil) + require.NoError(t, err) + resp, err := client.RoundTrip(req) + require.NoError(t, err) + body, err := io.ReadAll(resp.Body) + require.NoError(t, err) + require.Equal(t, "ok", string(body)) + + // Closing the socket out from under the transport is what a process exit + // does: whatever close the transport attempts never reaches the server. + require.NoError(t, udp.Close()) + require.False(t, s.li.idle(), "server already saw the peer leave; the test would prove nothing") + + ctx, cancel := context.WithTimeout(t.Context(), 20*time.Second) + defer cancel() + start := time.Now() + require.NoError(t, s.Shutdown(ctx)) + require.Less(t, time.Since(start), drainSettle+2*time.Second, "shutdown waited on a peer with nothing running") +} diff --git a/pkg/rpc/drain_test.go b/pkg/rpc/drain_test.go index f4213a68b..811bd7f15 100644 --- a/pkg/rpc/drain_test.go +++ b/pkg/rpc/drain_test.go @@ -197,7 +197,7 @@ func TestWaitForIdleNamesConnectionsItWaitsOn(t *testing.T) { ctx, cancel := context.WithTimeout(context.Background(), 30*time.Second) defer cancel() - if err := waitForIdle(ctx, log, "HTTP/3", ln); err != nil { + if err := waitForIdle(ctx, log, "HTTP/3", ln, nil); err != nil { t.Fatalf("wait that finished inside its deadline returned %v", err) } if got := strings.Count(logs.String(), `msg="drain still waiting on open connections" surface=HTTP/3`); got != 1 { @@ -219,7 +219,7 @@ func TestWaitForIdleStaysQuietOnAPromptDrain(t *testing.T) { ln.open.Store(0) }() - if err := waitForIdle(context.Background(), slog.New(slog.NewTextHandler(&logs, nil)), "HTTP/3", ln); err != nil { + if err := waitForIdle(context.Background(), slog.New(slog.NewTextHandler(&logs, nil)), "HTTP/3", ln, nil); err != nil { t.Fatalf("prompt drain returned %v", err) } if logs.Len() != 0 { @@ -228,6 +228,63 @@ func TestWaitForIdleStaysQuietOnAPromptDrain(t *testing.T) { }) } +func TestWaitForIdleStopsWaitingOnDeadPeersOnceHandlersSettle(t *testing.T) { + synctest.Test(t, func(t *testing.T) { + var logs bytes.Buffer + ln := &countingListener{} + ln.accepted.Store(2) + // A CLI that exited without closing its connection: the server holds + // it until the QUIC idle timeout, and nothing is running on it. + ln.open.Store(2) + + var requests requestCounter + requests.begin() + go func() { + time.Sleep(time.Second) + requests.end() + }() + + ctx, cancel := context.WithTimeout(context.Background(), 30*time.Second) + defer cancel() + start := time.Now() + if err := waitForIdle(ctx, slog.New(slog.NewTextHandler(&logs, nil)), "HTTP/3", ln, &requests); err != nil { + t.Fatalf("drain with settled handlers returned %v", err) + } + if got, want := time.Since(start), time.Second+drainSettle; got < want || got > want+drainPollInterval { + t.Fatalf("drain took %v, want the running handler plus the settle (%v)", got, want) + } + if logs.Len() != 0 { + t.Fatalf("prompt drain logged:\n%s", logs.String()) + } + }) +} + +func TestRequestCounterSettled(t *testing.T) { + synctest.Test(t, func(t *testing.T) { + var nilCounter *requestCounter + if nilCounter.settled(time.Now()) { + t.Fatal("nil counter settled; a drain without one must wait for its connections") + } + + var c requestCounter + if !c.settled(time.Now()) { + t.Fatal("counter that never saw a request is not settled") + } + c.begin() + if c.settled(time.Now()) { + t.Fatal("settled with a handler running") + } + c.end() + if c.settled(time.Now()) { + t.Fatal("settled the instant the last handler returned") + } + time.Sleep(drainSettle) + if !c.settled(time.Now()) { + t.Fatal("not settled drainSettle after the last handler returned") + } + }) +} + func TestDrainQUICNamesConnectionsItWaitsOn(t *testing.T) { synctest.Test(t, func(t *testing.T) { var logs bytes.Buffer diff --git a/pkg/rpc/server.go b/pkg/rpc/server.go index 92a7204e9..f91deb411 100644 --- a/pkg/rpc/server.go +++ b/pkg/rpc/server.go @@ -69,6 +69,10 @@ type Server struct { // and ServeMux panics on a duplicate pattern, so re-registration is skipped // rather than allowed to take the process down. restRoutes map[string]string + + // requests counts handlers still running, so a drain can tell a + // connection with work on it from one held open by a peer that has gone. + requests *requestCounter } type heldInterface struct { @@ -113,6 +117,7 @@ func newServer() *Server { knownAddresses: make(map[string]string), resolvers: make(map[string]HasReconstructFromState), restRoutes: make(map[string]string), + requests: &requestCounter{}, } s.setupMux() @@ -123,6 +128,7 @@ func newServer() *Server { func (s *Server) Clone(state *State) *Server { ns := *s ns.state = state + ns.requests = &requestCounter{} return &ns } @@ -513,6 +519,9 @@ func (s *Server) mountHTTPHandlers(mounts []httpHandlerMount) error { } func (s *Server) ServeHTTP(w http.ResponseWriter, r *http.Request) { + s.requests.begin() + defer s.requests.end() + ctx := r.Context() if s.state.top.Err() != nil && r.URL.Path != drainPath { http.Error(w, "server draining", http.StatusServiceUnavailable)