ateom-microvm: recover when the guest dies before the kata-agent answers

A resume can fail with a bare `dial unix /run/vc/vm/<uid>/clh.sock: connect:
no such file or directory`, one minute after it started (agent-substrate#619). The socket
was there — the caller waits for it before dialing — so it went away while
we polled, and cloud-hypervisor unlinks it in the vsock device's shutdown:
the guest died during boot. Under a contended host the guest's boot stretches
badly (measured: systemd reaching its default target 25s in, versus about a
second when idle), and a boot that stalls long enough is torn down guest-side.

So treat ENOENT as what it is. Instead of polling a socket that cannot come
back, and reporting the last dial error as if it were the problem, give up at
once with an error that names the cause, and retry the cold boot: a guest that
never reached its agent ran none of the actor's containers, and the failure
path tears the whole attempt down, so starting over is safe — and it is the
only recovery, since the dead VM is not coming back. Each retry is logged with
the guest's boot diagnostics (the console tail, plus each virtiofsd's log,
because cloud-hypervisor also stops the VM when a vhost-user backend dies and
that leaves the console silent).

Author: BenTheElder

cmd/ateom-microvm/durable.go

@@ -99,6 +99,12 @@ func workloadSpec(c actorContainer) *specs.Spec {
 	return &spec
 }
 
+// durableVirtiofsdLogPath is where the durable-dir share's virtiofsd logs,
+// beside the overlay lower's (see virtiofsdLogPath) under the actor's VM dir.
+func durableVirtiofsdLogPath(id string) string {
+	return filepath.Join(kata.VMDir(id), "virtiofsd-durable.log")
+}
+
 // stageDurableShare starts the virtiofsd serving the actor's durable-dir volumes.
 //
 // It serves ateompath.DurableDirVolumeMountsDir directly — no bind into the
