diff --git a/docs/cloud-hypervisor-foundation.md b/docs/cloud-hypervisor-foundation.md index 5ac96c06d..13e303b35 100644 --- a/docs/cloud-hypervisor-foundation.md +++ b/docs/cloud-hypervisor-foundation.md @@ -76,8 +76,10 @@ AWF performs these steps for each run: non-root identity. 7. Start one sandboxed `virtiofsd` process for each validated export. 8. Create and boot the VM, connect to the guest supervisor over VSOCK, verify - guest network readiness (loopback interface UP), and probe infrastructure - connectivity. + loopback plus the configured guest interface, address, and route, and probe + each trusted infrastructure service with bounded retries. An exhausted + retryable readiness failure recreates the VM at most twice before the agent + command is dispatched. 9. Execute the agent command and propagate its exit code. Timeouts return `124`. 10. Sync and unmount guest filesystems, stop the VM and VMM, reap `virtiofsd`, @@ -244,19 +246,30 @@ them only after collecting the diagnostics you need. ### Guest network readiness timeout -If the guest network readiness check times out (error: `guest-network-not-ready`), the guest's loopback interface did not become UP before the timeout expired. Possible causes: +If the guest network readiness check times out (error: +`guest-network-not-ready`), loopback or the configured guest interface, +address, and default route did not become ready before the bounded phase +timeout. AWF cleans up and recreates the Cloud Hypervisor VM up to two times, +with 5-second and 10-second delays, before failing. The wrapped command is +never dispatched during these recovery attempts. 1. **Guest image mismatch** — The guest supervisor contract requires loopback to be brought up before opening the VSOCK listener. A mismatched or incompatible guest image may violate this ordering. -2. **Host system issue** — Delays in kernel or KVM initialization may cause the readiness check to timeout. Retry the run; transient delays are sometimes recoverable. +2. **Host system issue** — Delays in kernel, KVM, interface, address, or route initialization may exhaust all automatic recovery attempts. 3. **Supervisor crash** — The guest supervisor may have crashed before initializing networking. Check preserved guest logs under `/microvm-images//` for supervisor output. -Verify the guest image digest and supervisor version match the build expectation, then retry. +Each failed attempt preserves diagnostics under +`/diagnostics/cloud-hypervisor/boot-attempt-/` (or the equivalent +`auditDir` path). Verify the recorded interface and route state, guest image +digest, and supervisor version before retrying the AWF invocation. ### Guest cannot reach Squid or the API proxy Check the namespace nftables rules, TAP state, and Squid/API proxy health. The guest must not have a direct route to the internet; fixing connectivity by loosening the default-deny policy would break the security boundary. +Squid, API proxy, and topology-peer probes retry independently inside the same +VM; an exhausted transient failure then enters the bounded pre-agent boot +recovery described above. ### VMM boot fails with TAP permission errors diff --git a/src/cloud-hypervisor-runtime-backend.test.ts b/src/cloud-hypervisor-runtime-backend.test.ts index 9ccfdadd0..92f290a47 100644 --- a/src/cloud-hypervisor-runtime-backend.test.ts +++ b/src/cloud-hypervisor-runtime-backend.test.ts @@ -98,6 +98,9 @@ function harness(overrides: Partial = const manager = { paths: { runDirectory: '/tmp/awf/cloud-hypervisor-run/cloud-hypervisor/test' }, guestIp: '100.64.0.2', + guestGatewayIp: '100.64.0.1', + guestPrefixLength: 30, + guestInterfaceName: 'eth0', networkNamespace: 'awfvm-test', start: jest.fn(async () => { order.push('vm-config'); }), startInstance: jest.fn(async () => { order.push('vm-start'); }), @@ -120,7 +123,10 @@ function harness(overrides: Partial = writeStdin: jest.fn().mockResolvedValue(undefined), endStdin: jest.fn().mockResolvedValue(undefined), collectDiagnostics: jest.fn().mockResolvedValue(undefined), - stop: jest.fn(async () => { order.push('vm-stop'); }), + stop: jest.fn(async (options?: { beforeCleanup?: () => Promise }) => { + order.push('vm-stop'); + await options?.beforeCleanup?.(); + }), }; const infra = infrastructure(); (infra.revalidate as jest.Mock).mockImplementation(async () => { @@ -143,6 +149,7 @@ function harness(overrides: Partial = info: jest.fn(), warn: jest.fn(), }, + sleep: jest.fn().mockResolvedValue(undefined), ...overrides, }; return { order, manager, infra, deps, stdin }; @@ -252,7 +259,7 @@ describe('Cloud Hypervisor runtime backend', () => { NO_PROXY: expect.stringContaining('awmg-mcpg'), no_proxy: expect.stringContaining('172.30.0.60'), }), - timeoutMs: 210_000, + timeoutMs: 468_000, }), ); }); @@ -332,21 +339,23 @@ describe('Cloud Hypervisor runtime backend', () => { it('stops the partial VM when readiness probing fails', async () => { const { manager, deps } = harness(); - manager.execute.mockReset() - .mockResolvedValueOnce({ - requestId: 'network-ready', exitCode: 0, signal: null, timedOut: false, - }) - .mockResolvedValue({ - requestId: 'probe', exitCode: 41, signal: null, timedOut: false, - }); + manager.execute.mockReset().mockImplementation(async (request) => ({ + requestId: request.requestId, + exitCode: request.requestId.startsWith('probe-network-ready-') ? 0 : 41, + signal: null, + timedOut: false, + })); const backend = new CloudHypervisorRuntimeBackend(config(), deps); await expect(backend.start('/tmp/awf', ['github.com'])) .rejects.toThrow(/connectivity probe failed/); - expect(manager.stop).toHaveBeenCalledTimes(1); + expect(manager.stop).toHaveBeenCalledTimes(3); + expect(deps.createManager).toHaveBeenCalledTimes(3); + expect(deps.sleep).toHaveBeenNthCalledWith(1, 5_000); + expect(deps.sleep).toHaveBeenNthCalledWith(2, 10_000); }); - it('waits with bounded backoff for guest loopback before probing connectivity', async () => { + it('waits with bounded backoff for the complete guest data plane before probing connectivity', async () => { const { manager, deps } = harness(); const backend = new CloudHypervisorRuntimeBackend(config(), deps); @@ -355,7 +364,14 @@ describe('Cloud Hypervisor runtime backend', () => { const networkReadyCall = manager.execute.mock.calls[0][0]; expect(networkReadyCall.argv.slice(0, 2)).toEqual(['/bin/sh', '-c']); expect(networkReadyCall.argv[2]).toContain('ip link show dev lo'); - expect(networkReadyCall.argv[2]).toContain('while [ "$attempt" -le 5 ]'); + expect(networkReadyCall.argv[2]).toContain("ip -4 addr show dev lo"); + expect(networkReadyCall.argv[2]).toContain("127.0.0.1/8"); + expect(networkReadyCall.argv[2]).toContain("interface='eth0'"); + expect(networkReadyCall.argv[2]).toContain("address='100.64.0.2/30'"); + expect(networkReadyCall.argv[2]).toContain("gateway='100.64.0.1'"); + expect(networkReadyCall.argv[2]).toContain('state UP'); + expect(networkReadyCall.argv[2]).toContain('ip route show default'); + expect(networkReadyCall.argv[2]).toContain('while [ "$attempt" -le 10 ]'); expect(networkReadyCall.argv[2]).toContain('delay=$((delay * 2))'); expect(networkReadyCall.timeoutMs).toBe(90_000); expect(manager.execute.mock.calls[1][0].argv[2]).toContain('nc -v -z'); @@ -363,7 +379,7 @@ describe('Cloud Hypervisor runtime backend', () => { .toBeLessThan(manager.execute.mock.invocationCallOrder[1]); }); - it('fails with guest-network-not-ready when loopback stays down', async () => { + it('retries the boot and fails with structured diagnostics when the data plane stays down', async () => { const { manager, deps } = harness(); manager.execute.mockReset().mockResolvedValue({ requestId: 'network-ready', @@ -373,13 +389,20 @@ describe('Cloud Hypervisor runtime backend', () => { }); const backend = new CloudHypervisorRuntimeBackend(config(), deps); - await expect(backend.start('/tmp/awf', ['github.com'])).rejects.toThrow( - /guest-network-not-ready: Cloud Hypervisor guest loopback interface lo did not become UP/, - ); - expect(manager.execute).toHaveBeenCalledTimes(1); - expect(manager.stop).toHaveBeenCalledTimes(1); + await expect(backend.start('/tmp/awf', ['github.com'])).rejects.toMatchObject({ + code: 'CLOUD_HYPERVISOR_RETRYABLE_READINESS', + stage: 'guest-network-readiness', + bootAttempt: 3, + diagnosticDirectories: [ + '/tmp/awf/diagnostics/cloud-hypervisor/boot-attempt-1', + '/tmp/awf/diagnostics/cloud-hypervisor/boot-attempt-2', + '/tmp/awf/diagnostics/cloud-hypervisor/boot-attempt-3', + ], + }); + expect(manager.execute).toHaveBeenCalledTimes(3); + expect(manager.stop).toHaveBeenCalledTimes(3); expect(deps.logger.warn).toHaveBeenCalledWith( - expect.stringContaining('stage=guest-network-readiness status=failed'), + expect.stringContaining('stage=guest-network-readiness status=failed boot-attempt=3/3'), ); }); @@ -391,21 +414,20 @@ describe('Cloud Hypervisor runtime backend', () => { // time -- harmless on its own (network/cgroup are already cleared), // but wasteful and a source of confusion when diagnosing failures. const { manager, deps } = harness(); - manager.execute.mockReset() - .mockResolvedValueOnce({ - requestId: 'network-ready', exitCode: 0, signal: null, timedOut: false, - }) - .mockResolvedValue({ - requestId: 'probe', exitCode: 41, signal: null, timedOut: false, - }); + manager.execute.mockReset().mockImplementation(async (request) => ({ + requestId: request.requestId, + exitCode: request.requestId.startsWith('probe-network-ready-') ? 0 : 41, + signal: null, + timedOut: false, + })); const backend = new CloudHypervisorRuntimeBackend(config(), deps); await expect(backend.start('/tmp/awf', ['github.com'])) .rejects.toThrow(/connectivity probe failed/); - expect(manager.stop).toHaveBeenCalledTimes(1); + expect(manager.stop).toHaveBeenCalledTimes(3); await backend.stop(); - expect(manager.stop).toHaveBeenCalledTimes(1); + expect(manager.stop).toHaveBeenCalledTimes(3); }); it('collects diagnostics at most once even if called again after teardown, avoiding a clobbered snapshot', async () => { @@ -419,13 +441,12 @@ describe('Cloud Hypervisor runtime backend', () => { // (network-diagnostics.txt regressed to "network namespace not set // up" after a redundant second collectDiagnostics() call). const { manager, deps } = harness(); - manager.execute.mockReset() - .mockResolvedValueOnce({ - requestId: 'network-ready', exitCode: 0, signal: null, timedOut: false, - }) - .mockResolvedValue({ - requestId: 'probe', exitCode: 41, signal: null, timedOut: false, - }); + manager.execute.mockReset().mockImplementation(async (request) => ({ + requestId: request.requestId, + exitCode: request.requestId.startsWith('probe-network-ready-') ? 0 : 41, + signal: null, + timedOut: false, + })); manager.stop.mockImplementation(async (options?: { beforeCleanup?: () => Promise }) => { await options?.beforeCleanup?.(); }); @@ -436,11 +457,11 @@ describe('Cloud Hypervisor runtime backend', () => { await expect(backend.start('/tmp/awf', ['github.com'])) .rejects.toThrow(/connectivity probe failed/); - expect(manager.collectDiagnostics).toHaveBeenCalledTimes(1); + expect(manager.collectDiagnostics).toHaveBeenCalledTimes(3); // Simulates main-action.ts's cleanup handler calling this again. await backend.collectDiagnostics(); - expect(manager.collectDiagnostics).toHaveBeenCalledTimes(1); + expect(manager.collectDiagnostics).toHaveBeenCalledTimes(3); }); it('includes captured guest stdout/stderr in the readiness probe failure message', async () => { @@ -449,14 +470,19 @@ describe('Cloud Hypervisor runtime backend', () => { // stdout/stderr from the probe execution and surface it in the thrown // error for faster live-KVM triage. const { manager, deps } = harness(); - manager.execute.mockReset() - .mockResolvedValueOnce({ - requestId: 'network-ready', exitCode: 0, signal: null, timedOut: false, - }) - .mockImplementationOnce(async (request) => { + manager.execute.mockReset().mockImplementation(async (request) => { + if (request.requestId.startsWith('probe-network-ready-')) { + return { requestId: request.requestId, exitCode: 0, signal: null, timedOut: false }; + } + if (request.requestId.startsWith('probe-netdiag-')) { + return { requestId: request.requestId, exitCode: 0, signal: null, timedOut: false }; + } + if (request.requestId.startsWith('probe-')) { request.stderr?.write('wget: can\'t connect to remote host: Connection refused\n'); - return { requestId: 'probe', exitCode: 1, signal: null, timedOut: false }; - }); + return { requestId: request.requestId, exitCode: 1, signal: null, timedOut: false }; + } + throw new Error(`unexpected request ${request.requestId}`); + }); const backend = new CloudHypervisorRuntimeBackend(config(), deps); await expect(backend.start('/tmp/awf', ['github.com'])).rejects.toThrow( @@ -471,23 +497,22 @@ describe('Cloud Hypervisor runtime backend', () => { // follow-up `ip addr show; ip route show` call is issued only after // the main probe fails, and its output is folded into the error. const { manager, deps } = harness(); - manager.execute.mockReset() - .mockResolvedValueOnce({ - requestId: 'network-ready', exitCode: 0, signal: null, timedOut: false, - }) - .mockImplementationOnce(async () => ({ - requestId: 'probe', exitCode: 1, signal: null, timedOut: false, - })) - .mockImplementationOnce(async (request) => { + manager.execute.mockReset().mockImplementation(async (request) => { + if (request.requestId.startsWith('probe-network-ready-')) { + return { requestId: request.requestId, exitCode: 0, signal: null, timedOut: false }; + } + if (request.requestId.startsWith('probe-netdiag-')) { request.stdout?.write('1: lo: \n---\ndefault via 100.115.75.109 dev eth0\n'); - return { requestId: 'netdiag', exitCode: 0, signal: null, timedOut: false }; - }); + return { requestId: request.requestId, exitCode: 0, signal: null, timedOut: false }; + } + return { requestId: request.requestId, exitCode: 1, signal: null, timedOut: false }; + }); const backend = new CloudHypervisorRuntimeBackend(config(), deps); await expect(backend.start('/tmp/awf', ['github.com'])).rejects.toThrow( /guest network state: 1: lo: /, ); - expect(manager.execute).toHaveBeenCalledTimes(3); + expect(manager.execute).toHaveBeenCalledTimes(9); const netDiagCall = manager.execute.mock.calls[2][0]; expect(netDiagCall.argv).toEqual(['/bin/sh', '-c', 'ip addr show; echo ---; ip route show; echo ---; ip neigh show']); }); @@ -521,10 +546,13 @@ describe('Cloud Hypervisor runtime backend', () => { // The API proxy request must bypass the guest's HTTP(S)_PROXY env vars // (it targets the sidecar directly, not through Squid) and must only // run if the Squid reachability check already succeeded. - expect(script).toMatch(/nc -v -z .* && \(unset .*HTTP_PROXY.*; attempt=1;/); - expect(script).toContain('while ! wget -q -T 20'); + expect(script).toContain("probe_leg 'squid' 'nc -v -z"); + expect(script).toContain("probe_leg 'api-proxy' 'unset HTTP_PROXY"); + expect(script).toContain("|| exit $?"); + expect(script).toContain('wget -q -T 20'); expect(script).toContain('if [ "$attempt" -ge 3 ]'); - expect(script).toContain('API proxy /reflect unavailable after $attempt attempts'); + expect(script).toContain('connectivity leg=$leg exhausted attempts=$attempt'); + expect(script).toContain('permanent-command-failure'); expect(script).toContain('sleep "$delay"'); expect(script).toContain('delay=$((delay * 2))'); }); @@ -559,9 +587,10 @@ describe('Cloud Hypervisor runtime backend', () => { const script = probeCall.argv[2] as string; expect(script).toContain('nc -v -z -w 60'); expect(script).toContain('wget -q -T 20'); - expect(script).toContain('attempt=1; delay=2'); + expect(script).toContain('attempt=1'); + expect(script).toContain('delay=2'); expect(script).toContain('if [ "$attempt" -ge 3 ]'); - expect(probeCall.timeoutMs).toBe(150_000); + expect(probeCall.timeoutMs).toBe(282_000); }); it('passes a beforeCleanup diagnostics hook to stop() on a startup failure, when --diagnostic-logs is set', async () => { @@ -600,7 +629,7 @@ describe('Cloud Hypervisor runtime backend', () => { expect(order).toEqual(['stop-process-terminated', 'collect-diagnostics', 'stop-directory-removed']); }); - it('does not pass a diagnostics hook to stop() on a startup failure when --diagnostic-logs is unset', async () => { + it('preserves boot-attempt diagnostics even when --diagnostic-logs is unset', async () => { const { manager, deps } = harness(); manager.startInstance.mockRejectedValue(new Error('guest disconnected before readiness')); const backend = new CloudHypervisorRuntimeBackend( @@ -610,10 +639,12 @@ describe('Cloud Hypervisor runtime backend', () => { await expect(backend.start('/tmp/awf', ['github.com'])) .rejects.toThrow('guest disconnected before readiness'); - expect(manager.collectDiagnostics).not.toHaveBeenCalled(); + expect(manager.collectDiagnostics).toHaveBeenCalledWith( + '/tmp/awf/diagnostics/cloud-hypervisor/boot-attempt-1', + ); expect(manager.stop).toHaveBeenCalledTimes(1); expect(manager.stop).toHaveBeenCalledWith( - expect.objectContaining({ beforeCleanup: undefined }), + expect.objectContaining({ beforeCleanup: expect.any(Function) }), ); }); @@ -639,20 +670,77 @@ describe('Cloud Hypervisor runtime backend', () => { Reflect.set(missingIp.manager, 'guestIp', undefined); const backend = new CloudHypervisorRuntimeBackend(config(), missingIp.deps); await expect(backend.start('/tmp/awf', ['github.com'])) - .rejects.toThrow(/did not expose the configured guest IP/); + .rejects.toThrow(/did not expose the configured guest network plan/); expect(missingIp.manager.stop).toHaveBeenCalledTimes(1); const dualFailure = harness(); - (dualFailure.infra.revalidate as jest.Mock).mockRejectedValue('topology moved'); + dualFailure.manager.start.mockRejectedValue('VMM configuration failed'); dualFailure.manager.stop.mockRejectedValue('cleanup failed'); const failing = new CloudHypervisorRuntimeBackend(config(), dualFailure.deps); await expect(failing.start('/tmp/awf', ['github.com'])).rejects.toMatchObject({ - message: expect.stringContaining('topology moved'), - cause: 'topology moved', + message: expect.stringContaining('VMM configuration failed'), + cause: 'VMM configuration failed', cleanupCause: 'cleanup failed', }); }); + it('recovers in the same invocation by recreating a VM after a classified readiness failure', async () => { + const { manager, deps } = harness(); + let readinessCalls = 0; + manager.execute.mockReset().mockImplementation(async (request) => { + if (request.requestId.startsWith('probe-network-ready-')) { + readinessCalls += 1; + return { + requestId: request.requestId, + exitCode: readinessCalls === 1 ? 1 : 0, + signal: null, + timedOut: false, + }; + } + return { requestId: request.requestId, exitCode: 0, signal: null, timedOut: false }; + }); + const backend = new CloudHypervisorRuntimeBackend(config(), deps); + + await expect(backend.start('/tmp/awf', ['github.com'])).resolves.toBeUndefined(); + + expect(deps.createManager).toHaveBeenCalledTimes(2); + expect(manager.stop).toHaveBeenCalledTimes(1); + expect(deps.sleep).toHaveBeenCalledWith(5_000); + expect(manager.collectDiagnostics).toHaveBeenCalledWith( + '/tmp/awf/diagnostics/cloud-hypervisor/boot-attempt-1', + ); + }); + + it('fails fast without boot recovery for a permanent connectivity configuration error', async () => { + const { manager, deps } = harness(); + manager.execute.mockReset().mockImplementation(async (request) => ({ + requestId: request.requestId, + exitCode: request.requestId.startsWith('probe-network-ready-') ? 0 : 127, + signal: null, + timedOut: false, + })); + const backend = new CloudHypervisorRuntimeBackend(config(), deps); + + await expect(backend.start('/tmp/awf', ['github.com'])) + .rejects.toThrow(/connectivity configuration is invalid/); + expect(deps.createManager).toHaveBeenCalledTimes(1); + expect(deps.sleep).not.toHaveBeenCalled(); + expect(manager.stop).toHaveBeenCalledTimes(1); + }); + + it('does not retry a failed wrapped command after execution starts', async () => { + const { deps, stdin } = harness(); + const backend = new CloudHypervisorRuntimeBackend(config(), deps); + await backend.start('/tmp/awf', ['github.com']); + + const execution = backend.exec('/tmp/awf', ['github.com']); + stdin.end(); + + await expect(execution).resolves.toEqual({ exitCode: 23 }); + expect(deps.createManager).toHaveBeenCalledTimes(1); + expect(deps.sleep).not.toHaveBeenCalled(); + }); + it('rejects execution before readiness and unsupported TTY execution', async () => { const cold = harness(); await expect(new CloudHypervisorRuntimeBackend(config(), cold.deps).exec( diff --git a/src/cloud-hypervisor-runtime-backend.ts b/src/cloud-hypervisor-runtime-backend.ts index d974c22c8..277e82d37 100644 --- a/src/cloud-hypervisor-runtime-backend.ts +++ b/src/cloud-hypervisor-runtime-backend.ts @@ -52,11 +52,14 @@ const CLOUD_HYPERVISOR_GUEST_HOME = `${CLOUD_HYPERVISOR_GUEST_WORKSPACE}/.awf-ho */ const CLOUD_HYPERVISOR_PROBE_TIMEOUT_MS = 90_000; const CLOUD_HYPERVISOR_GUEST_NETWORK_READY_TIMEOUT_MS = CLOUD_HYPERVISOR_PROBE_TIMEOUT_MS; -const CLOUD_HYPERVISOR_API_PROXY_PROBE_ATTEMPTS = 3; -const CLOUD_HYPERVISOR_API_PROXY_PROBE_INITIAL_DELAY_SECONDS = 2; -// Covers the 60-second Squid probe, three 20-second API proxy attempts, -// their bounded backoff, and nested-KVM scheduling overhead. -const CLOUD_HYPERVISOR_CONNECTIVITY_PROBE_TIMEOUT_MS = 150_000; +const CLOUD_HYPERVISOR_CONNECTIVITY_PROBE_ATTEMPTS = 3; +const CLOUD_HYPERVISOR_CONNECTIVITY_PROBE_INITIAL_DELAY_SECONDS = 2; +const CLOUD_HYPERVISOR_MAX_BOOT_ATTEMPTS = 3; +const CLOUD_HYPERVISOR_BOOT_RETRY_DELAYS_MS = [5_000, 10_000] as const; +const CLOUD_HYPERVISOR_TCP_PROBE_TIMEOUT_SECONDS = 60; +const CLOUD_HYPERVISOR_API_PROXY_PROBE_TIMEOUT_SECONDS = 20; +const CLOUD_HYPERVISOR_CONNECTIVITY_PROBE_BACKOFF_SECONDS = 6; +const CLOUD_HYPERVISOR_CONNECTIVITY_PROBE_SCHEDULING_GRACE_MS = 30_000; const CLOUD_HYPERVISOR_CANCEL_GRACE_MS = 3_000; const CLOUD_HYPERVISOR_MAX_TIMEOUT_MS = 86_400_000; const MCP_GATEWAY_PORT = 8080; @@ -70,6 +73,9 @@ interface CloudHypervisorBackendLogger { interface CloudHypervisorManagerAdapter { readonly paths: Pick; readonly guestIp?: string; + readonly guestGatewayIp?: string; + readonly guestPrefixLength?: number; + readonly guestInterfaceName?: string; readonly networkNamespace?: string; start(): Promise; startInstance(): Promise; @@ -104,6 +110,7 @@ export interface CloudHypervisorRuntimeBackendDependencies { stdout: Writable; stderr: Writable; logger: CloudHypervisorBackendLogger; + sleep(milliseconds: number): Promise; } function defaultDependencies( @@ -146,6 +153,7 @@ function defaultDependencies( stdout: process.stdout, stderr: process.stderr, logger, + sleep: (milliseconds) => new Promise((resolve) => setTimeout(resolve, milliseconds)), }; } @@ -153,6 +161,41 @@ function defaultDependencies( // ts-prune-ignore-next export const cloudHypervisorRuntimeTestHelpers = { defaultDependencies }; +type CloudHypervisorReadinessStage = + | 'guest-network-readiness' + | 'guest-connectivity'; + +/** @internal Structured sentinel used to permit only pre-agent boot retries. */ +// ts-prune-ignore-next +export class CloudHypervisorRetryableReadinessError extends Error { + readonly code = 'CLOUD_HYPERVISOR_RETRYABLE_READINESS'; + readonly retryable = true; + diagnosticDirectories: readonly string[] = []; + + constructor( + readonly stage: CloudHypervisorReadinessStage, + readonly bootAttempt: number, + detail: string, + cause?: unknown, + ) { + super( + `Cloud Hypervisor retryable readiness failure ` + + `(stage=${stage}, boot attempt=${bootAttempt}/${CLOUD_HYPERVISOR_MAX_BOOT_ATTEMPTS}): ${detail}`, + ); + this.name = 'CloudHypervisorRetryableReadinessError'; + if (cause !== undefined) Object.defineProperty(this, 'cause', { value: cause }); + } + + attachDiagnostics(directories: readonly string[], exhausted: boolean): void { + this.diagnosticDirectories = [...directories]; + if (exhausted) { + this.message += + `; boot recovery exhausted after ${CLOUD_HYPERVISOR_MAX_BOOT_ATTEMPTS} attempts` + + (directories.length > 0 ? `; diagnostics: ${directories.join(', ')}` : ''); + } + } +} + /** * Stateful adapter for an explicitly enabled, fail-closed Cloud Hypervisor microVM. * @@ -174,6 +217,8 @@ export class CloudHypervisorRuntimeBackend implements ExternalAgentRuntimeBacken private preflightResult: CloudHypervisorPreflightResult | undefined; private infrastructure: MicrovmInfrastructureSnapshot | undefined; private diagnosticsCollected = false; + private agentExecutionStarted = false; + private readonly failedBootDiagnostics: string[] = []; constructor( private readonly config: WrapperConfig, @@ -230,79 +275,91 @@ export class CloudHypervisorRuntimeBackend implements ExternalAgentRuntimeBacken this.infrastructure = infrastructure; this.identity = this.dependencies.identity(); const exports = await this.dependencies.resolveExports(); - this.manager = this.dependencies.createManager( - cloudHypervisor, - workDir, - infrastructure, - exports, - this.identity, - ); - stage = 'topology-revalidation'; await infrastructure.revalidate(); - stage = 'vmm-configuration'; - await this.manager.start(); - if (!this.manager.guestIp) { - throw new Error('Cloud Hypervisor manager did not expose the configured guest IP'); + for ( + let bootAttempt = 1; + bootAttempt <= CLOUD_HYPERVISOR_MAX_BOOT_ATTEMPTS; + bootAttempt += 1 + ) { + if (bootAttempt > 1) { + const delay = CLOUD_HYPERVISOR_BOOT_RETRY_DELAYS_MS[bootAttempt - 2]; + this.dependencies.logger.warn( + `[cloud-hypervisor] stage=boot-recovery attempt=${bootAttempt}/` + + `${CLOUD_HYPERVISOR_MAX_BOOT_ATTEMPTS} delay=${delay}ms`, + ); + await this.dependencies.sleep(delay); + } + this.manager = this.dependencies.createManager( + cloudHypervisor, + workDir, + infrastructure, + exports, + this.identity, + ); + try { + stage = 'vmm-configuration'; + await this.manager.start(); + const { + guestIp, + guestGatewayIp, + guestPrefixLength, + guestInterfaceName, + } = this.manager; + if ( + !guestIp || + !guestGatewayIp || + guestPrefixLength === undefined || + !guestInterfaceName + ) { + throw new Error( + 'Cloud Hypervisor manager did not expose the configured guest network plan', + ); + } + this.environment = buildCloudHypervisorGuestEnvironment( + this.config, + infrastructure, + guestIp, + exports, + ); + stage = 'guest-boot'; + await this.manager.startInstance(); + stage = 'guest-network-readiness'; + await this.waitForGuestNetworkReady(bootAttempt); + stage = 'guest-connectivity'; + await this.probeGuestConnectivity(bootAttempt); + this.dependencies.logger.info( + `[cloud-hypervisor] stage=ready boot-attempt=${bootAttempt}/` + + `${CLOUD_HYPERVISOR_MAX_BOOT_ATTEMPTS}`, + ); + return; + } catch (error) { + this.dependencies.logger.warn( + `[cloud-hypervisor] stage=${stage} status=failed ` + + `boot-attempt=${bootAttempt}/${CLOUD_HYPERVISOR_MAX_BOOT_ATTEMPTS}: ` + + formatError(error), + ); + const finalAttempt = bootAttempt === CLOUD_HYPERVISOR_MAX_BOOT_ATTEMPTS; + await this.cleanupFailedBootAttempt(bootAttempt, error, finalAttempt); + if ( + error instanceof CloudHypervisorRetryableReadinessError && + !this.agentExecutionStarted && + !finalAttempt + ) { + continue; + } + if (error instanceof CloudHypervisorRetryableReadinessError) { + error.attachDiagnostics(this.failedBootDiagnostics, finalAttempt); + } + this.stopped = true; + throw error; + } } - this.environment = buildCloudHypervisorGuestEnvironment( - this.config, - infrastructure, - this.manager.guestIp, - exports, - ); - stage = 'guest-boot'; - await this.manager.startInstance(); - stage = 'guest-network-readiness'; - await this.waitForGuestNetworkReady(); - stage = 'guest-connectivity'; - await this.probeGuestConnectivity(); - this.dependencies.logger.info('[cloud-hypervisor] stage=ready'); } catch (error) { - this.dependencies.logger.warn( - `[cloud-hypervisor] stage=${stage} status=failed: ${formatError(error)}`, - ); - // Collect diagnostics (guest serial console, Cloud Hypervisor log, - // network plan, counters) once the Cloud Hypervisor process is - // confirmed terminated but before stop() deletes the private run - // directory. Collecting any earlier (before the process actually - // exits) can observe a still-empty guest serial console log, since - // Cloud Hypervisor does not guarantee flushing buffered console - // output to disk until the process exits. Without this hook at all, - // a startup failure would leave nothing for the outer, - // --diagnostic-logs-gated collectDiagnostics() call (invoked later, - // from the CLI's cleanup path) to find — it would silently no-op on - // now-ENOENT paths. - const collectPreCleanupDiagnostics = - this.config.diagnosticLogs && this.manager - ? async () => { - try { - await this.collectDiagnostics(); - } catch (diagnosticsError) { - this.dependencies.logger.warn( - `[cloud-hypervisor] failed to collect pre-cleanup diagnostics: ${formatError(diagnosticsError)}`, - ); - } - } - : undefined; - try { - await this.manager?.stop({ beforeCleanup: collectPreCleanupDiagnostics }); - // Mark the backend stopped so the CLI's own cleanup path (which - // unconditionally calls backend.stop() again after any startup - // failure) doesn't invoke a second, redundant manager.stop() -- - // by this point network/cgroup/run-directory teardown has already - // completed. On a *failed* cleanup here, deliberately leave - // `stopped` false so that outer cleanup call gets a genuine retry - // attempt rather than silently no-op-ing on a botched teardown. - this.stopped = true; - } catch (cleanupError) { - const combined = new Error( - `Cloud Hypervisor startup failed: ${formatError(error)}; ` + - `microVM cleanup also failed: ${formatError(cleanupError)}`, + if (!this.stopped) { + this.dependencies.logger.warn( + `[cloud-hypervisor] stage=${stage} status=failed: ${formatError(error)}`, ); - Object.defineProperty(combined, 'cause', { value: error }); - Object.assign(combined, { cleanupCause: cleanupError }); - throw combined; } throw error; } @@ -330,6 +387,7 @@ export class CloudHypervisorRuntimeBackend implements ExternalAgentRuntimeBacken const timeoutMs = agentTimeoutMinutes === undefined ? undefined : agentTimeoutMinutes * 60_000; + this.agentExecutionStarted = true; const execution = manager.execute({ requestId, argv: ['/bin/sh', '-lc', this.config.agentCommand], @@ -454,7 +512,7 @@ export class CloudHypervisorRuntimeBackend implements ExternalAgentRuntimeBacken await this.manager?.stop({ preserve }); } - private async probeGuestConnectivity(): Promise { + private async probeGuestConnectivity(bootAttempt: number): Promise { const manager = this.manager!; const environment = this.environment!; const identity = this.identity; @@ -474,36 +532,90 @@ export class CloudHypervisorRuntimeBackend implements ExternalAgentRuntimeBacken // case), with the proxy env vars unset so the request reaches the // sidecar directly rather than being routed through Squid. Discovered // via live-KVM validation on the original BusyBox rootfs. - const squidProbe = `nc -v -z -w 60 ${SQUID_IP} 3128`; - const apiProxyProbe = this.config.enableApiProxy - ? ` && (unset HTTP_PROXY HTTPS_PROXY http_proxy https_proxy ALL_PROXY all_proxy; ` + - `attempt=1; delay=${CLOUD_HYPERVISOR_API_PROXY_PROBE_INITIAL_DELAY_SECONDS}; ` + - `while ! wget -q -T 20 -O /dev/null http://${API_PROXY_IP}:10000/reflect; do ` + - `if [ "$attempt" -ge ${CLOUD_HYPERVISOR_API_PROXY_PROBE_ATTEMPTS} ]; then ` + - `echo "API proxy /reflect unavailable after $attempt attempts" >&2; exit 1; fi; ` + - `sleep "$delay"; attempt=$((attempt + 1)); delay=$((delay * 2)); done)` - : ''; - const topologyPeerProbe = Object.values(this.infrastructure?.topologyPeerIps ?? {}) - .map((ip) => ` && nc -v -z -w 60 ${ip} ${MCP_GATEWAY_PORT}`) - .join(''); + const probes = [ + { + name: 'squid', + command: `nc -v -z -w ${CLOUD_HYPERVISOR_TCP_PROBE_TIMEOUT_SECONDS} ` + + `${SQUID_IP} 3128`, + }, + ]; + if (this.config.enableApiProxy) { + probes.push({ + name: 'api-proxy', + command: + `unset HTTP_PROXY HTTPS_PROXY http_proxy https_proxy ALL_PROXY all_proxy; ` + + `wget -q -T ${CLOUD_HYPERVISOR_API_PROXY_PROBE_TIMEOUT_SECONDS} ` + + `-O /dev/null http://${API_PROXY_IP}:10000/reflect`, + }); + } + for (const [name, ip] of Object.entries(this.infrastructure?.topologyPeerIps ?? {})) { + probes.push({ + name: `topology-peer-${name}`, + command: `nc -v -z -w ${CLOUD_HYPERVISOR_TCP_PROBE_TIMEOUT_SECONDS} ` + + `${ip} ${MCP_GATEWAY_PORT}`, + }); + } const topologyPeerCount = Object.keys(this.infrastructure?.topologyPeerIps ?? {}).length; + const probeFunction = [ + 'probe_leg() {', + ' leg="$1"', + ' command="$2"', + ' attempt=1', + ` delay=${CLOUD_HYPERVISOR_CONNECTIVITY_PROBE_INITIAL_DELAY_SECONDS}`, + ' while true; do', + ' if /bin/sh -c "$command"; then', + ' return 0', + ' else', + ' status=$?', + ' fi', + ' echo "connectivity leg=$leg attempt=$attempt exit=$status" >&2', + ' if [ "$status" -eq 126 ] || [ "$status" -eq 127 ]; then', + ' echo "connectivity leg=$leg permanent-command-failure exit=$status" >&2', + ' return "$status"', + ' fi', + ` if [ "$attempt" -ge ${CLOUD_HYPERVISOR_CONNECTIVITY_PROBE_ATTEMPTS} ]; then`, + ' echo "connectivity leg=$leg exhausted attempts=$attempt exit=$status" >&2', + ' return "$status"', + ' fi', + ' sleep "$delay"', + ' attempt=$((attempt + 1))', + ' delay=$((delay * 2))', + ' done', + '}', + ].join('\n'); + const probeCommands = probes + .map(({ name, command }) => + `probe_leg ${shellSingleQuote(name)} ${shellSingleQuote(command)} || exit $?`) + .join('\n'); // Capture (bounded) stdout/stderr so a probe failure can report which // leg failed and why, rather than only a bare exit code -- useful for // diagnosing this compound nc-then-wget command without a full guest // command execution's live output stream. const stdoutCollector = createBoundedOutputCollector(); const stderrCollector = createBoundedOutputCollector(); - const result = await manager.execute({ - requestId: `probe-${process.pid}-${Date.now()}`, - argv: ['/bin/sh', '-c', `set -eu; ${squidProbe}${apiProxyProbe}${topologyPeerProbe}`], - env: environment, - cwd: CLOUD_HYPERVISOR_GUEST_WORKSPACE, - ...identity, - timeoutMs: CLOUD_HYPERVISOR_CONNECTIVITY_PROBE_TIMEOUT_MS + - topologyPeerCount * 60_000, - stdout: stdoutCollector.stream, - stderr: stderrCollector.stream, - }); + let result: GuestExecutionResult; + try { + result = await manager.execute({ + requestId: `probe-${process.pid}-${Date.now()}`, + argv: ['/bin/sh', '-c', `set -u\n${probeFunction}\n${probeCommands}`], + env: environment, + cwd: CLOUD_HYPERVISOR_GUEST_WORKSPACE, + ...identity, + timeoutMs: connectivityProbeTimeoutMs( + topologyPeerCount, + Boolean(this.config.enableApiProxy), + ), + stdout: stdoutCollector.stream, + stderr: stderrCollector.stream, + }); + } catch (error) { + throw new CloudHypervisorRetryableReadinessError( + 'guest-connectivity', + bootAttempt, + `connectivity probe could not execute: ${formatError(error)}`, + error, + ); + } if (result.exitCode !== 0) { const stdout = stdoutCollector.toString().trim(); const stderr = stderrCollector.toString().trim(); @@ -515,9 +627,16 @@ export class CloudHypervisorRuntimeBackend implements ExternalAgentRuntimeBacken ] .filter((part): part is string => Boolean(part)) .join('; '); - throw new Error( + const failure = `Cloud Hypervisor guest connectivity probe failed with exit code ${result.exitCode}` + - (detail ? ` (${detail})` : ''), + (detail ? ` (${detail})` : ''); + if (result.exitCode === 126 || result.exitCode === 127) { + throw new Error(`Cloud Hypervisor guest connectivity configuration is invalid: ${failure}`); + } + throw new CloudHypervisorRetryableReadinessError( + 'guest-connectivity', + bootAttempt, + failure, ); } this.dependencies.logger.info( @@ -531,27 +650,53 @@ export class CloudHypervisorRuntimeBackend implements ExternalAgentRuntimeBacken * loopback up before opening the vsock listener; this bounded check also * fails clearly if a mismatched guest image violates that contract. */ - private async waitForGuestNetworkReady(): Promise { + private async waitForGuestNetworkReady(bootAttempt: number): Promise { const manager = this.manager!; const environment = this.environment!; const identity = this.identity; if (!identity) { throw new Error('guest-network-not-ready: Cloud Hypervisor guest identity is not ready'); } + const guestIp = manager.guestIp; + const guestGatewayIp = manager.guestGatewayIp; + const guestPrefixLength = manager.guestPrefixLength; + const guestInterfaceName = manager.guestInterfaceName; + if ( + !guestIp || + !guestGatewayIp || + guestPrefixLength === undefined || + !guestInterfaceName + ) { + throw new Error('Cloud Hypervisor guest network plan is not ready'); + } + const expectedAddress = `${guestIp}/${guestPrefixLength}`; const script = [ 'attempt=1', 'delay=1', - 'while [ "$attempt" -le 5 ]; do', - " if ip link show dev lo 2>/dev/null | grep -q '[<,]UP[,>]'; then", + `interface=${shellSingleQuote(guestInterfaceName)}`, + `address=${shellSingleQuote(expectedAddress)}`, + `gateway=${shellSingleQuote(guestGatewayIp)}`, + 'while [ "$attempt" -le 10 ]; do', + " if ip link show dev lo 2>/dev/null | grep -q '[<,]UP[,>]' &&", + " ip -4 addr show dev lo 2>/dev/null | grep -F -q '127.0.0.1/8' &&", + " ip link show dev \"$interface\" 2>/dev/null | grep -q '[<,]UP[,>]' &&", + " ip link show dev \"$interface\" 2>/dev/null | grep -q 'state UP' &&", + ' ip -4 addr show dev "$interface" 2>/dev/null | grep -F -q "$address" &&', + ' ip route show default 2>/dev/null | grep -F -q "default via $gateway dev $interface"; then', ' exit 0', ' fi', - ' [ "$attempt" -eq 5 ] && break', + ' [ "$attempt" -eq 10 ] && break', ' sleep "$delay"', ' attempt=$((attempt + 1))', - ' [ "$delay" -ge 4 ] || delay=$((delay * 2))', + ' [ "$delay" -ge 8 ] || delay=$((delay * 2))', 'done', + 'echo "guest data-plane readiness exhausted after $attempt attempts" >&2', + 'ip addr show >&2 || true', + 'echo --- >&2', + 'ip route show >&2 || true', 'exit 1', ].join('\n'); + const stderrCollector = createBoundedOutputCollector(); try { const result = await manager.execute({ requestId: `probe-network-ready-${process.pid}-${Date.now()}`, @@ -560,17 +705,69 @@ export class CloudHypervisorRuntimeBackend implements ExternalAgentRuntimeBacken cwd: CLOUD_HYPERVISOR_GUEST_WORKSPACE, ...identity, timeoutMs: CLOUD_HYPERVISOR_GUEST_NETWORK_READY_TIMEOUT_MS, + stderr: stderrCollector.stream, }); if (result.exitCode === 0) return; - throw new Error(`loopback readiness check exited with code ${result.exitCode}`); - } catch (error) { throw new Error( - `guest-network-not-ready: Cloud Hypervisor guest loopback interface lo ` + - `did not become UP (${formatError(error)})`, + `data-plane readiness check exited with code ${result.exitCode}` + + (stderrCollector.toString().trim() + ? ` (${stderrCollector.toString().trim()})` + : ''), + ); + } catch (error) { + throw new CloudHypervisorRetryableReadinessError( + 'guest-network-readiness', + bootAttempt, + `guest-network-not-ready: expected lo UP with 127.0.0.1/8, ` + + `${guestInterfaceName} state UP with ${expectedAddress}, and default route via ` + + `${guestGatewayIp} (${formatError(error)})`, + error, + ); + } + } + + private async cleanupFailedBootAttempt( + bootAttempt: number, + startupError: unknown, + finalAttempt: boolean, + ): Promise { + const manager = this.manager; + if (!manager) return; + const diagnosticsDirectory = this.getBootDiagnosticsDirectory(bootAttempt); + const collectPreCleanupDiagnostics = async (): Promise => { + try { + await manager.collectDiagnostics(diagnosticsDirectory); + this.failedBootDiagnostics.push(diagnosticsDirectory); + if (finalAttempt) this.diagnosticsCollected = true; + } catch (diagnosticsError) { + this.dependencies.logger.warn( + `[cloud-hypervisor] failed to collect boot-attempt diagnostics ` + + `attempt=${bootAttempt}: ${formatError(diagnosticsError)}`, + ); + } + }; + try { + await manager.stop({ beforeCleanup: collectPreCleanupDiagnostics }); + this.manager = undefined; + this.environment = undefined; + } catch (cleanupError) { + const combined = new Error( + `Cloud Hypervisor startup failed: ${formatError(startupError)}; ` + + `microVM cleanup also failed: ${formatError(cleanupError)}`, ); + Object.defineProperty(combined, 'cause', { value: startupError }); + Object.assign(combined, { cleanupCause: cleanupError }); + throw combined; } } + private getBootDiagnosticsDirectory(bootAttempt: number): string { + const root = this.config.auditDir + ? `${this.config.auditDir}/cloud-hypervisor` + : `${this.config.workDir}/diagnostics/cloud-hypervisor`; + return `${root}/boot-attempt-${bootAttempt}`; + } + /** * Best-effort diagnostic-only helper: on a connectivity probe failure, * capture the guest's own view of its network configuration (interface @@ -664,6 +861,31 @@ function formatError(error: unknown): string { return error instanceof Error ? error.message : String(error); } +function shellSingleQuote(value: string): string { + return `'${value.replace(/'/g, `'\\''`)}'`; +} + +function connectivityProbeTimeoutMs( + topologyPeerCount: number, + enableApiProxy: boolean, +): number { + const tcpLegCount = 1 + topologyPeerCount; + const tcpBudgetSeconds = tcpLegCount * ( + CLOUD_HYPERVISOR_CONNECTIVITY_PROBE_ATTEMPTS * + CLOUD_HYPERVISOR_TCP_PROBE_TIMEOUT_SECONDS + + CLOUD_HYPERVISOR_CONNECTIVITY_PROBE_BACKOFF_SECONDS + ); + const apiProxyBudgetSeconds = enableApiProxy + ? CLOUD_HYPERVISOR_CONNECTIVITY_PROBE_ATTEMPTS * + CLOUD_HYPERVISOR_API_PROXY_PROBE_TIMEOUT_SECONDS + + CLOUD_HYPERVISOR_CONNECTIVITY_PROBE_BACKOFF_SECONDS + : 0; + return ( + (tcpBudgetSeconds + apiProxyBudgetSeconds) * 1_000 + + CLOUD_HYPERVISOR_CONNECTIVITY_PROBE_SCHEDULING_GRACE_MS + ); +} + /** * A bounded, in-memory Writable for capturing a guest command's stdout or * stderr without printing it live (unlike the real agent command, whose diff --git a/src/cloud-hypervisor/manager.ts b/src/cloud-hypervisor/manager.ts index 1b78a88cf..9f704c582 100644 --- a/src/cloud-hypervisor/manager.ts +++ b/src/cloud-hypervisor/manager.ts @@ -188,6 +188,18 @@ export class CloudHypervisorManager { return this.networkPlan?.guestIp; } + get guestGatewayIp(): string | undefined { + return this.networkPlan?.guestGatewayIp; + } + + get guestPrefixLength(): number | undefined { + return this.networkPlan?.guestPrefixLength; + } + + get guestInterfaceName(): string | undefined { + return this.networkPlan?.networkInterface.iface_id; + } + get networkNamespace(): string | undefined { return this.networkPlan?.namespaceName; }