@@ -113,7 +119,7 @@ func (s *AteomService) stageDurableShare(ctx context.Context, rr resolvedRuntime
 	if _, err := os.Stat(shared); err != nil {
 		return nil, fmt.Errorf("while checking durable-dir volumes dir %q: %w", shared, err)
 	}
-	log, _ := os.OpenFile(filepath.Join(kata.VMDir(actorUID), "virtiofsd-durable.log"), os.O_CREATE|os.O_WRONLY|os.O_TRUNC, 0o600)
+	log, _ := os.OpenFile(durableVirtiofsdLogPath(actorUID), os.O_CREATE|os.O_WRONLY|os.O_TRUNC, 0o600)
 	cmd, err := kata.StartVirtiofsd(ctx, kata.VirtiofsdOptions{
 		Binary:     rr.virtiofsd,
 		SocketPath: kata.DurableVirtiofsdSocketPath(actorUID),

cmd/ateom-microvm/restore.go

@@ -87,7 +87,7 @@ func (s *AteomService) RestoreWorkload(ctx context.Context, req *ateompb.Restore
 		// A Data snapshot holds no guest state, so this is a cold boot that
 		// happens to start with the volumes already populated. readyz gating comes
 		// with the cold-boot path, so the actor is serving when we return.
-		if err := s.coldBootActor(ctx, p); err != nil {
+		if err := s.coldBootActorRetrying(ctx, p); err != nil {
 			return nil, err
 		}
 		slog.InfoContext(ctx, "Actor restored (durable-dir volumes, cold boot)",

cmd/ateom-microvm/run.go

@@ -18,7 +18,9 @@ package main
 
 import (
 	"context"
+	"errors"
 	"fmt"
+	"io/fs"
 	"log/slog"
 	"os"
 	"os/exec"
@@ -209,7 +211,7 @@ func (s *AteomService) RunWorkload(ctx context.Context, req *ateompb.RunWorkload
 	}
 
 	s.actorLogger.EmitLifecycleLog("Actor starting", p.actorRef, p.actorUID, p.templateNS, p.templateName)
-	if err := s.coldBootActor(ctx, p); err != nil {
+	if err := s.coldBootActorRetrying(ctx, p); err != nil {
 		return nil, err
 	}
 	s.actorLogger.EmitLifecycleLog("Actor started", p.actorRef, p.actorUID, p.templateNS, p.templateName)
@@ -229,6 +231,34 @@ type actorBootParams struct {
 	assetPaths   map[string]string
 }
 
+// coldBootAttempts is how many times a cold boot is tried when the micro-VM
+// stops before the kata-agent answers. Two: one retry covers a transient guest
+// death (a contended host makes the guest's boot pathologically slow, and a
+// boot that stalls long enough is torn down guest-side), and beyond that the
+// fault is not transient and the caller should hear about it.
+const coldBootAttempts = 2
+
+// coldBootActorRetrying cold-boots the actor, retrying if the micro-VM stopped
+// before the kata-agent answered.
+//
+// Retrying is safe there and nowhere else: a guest that never reached its agent
+// ran none of the actor's containers, so the attempt has no observable effect,
+// and coldBootActor's failure path tears the whole thing down (VMM, virtiofsds,
+// network, bundle mounts) before returning. It is also the only recovery — the
+// dead VM does not come back, so the alternative is failing the actor's resume.
+// Every retry is logged alongside the guest's boot diagnostics, so a guest that
+// dies at boot is never silent.
+func (s *AteomService) coldBootActorRetrying(ctx context.Context, p actorBootParams) error {
+	for attempt := 1; ; attempt++ {
+		err := s.coldBootActor(ctx, p)
+		if err == nil || attempt >= coldBootAttempts || !errors.Is(err, errGuestStopped) {
+			return err
+		}
+		slog.WarnContext(ctx, "Micro-VM stopped before the kata-agent answered; retrying cold boot",
+			slog.String("id", p.actorUID), slog.Int("attempt", attempt), slog.Any("err", err))
+	}
+}
+
 // coldBootActor boots the actor's micro-VM from scratch and starts its
 // containers, registering the result in s.running. The caller holds s.lock and
 // owns the lifecycle logging.
@@ -392,9 +422,7 @@ func (s *AteomService) coldBootActor(ctx context.Context, p actorBootParams) (re
 	}
 	ac, err := dialAgentRetry(ctx, vsockPath, 60*time.Second)
 	if err != nil {
-		if b, rerr := os.ReadFile(serialLog); rerr == nil {
-			slog.ErrorContext(ctx, "agent dial failed; guest serial tail", slog.String("serial", tailString(string(b), 3000)))
-		}
+		logGuestBootDiagnostics(ctx, actorUID, serialLog)
 		return fmt.Errorf("while dialing kata-agent: %w", err)
 	}
 	// The agent client must stay open past this RPC: the stdout/stderr forwarding
@@ -486,7 +514,7 @@ func (s *AteomService) stageOverlayLowers(ctx context.Context, rr resolvedRuntim
 			return nil, fmt.Errorf("while staging overlay lower for %q: %w", c.name, err)
 		}
 	}
-	vfsdLog, _ := os.OpenFile(filepath.Join(kata.VMDir(id), "virtiofsd.log"), os.O_CREATE|os.O_WRONLY|os.O_TRUNC, 0o600)
+	vfsdLog, _ := os.OpenFile(virtiofsdLogPath(id), os.O_CREATE|os.O_WRONLY|os.O_TRUNC, 0o600)
 	vfsdCmd, err := kata.StartVirtiofsd(ctx, kata.VirtiofsdOptions{
 		Binary:     rr.virtiofsd,
 		SocketPath: kata.VirtiofsdSocketPath(id),
@@ -658,12 +686,23 @@ func (s *AteomService) startActorLogForwarding(ac *kata.AgentClient, actorRef re
 	go s.actorLogger.WrapContainerLogs(kata.NewStdioReader(context.Background(), ac, streamID, streamID, true), actorRef, actorUID, actorTemplateNamespace, actorTemplateName, containerName)
 }
 
+// errGuestStopped reports that the micro-VM stopped before the kata-agent
+// answered. Callers that can start over (a cold boot has no observable side
+// effects until the agent runs the containers) retry on it.
+var errGuestStopped = errors.New("micro-VM stopped before the kata-agent answered")
+
 // dialAgentRetry polls DialAgent until the kata-agent answers the hybrid-vsock
 // CONNECT (the socket file exists at boot, but the agent only listens once the
 // guest reaches kata-containers.target) or the overall timeout elapses. Each
 // attempt is capped at 5s (usually it fails fast with connection-refused while
 // the agent isn't listening yet; the cap only bounds a rare hung dial), then
 // waits 500ms before retrying — so steady-state polling is ~every 500ms, not 5s.
+//
+// A dial that fails with ENOENT ends the poll immediately as errGuestStopped:
+// callers wait for the socket to appear before dialing, and cloud-hypervisor
+// unlinks it when the VM stops (virtio-vsock device shutdown), so a socket that
+// has gone missing means the guest died. Polling on would only spend the rest
+// of the timeout to report a bare "no such file or directory".
 func dialAgentRetry(ctx context.Context, vsockPath string, timeout time.Duration) (*kata.AgentClient, error) {
 	deadline := time.Now().Add(timeout)
 	var lastErr error
@@ -674,6 +713,9 @@ func dialAgentRetry(ctx context.Context, vsockPath string, timeout time.Duration
 		if err == nil {
 			return ac, nil
 		}
+		if errors.Is(err, fs.ErrNotExist) {
+			return nil, fmt.Errorf("%w (cloud-hypervisor removed %q): %w", errGuestStopped, vsockPath, err)
+		}
 		lastErr = err
 		if time.Now().After(deadline) {
 			return nil, lastErr
@@ -686,6 +728,29 @@ func dialAgentRetry(ctx context.Context, vsockPath string, timeout time.Duration
 	}
 }
 
+// logGuestBootDiagnostics dumps what the host recorded about a guest that never
+// reached the kata-agent: the console tail, where a guest-side panic or an early
+// power-off shows up, and each virtiofsd's log — cloud-hypervisor stops the VM
+// when a vhost-user backend dies, and that leaves the console silent.
+func logGuestBootDiagnostics(ctx context.Context, actorUID, serialLog string) {
+	for _, l := range []struct{ name, path string }{
+		{"serial", serialLog},
+		{"virtiofsd", virtiofsdLogPath(actorUID)},
+		{"virtiofsd-durable", durableVirtiofsdLogPath(actorUID)},
+	} {
+		b, err := os.ReadFile(l.path)
+		if err != nil || len(b) == 0 {
+			continue
+		}
+		slog.ErrorContext(ctx, "agent dial failed; guest boot diagnostics",
+			slog.String("log", l.name), slog.String("tail", tailString(string(b), 3000)))
+	}
+}
+
+// virtiofsdLogPath is where the overlay RO lower's virtiofsd logs, under the
+// actor's VM dir alongside the sockets and the guest console.
+func virtiofsdLogPath(id string) string { return filepath.Join(kata.VMDir(id), "virtiofsd.log") }
+
 // tailString returns the last n bytes of s (for logging a serial-console tail).
 func tailString(s string, n int) string {
 	if len(s) <= n {

cmd/ateom-microvm/run_test.go

@@ -0,0 +1,96 @@
+//go:build linux
+
+// Copyright 2026 Google LLC
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//     http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
+package main
+
+import (
+	"context"
+	"errors"
+	"net"
+	"path/filepath"
+	"testing"
+	"time"
+)
+
+// A vsock socket that has gone missing means cloud-hypervisor stopped the VM
+// (it unlinks the socket in the vsock device's shutdown), so the poll must give
+// up at once instead of spending the whole timeout on a guest that is gone.
+func TestDialAgentRetryGuestStopped(t *testing.T) {
+	missing := filepath.Join(t.TempDir(), "clh.sock")
+
+	start := time.Now()
+	_, err := dialAgentRetry(t.Context(), missing, 30*time.Second)
+	elapsed := time.Since(start)
+
+	if !errors.Is(err, errGuestStopped) {
+		t.Errorf("dialAgentRetry(%q) error = %v, want it to wrap errGuestStopped", missing, err)
+	}
+	if elapsed > 5*time.Second {
+		t.Errorf("dialAgentRetry(%q) took %v; want it to give up immediately, not poll for the full timeout", missing, elapsed)
+	}
+}
+
+// The socket exists but nothing answers yet: that is every dial until the guest
+// reaches kata-containers.target, so it must keep polling to the timeout.
+func TestDialAgentRetryNotListeningYet(t *testing.T) {
+	path := filepath.Join(t.TempDir(), "clh.sock")
+	l, err := net.Listen("unix", path)
+	if err != nil {
+		t.Fatalf("failed to create test socket: %v", err)
+	}
+	// Leave the socket file behind, as cloud-hypervisor does while the VM runs:
+	// connecting is then refused, which is what an unanswered CONNECT looks like.
+	l.(*net.UnixListener).SetUnlinkOnClose(false)
+	if err := l.Close(); err != nil {
+		t.Fatalf("failed to close test listener: %v", err)
+	}
+
+	const timeout = 700 * time.Millisecond
+	start := time.Now()
+	_, err = dialAgentRetry(t.Context(), path, timeout)
+	elapsed := time.Since(start)
+
+	if err == nil {
+		t.Fatalf("dialAgentRetry(%q) succeeded, want an error", path)
+	}
+	if errors.Is(err, errGuestStopped) {
+		t.Errorf("dialAgentRetry(%q) error = %v, want a plain dial error (the guest is still running)", path, err)
+	}
+	if elapsed < timeout {
+		t.Errorf("dialAgentRetry(%q) gave up after %v, want it to keep polling for at least %v", path, elapsed, timeout)
+	}
+}
+
+// A canceled context ends the poll with the context's error, so a caller that
+// gives up on the restore is not left waiting out the timeout.
+func TestDialAgentRetryContextCanceled(t *testing.T) {
+	path := filepath.Join(t.TempDir(), "clh.sock")
+	l, err := net.Listen("unix", path)
+	if err != nil {
+		t.Fatalf("failed to create test socket: %v", err)
+	}
+	l.(*net.UnixListener).SetUnlinkOnClose(false)
+	if err := l.Close(); err != nil {
+		t.Fatalf("failed to close test listener: %v", err)
+	}
+
+	ctx, cancel := context.WithCancel(t.Context())
+	cancel()
+
+	if _, err := dialAgentRetry(ctx, path, time.Minute); !errors.Is(err, context.Canceled) {
+		t.Errorf("dialAgentRetry(%q) error = %v, want context.Canceled", path, err)
+	}
+}