diff --git a/docs/cloud-hypervisor-foundation.md b/docs/cloud-hypervisor-foundation.md index 9237cedd3..912f05a24 100644 --- a/docs/cloud-hypervisor-foundation.md +++ b/docs/cloud-hypervisor-foundation.md @@ -1449,6 +1449,37 @@ It retains 128 events and the first failure independently, using only finite reason/error categories. Later persistence failures report a fixed error without preventing resource cleanup. +Control events carry a sequence number and the validated `invocationId` when +available, including plan rejection before backend entry. Join that ID to the +broker audit and invocation snapshot; run-wide shutdown and undecodable requests +have no invocation ID. `invoke-plan` is an attempt, `invocation-register` precedes +the durable registration write, and only `backend-start` proves the backend was +entered. Missing events alone prove nothing if `dropped` is nonzero, the runtime +predates this instrumentation, or artifact export is incomplete. + +Within an invocation, `vm-launch/*` checks split the shared manager path into +artifact/preflight, recovery, identity, network setup, rootfs preparation, +run-directory/cgroup/artifact staging, VMM spawn, API socket readiness and ping, +confinement, virtiofsd, `vm-create`, `vm-boot`, and `guest-connect`. +These are the actual host operations, not probes or retries. A passed +`vmm-launch` means the spawn call returned, not that the VMM became ready. +A passed `vm-create` does not mean boot succeeded; a passed `vm-boot` does not +mean the guest supervisor connected. Unreached checks remain `not-attempted`; +operations between these gates can still fail at the enclosing +`host-invocation/manager-start` or `instance-start` gate. The first origin +failure is recorded before partial-start cleanup, whose failure is retained +separately as `host-invocation-cleanup/manager-stop`. All these records use the +same durable protected export, even without public-fixture raw guest capture. + +Activation follows the executing artifacts, not the workflow checkout's SHA. +Host control correlation and `vm-launch` checks require an AWF host binary +built with this instrumentation; broker exchange diagnostics require the +corresponding enclave MCP image. Merging source into main does not update a +run pinned to an older published AWF binary/image. Absence of these fields in +such a run cannot identify its failing stage. These host checks need no guest +rootfs rebuild and do not change artifact acceptance, launch policy, or caller +errors. + For script guests, the entrypoint emits bounded JSON lifecycle records on stderr: startup identity, seed copy, output link, working-directory setup, and script execution, with elapsed time and native error category/errno on failure. diff --git a/src/cloud-hypervisor/enclave-executor-types.ts b/src/cloud-hypervisor/enclave-executor-types.ts index 88b9bc46f..d6ba05bfb 100644 --- a/src/cloud-hypervisor/enclave-executor-types.ts +++ b/src/cloud-hypervisor/enclave-executor-types.ts @@ -102,6 +102,8 @@ export interface HostEnclaveExecutorDependencies { runId: string, artifacts: CloudHypervisorPreflightResult, managerDependencies?: CloudHypervisorManagerDependencies, + launchReport?: import('./host-preflight-progress').HostPreflightReporter, + managerStartReport?: import('./host-preflight-progress').HostPreflightReporter, ) => HostEnclaveExecutorManager; readonly mountTmpfs: ( directory: string, diff --git a/src/cloud-hypervisor/host-enclave-executor.test.ts b/src/cloud-hypervisor/host-enclave-executor.test.ts index af3abef02..8b465e042 100644 --- a/src/cloud-hypervisor/host-enclave-executor.test.ts +++ b/src/cloud-hypervisor/host-enclave-executor.test.ts @@ -315,7 +315,8 @@ describe('readBoundedCloudHypervisorEnclaveResult', () => { unmount: async () => { unmounted = true; }, chown: async (filePathValue) => { chownedPaths.push(filePathValue.toString()); }, resolveIdentity: () => ({ uid, gid }), - createManager: (managerConfig, _workDir, profile, _runId, _artifacts, managerDependencies) => { + createManager: (managerConfig, _workDir, profile, _runId, _artifacts, managerDependencies, launchReport) => { + expect(launchReport?.scope).toBe('vm-launch'); managerBinary = managerConfig.cloudHypervisorBinary; workloadProfile = profile; expect(profile.guest?.identity).toEqual({ uid: 65534, gid: 65534 }); @@ -689,7 +690,9 @@ describe('readBoundedCloudHypervisorEnclaveResult', () => { .resolves.toEqual({ outcome: 'success', result: 'true' }); expect(boundedManager).toHaveBeenCalledWith(expect.objectContaining({ cloudHypervisorBinary: expect.stringContaining('/snapshot-'), - }), root, expect.anything(), expect.anything(), expect.anything(), expect.anything()); + }), root, expect.anything(), expect.anything(), expect.anything(), expect.anything(), + expect.objectContaining({ scope: 'vm-launch' }), + expect.objectContaining({ scope: 'host-invocation' })); for (const file of ['cloudHypervisorBinary', 'virtiofsdBinary', 'kernelPath', 'supervisorPath', 'rootfsPath'] as const) { replacement = file; boundedManager.mockClear(); diff --git a/src/cloud-hypervisor/host-enclave-executor.ts b/src/cloud-hypervisor/host-enclave-executor.ts index af1bc43ac..7272d7c14 100644 --- a/src/cloud-hypervisor/host-enclave-executor.ts +++ b/src/cloud-hypervisor/host-enclave-executor.ts @@ -103,7 +103,9 @@ const defaultDependencies: HostEnclaveExecutorDependencies = { createResourceJournal: (run, plan, vmRunId) => HostExecutorResourceJournal.create(run, plan, vmRunId), copySparseFile: copySparseFileWithRsync, removeArtifactSnapshot: async (directory) => fs.rm(directory, { recursive: true, force: true }), - createManager: (config, workDir, profile, runId, artifacts, managerDependencies) => new CloudHypervisorManager( + createManager: ( + config, workDir, profile, runId, artifacts, managerDependencies, launchReport, managerStartReport, + ) => new CloudHypervisorManager( config, workDir, managerDependencies, @@ -112,6 +114,8 @@ const defaultDependencies: HostEnclaveExecutorDependencies = { undefined, artifacts, true, + launchReport, + managerStartReport, ), mountTmpfs: mountBoundedEnclaveStorage, unmount: unmountBoundedEnclaveStorage, @@ -365,7 +369,11 @@ export class CloudHypervisorHostEnclaveExecutorBackend implements HostEnclaveExe return { outcome: 'executor-failure' }; } const diagnostic = new HostExecutorInvocationDiagnostics(this.options.runState, plan); - const report = new HostPreflightReporter('host-invocation', diagnostic.publish); + const report = new HostPreflightReporter( + 'host-invocation', + diagnostic.publish, + (failedReport, _id, error) => diagnostic.classifyFailure(failedReport, error), + ); const check = (id: Parameters[0], operation: () => Promise | T) => diagnostic.check(report, id, operation); const role: CloudHypervisorEnclaveRole = plan.executorKind; @@ -588,6 +596,8 @@ export class CloudHypervisorHostEnclaveExecutorBackend implements HostEnclaveExe enclaveDebugArtifactProtectedRoot: this.options.publicDebugArtifactProtectedRoot, } : managerDependencies, + report.fork('vm-launch'), + report, )); if (filesystemState.aborted) throw new Error('Host executor invocation was cancelled'); await check('manager-start', () => raceInterruption(trackFilesystemWork(manager!.start()))); diff --git a/src/cloud-hypervisor/host-preflight-progress.ts b/src/cloud-hypervisor/host-preflight-progress.ts index ea4331845..53034a518 100644 --- a/src/cloud-hypervisor/host-preflight-progress.ts +++ b/src/cloud-hypervisor/host-preflight-progress.ts @@ -49,7 +49,15 @@ export class HostPreflightCleanupError extends Error { export class HostPreflightReporter { private readonly progress: HostPreflightProgress; - constructor(readonly scope: HostPreflightScope, private readonly publish?: (value: HostPreflightProgress) => void) { + constructor( + readonly scope: HostPreflightScope, + private readonly publish?: (value: HostPreflightProgress) => void, + private readonly onFailure?: ( + report: HostPreflightReporter, + id: HostPreflightCheck, + error: unknown, + ) => void, + ) { this.progress = { schemaVersion: 1, scope, checks: (Object.keys(schema.scopes[scope]) as HostPreflightCheck[]) @@ -68,7 +76,7 @@ export class HostPreflightReporter { } fork(scope: HostPreflightScope): HostPreflightReporter { - return new HostPreflightReporter(scope, this.publish); + return new HostPreflightReporter(scope, this.publish, this.onFailure); } topology(value: MountTopologyEvidence): void { @@ -107,6 +115,7 @@ export class HostPreflightReporter { check.result = 'failed'; check.reason = hostPreflightReason(error); this.emit(); + this.onFailure?.(this, id, error); } private pass(id: HostPreflightCheck): void { diff --git a/src/cloud-hypervisor/host-preflight-schema.ts b/src/cloud-hypervisor/host-preflight-schema.ts index 10cfb19f4..e3ab2133e 100644 --- a/src/cloud-hypervisor/host-preflight-schema.ts +++ b/src/cloud-hypervisor/host-preflight-schema.ts @@ -22,6 +22,25 @@ const boundedExecutorChecks = { export const schema = { "scopes": { + "vm-launch": { + "artifact-preflight": null, + "recovery": null, + "identity": null, + "network": null, + "rootfs": null, + "run-directory": null, + "cgroup": null, + "kernel-stage": null, + "rootfs-stage": null, + "vmm-launch": null, + "api-socket": null, + "api-ping": null, + "confinement": null, + "virtiofsd": null, + "vm-create": null, + "vm-boot": null, + "guest-connect": null + }, "host-invocation": { "policy": null, "filesystem": null, diff --git a/src/cloud-hypervisor/manager-launch-evidence.test.ts b/src/cloud-hypervisor/manager-launch-evidence.test.ts new file mode 100644 index 000000000..8c5fabb18 --- /dev/null +++ b/src/cloud-hypervisor/manager-launch-evidence.test.ts @@ -0,0 +1,239 @@ +import * as fs from 'fs'; +import * as path from 'path'; +import { CloudHypervisorManager } from './manager'; +import { CloudHypervisorGuestChannel } from './guest-execution'; +import { createScriptEnclaveCloudHypervisorProfile } from './workload-profile'; +import { HostPreflightReporter } from './host-preflight-progress'; +import { + HostExecutorInvocationDiagnostics, readHostExecutorInvocationDiagnostics, +} from '../enclave/host-executor-journal'; +import type { HostExecutorInvocationPlan, HostExecutorRunState } from '../enclave/host-executor-server'; +import { + config, dependencies, networkConfig, enclaveExportPlan, processMock, vmmIdentityMock, +} from './manager.test-utils'; + +describe('protected shared VMM launch evidence', () => { + let root: string; + let run: HostExecutorRunState; + let diagnostic: HostExecutorInvocationDiagnostics; + let report: HostPreflightReporter; + + beforeEach(() => { + root = fs.mkdtempSync(path.join(process.cwd(), '.vm-launch-evidence-')); + run = { + runId: 'a'.repeat(32), journalDir: path.join(root, 'journal'), + invocationsDir: path.join(root, 'invocations'), seedsDir: path.join(root, 'seeds'), entries: [], + }; + diagnostic = new HostExecutorInvocationDiagnostics(run, { + runId: run.runId, invocationId: 'b'.repeat(32), entryId: 'script', executorKind: 'script', + } as HostExecutorInvocationPlan); + report = new HostPreflightReporter( + 'host-invocation', + diagnostic.publish, + (failedReport, _id, error) => diagnostic.classifyFailure(failedReport, error), + ); + }); + + afterEach(() => { + jest.restoreAllMocks(); + fs.rmSync(root, { recursive: true, force: true }); + }); + + const failure = () => Object.assign(new Error('PRIVATE_TOKEN /private/repo PRIVATE_SCRIPT'), { + code: 'EACCES', stderr: 'PRIVATE_STDERR', + }); + + it.each(['vmm-launch', 'api-socket', 'api-ping', 'confinement', 'vm-create', 'vm-boot'] as const)( + 'retains %s as the original failure before secondary cleanup/reconcile failures', + async (stage) => { + const original = failure(); + const deps = dependencies(); + const client = deps.createClient('/unused', 1); + if (stage === 'vmm-launch') (deps.launch as jest.Mock).mockImplementation(() => { throw original; }); + if (stage === 'api-socket') (deps.access as jest.Mock).mockRejectedValue(original); + if (stage === 'api-ping') (client.ping as jest.Mock).mockRejectedValue(original); + if (stage === 'confinement') (deps.verifyConfinement as jest.Mock).mockRejectedValue(original); + if (stage === 'vm-create') (client.vmCreate as jest.Mock).mockRejectedValue(original); + if (stage === 'vm-boot') (client.vmBoot as jest.Mock).mockRejectedValue(original); + const manager = new CloudHypervisorManager( + config(), '/tmp/awf', deps, 'evidence', networkConfig(), undefined, undefined, false, + report.fork('vm-launch'), + ); + if (stage === 'vm-boot') { + await diagnostic.check(report, 'manager-start', () => manager.start()); + await expect(diagnostic.check(report, 'instance-start', () => manager.startInstance())).rejects.toBe(original); + await manager.stop(); + } else { + await expect(diagnostic.check(report, 'manager-start', () => manager.start())).rejects.toBe(original); + } + const before = JSON.parse(readHostExecutorInvocationDiagnostics(run)[0].contents); + expect(before).toMatchObject({ + failure: { stage: `vm-launch/${stage}`, reason: 'EACCES', code: 'EACCES' }, + checks: { [`vm-launch/${stage}`]: ['failed', 'EACCES'] }, + }); + if (stage !== 'vm-boot') { + expect(before.checks['vm-launch/vm-boot']).toEqual(['not-attempted', 'none']); + expect(before.checks['host-invocation/instance-start']).toEqual(['not-attempted', 'none']); + } + const cleanup = report.fork('host-invocation-cleanup'); + await expect(diagnostic.check(cleanup, 'manager-stop', () => { + throw Object.assign(new Error('PRIVATE_CLEANUP'), { code: 'EIO' }); + })).rejects.toThrow('PRIVATE_CLEANUP'); + diagnostic.fail(report, 'manager-start', new Error('Host executor lifecycle is unresolved')); + const [file] = readHostExecutorInvocationDiagnostics(run); + const after = JSON.parse(file.contents); + expect(after.failure).toEqual(before.failure); + expect(after.cleanupFailure).toMatchObject({ stage: 'host-invocation-cleanup/manager-stop', code: 'EIO' }); + expect(after.failure.sequence).toBeLessThan(after.cleanupFailure.sequence); + expect(file.contents).not.toMatch(/PRIVATE_|\/private\/repo|stderr/); + expect(Buffer.byteLength(file.contents)).toBeLessThan(64 * 1024); + expect(fs.statSync(path.join(run.journalDir!, 'diagnostics', file.name)).mode & 0o777).toBe(0o600); + }, + ); + + it('distinguishes an unentered manager from a completed create and boot', async () => { + const deps = dependencies(); + const manager = new CloudHypervisorManager( + config(), '/tmp/awf', deps, 'evidence', networkConfig(), undefined, undefined, false, + report.fork('vm-launch'), + ); + const read = () => JSON.parse(readHostExecutorInvocationDiagnostics(run)[0].contents); + expect(read().checks['vm-launch/vmm-launch']).toEqual(['not-attempted', 'none']); + await diagnostic.check(report, 'manager-start', () => manager.start()); + expect(read().checks['vm-launch/vm-create']).toEqual(['passed', 'none']); + expect(read().checks['vm-launch/vm-boot']).toEqual(['not-attempted', 'none']); + await diagnostic.check(report, 'instance-start', () => manager.startInstance()); + expect(read().checks['vm-launch/vm-boot']).toEqual(['passed', 'none']); + expect(read()).not.toHaveProperty('failure'); + await manager.stop(); + }); + + it('leaves preverified artifact preflight not-attempted', async () => { + const deps = dependencies(); + const verifiedArtifacts = await deps.preflight(config()); + const manager = new CloudHypervisorManager( + config(), '/tmp/awf', deps, 'evidence', networkConfig(), undefined, verifiedArtifacts, false, + report.fork('vm-launch'), + ); + await manager.start(); + const snapshot = JSON.parse(readHostExecutorInvocationDiagnostics(run)[0].contents); + expect(snapshot.checks['vm-launch/artifact-preflight']).toEqual(['not-attempted', 'none']); + expect(deps.preflight).toHaveBeenCalledTimes(1); + await manager.stop(); + }); + + it('records a returned process without a PID as a failed VMM launch', async () => { + const deps = dependencies(); + const child = processMock(); + Object.assign(child, { pid: undefined }); + (deps.launch as jest.Mock).mockReturnValue(child); + const manager = new CloudHypervisorManager( + config(), '/tmp/awf', deps, 'evidence', networkConfig(), undefined, undefined, false, + report.fork('vm-launch'), + report, + ); + await expect(diagnostic.check(report, 'manager-start', () => manager.start())) + .rejects.toThrow('Cloud Hypervisor process did not expose a PID'); + expect(JSON.parse(readHostExecutorInvocationDiagnostics(run)[0].contents)).toMatchObject({ + failure: { stage: 'vm-launch/vmm-launch', reason: 'unknown' }, + checks: { 'vm-launch/vmm-launch': ['failed', 'unknown'] }, + }); + }); + + it('distinguishes script enclave no-network setup and boot from guest supervisor connection', async () => { + const deps = dependencies(); + const original = failure(); + jest.spyOn(CloudHypervisorGuestChannel, 'connect').mockRejectedValue(original); + const profile = createScriptEnclaveCloudHypervisorProfile({ + enclaveId: 'script-entry', invocationId: 'b'.repeat(32), + guest: { supervisorBinaryPath: '/opt/awf-supervisor', supervisorSha256: 'a'.repeat(64) }, + exportPlan: enclaveExportPlan('script'), + }); + const manager = new CloudHypervisorManager( + config(), '/tmp/awf', deps, 'evidence', profile, undefined, undefined, true, + report.fork('vm-launch'), + ); + await diagnostic.check(report, 'manager-start', () => manager.start()); + await expect(diagnostic.check(report, 'instance-start', () => manager.startInstance())).rejects.toBe(original); + expect(deps.createEmptyNetworkNamespace).toHaveBeenCalledTimes(1); + expect(deps.reserveNetwork).not.toHaveBeenCalled(); + expect(JSON.parse(readHostExecutorInvocationDiagnostics(run)[0].contents)).toMatchObject({ + failure: { stage: 'vm-launch/guest-connect', reason: 'EACCES' }, + checks: { + 'vm-launch/network': ['passed', 'none'], + 'vm-launch/rootfs': ['passed', 'none'], + 'vm-launch/virtiofsd': ['passed', 'none'], + 'vm-launch/vm-create': ['passed', 'none'], + 'vm-launch/vm-boot': ['passed', 'none'], + 'host-invocation/guest-execute': ['not-attempted', 'none'], + }, + }); + await manager.stop(); + }); + + it('persists the create failure before the manager attempts its own failing partial-start cleanup', async () => { + const deps = dependencies(); + const original = failure(); + let snapshotAtCleanup: unknown; + (deps.createClient('/unused', 1).vmCreate as jest.Mock).mockRejectedValue(original); + (deps.rm as jest.Mock).mockImplementation(async () => { + snapshotAtCleanup = JSON.parse(readHostExecutorInvocationDiagnostics(run)[0].contents); + throw Object.assign(new Error('PRIVATE_CLEANUP'), { code: 'EIO' }); + }); + const manager = new CloudHypervisorManager( + config(), '/tmp/awf', deps, 'evidence', networkConfig(), undefined, undefined, false, + report.fork('vm-launch'), + ); + await expect(diagnostic.check(report, 'manager-start', () => manager.start())) + .rejects.toThrow('partial-start cleanup also failed'); + expect(snapshotAtCleanup).toMatchObject({ + failure: { stage: 'vm-launch/vm-create', reason: 'EACCES', code: 'EACCES' }, + }); + const [file] = readHostExecutorInvocationDiagnostics(run); + const snapshot = JSON.parse(file.contents); + expect(snapshot).toMatchObject({ + failure: { stage: 'vm-launch/vm-create', reason: 'EACCES', code: 'EACCES' }, + cleanupFailure: { stage: 'host-invocation-cleanup/manager-stop', reason: 'unknown' }, + }); + expect(snapshot.failure.sequence).toBeLessThan(snapshot.cleanupFailure.sequence); + expect(file.contents).not.toMatch(/PRIVATE_|\/private\/repo/); + }); + + it('publishes an ungated startup failure before partial cleanup fails', async () => { + const deps = dependencies(); + const original = Object.assign(new Error('original identity validation failed'), { code: 'EIO' }); + const identity = vmmIdentityMock(); + (identity.validateOwnedPaths as jest.Mock).mockRejectedValue(original); + (deps.createVmmIdentity as jest.Mock).mockReturnValue(identity); + (deps.rm as jest.Mock).mockRejectedValue(Object.assign(new Error('cleanup failed'), { code: 'EACCES' })); + const manager = new CloudHypervisorManager( + config(), '/tmp/awf', deps, 'evidence', networkConfig(), undefined, undefined, false, + report.fork('vm-launch'), + report, + ); + + await expect(diagnostic.check(report, 'manager-start', () => manager.start())) + .rejects.toThrow('partial-start cleanup also failed'); + expect(JSON.parse(readHostExecutorInvocationDiagnostics(run)[0].contents)).toMatchObject({ + failure: { stage: 'host-invocation/manager-start', reason: 'EIO', code: 'EIO' }, + cleanupFailure: { stage: 'host-invocation-cleanup/manager-stop' }, + }); + }); + + it('keeps the first cleanup error classification when a retry fails differently', async () => { + const cleanup = report.fork('host-invocation-cleanup'); + const first = Object.assign(new Error('first cleanup failure'), { code: 'EIO' }); + const retry = Object.assign(new Error('retry cleanup failure'), { code: 'EACCES' }); + await expect(cleanup.check('manager-stop', () => Promise.reject(first))).rejects.toBe(first); + await expect(diagnostic.check(cleanup, 'manager-stop', () => Promise.reject(retry))) + .rejects.toBe(retry); + + expect(JSON.parse(readHostExecutorInvocationDiagnostics(run)[0].contents)).toMatchObject({ + cleanupFailure: { + stage: 'host-invocation-cleanup/manager-stop', + reason: 'EIO', + code: 'EIO', + }, + }); + }); +}); diff --git a/src/cloud-hypervisor/manager-start.ts b/src/cloud-hypervisor/manager-start.ts index 8eb4743b4..74ea84cba 100644 --- a/src/cloud-hypervisor/manager-start.ts +++ b/src/cloud-hypervisor/manager-start.ts @@ -43,6 +43,7 @@ import { assertCloudHypervisorWorkloadLaunchable, type CloudHypervisorWorkloadProfile, } from './workload-profile'; +import type { HostPreflightCheck, HostPreflightReporter } from './host-preflight-progress'; export interface CloudHypervisorStartContext { config: CloudHypervisorOptions; @@ -53,6 +54,8 @@ export interface CloudHypervisorStartContext { /** True only for the internal host-executor backend; user runtime selection never sets this. */ allowTrustedEnclaveExecution?: boolean; verifiedArtifacts?: CloudHypervisorPreflightResult; + launchReport?: HostPreflightReporter; + managerStartReport?: HostPreflightReporter; stdoutCapture: BoundedOutputCapture; stderrCapture: BoundedOutputCapture; setNetworkPlan(plan: MicrovmNetworkPlan | undefined): void; @@ -75,14 +78,18 @@ export async function startCloudHypervisor( ): Promise { const { config, workDir, dependencies, paths, workloadProfile, verifiedArtifacts, + managerStartReport, allowTrustedEnclaveExecution, } = context; assertCloudHypervisorWorkloadLaunchable(workloadProfile, allowTrustedEnclaveExecution); const guestConfig = workloadProfile.guest; + const check = (id: HostPreflightCheck, operation: () => Promise | T): Promise | T => + context.launchReport ? context.launchReport.check(id, operation) : operation(); let startupError: unknown; try { - const artifacts = verifiedArtifacts ?? await dependencies.preflight(config); + const artifacts = verifiedArtifacts + ?? await check('artifact-preflight', () => dependencies.preflight(config)); const networkConfig: (CloudHypervisorManagerNetworkConfig & Pick< MicrovmNetworkPlanOptions, 'enclaveAgent' >) | undefined = @@ -119,11 +126,11 @@ export async function startCloudHypervisor( useradd: artifacts.tools.useradd, userdel: artifacts.tools.userdel, }; - await dependencies.cleanupRegistry.reapPending( + await check('recovery', () => dependencies.cleanupRegistry.reapPending( artifacts.tools.ip, artifacts.tools.umount, vmmTools, - ); + )); const guestIdentity = guestConfig?.identity ?? dependencies.resolveIdentity(); const cleanupRecord = await dependencies.cleanupRegistry.createPending( paths, @@ -140,7 +147,7 @@ export async function startCloudHypervisor( releaseAcl: (aclPath) => cleanupRecord.releaseVmmAcl(aclPath), }); context.setVmmIdentity(vmmIdentityManager); - const identity = await vmmIdentityManager.allocate(); + const identity = await check('identity', () => vmmIdentityManager.allocate()); let networkPlan: MicrovmNetworkPlan | undefined; let networkNamespace: string; if (networkConfig) { @@ -178,7 +185,7 @@ export async function startCloudHypervisor( resourceCreated: (resource) => cleanupRecord.captureNetworkResource(resource), }); context.setNetwork(network); - await network.setup(); + await check('network', () => network.setup()); networkNamespace = networkPlan.namespaceName; } else { const namespacePlan = createCloudHypervisorEmptyNetworkNamespacePlan(paths.runId); @@ -189,7 +196,7 @@ export async function startCloudHypervisor( { resourceCreated: (resource) => cleanupRecord.captureNetworkResource(resource) }, ); context.setNetwork(network); - await network.setup(); + await check('network', () => network.setup()); networkNamespace = namespacePlan.namespaceName; } let rootfsSource = artifacts.rootfsPath; @@ -218,10 +225,10 @@ export async function startCloudHypervisor( }, artifacts.tools, (source, destination) => dependencies.copySparseFile(artifacts.tools.rsync, source, destination)); context.setRootfsPreparer(rootfsPreparer); - rootfsSource = await rootfsPreparer.prepare(); + rootfsSource = await check('rootfs', () => rootfsPreparer.prepare()); } - await prepareRunDirectory(dependencies, paths, identity); + await check('run-directory', () => prepareRunDirectory(dependencies, paths, identity)); await cleanupRecord.captureRunDirectory(); const cgroup = dependencies.createCgroup( paths.cgroupPath, @@ -235,10 +242,10 @@ export async function startCloudHypervisor( : { memoryMib: config.memoryMib, vcpuCount: config.vcpuCount }, ); context.setCgroup(cgroup); - await cgroup.setup(); + await check('cgroup', () => cgroup.setup()); await cleanupRecord.captureCgroup(); - await stageArtifact(dependencies, artifacts.kernelPath, paths.kernelPath, 0o400, identity); - await stageArtifact( + await check('kernel-stage', () => stageArtifact(dependencies, artifacts.kernelPath, paths.kernelPath, 0o400, identity)); + await check('rootfs-stage', () => stageArtifact( dependencies, rootfsSource, paths.rootfsPath, @@ -249,7 +256,7 @@ export async function startCloudHypervisor( rootfsSource, paths.rootfsPath, ), - ); + )); await stageDiagnosticFile(dependencies, paths.logPath, identity); await stageDiagnosticFile(dependencies, paths.serialLogPath, identity); await vmmIdentityManager.validateOwnedPaths([ @@ -278,7 +285,7 @@ export async function startCloudHypervisor( await cleanupRecord.prepareProcess( 'vmm', artifacts.cloudHypervisorBinary, paths.apiSocketPath, ); - const child = dependencies.launch(launchCommand.command, [...launchCommand.args], { + const launch = () => dependencies.launch(launchCommand.command, [...launchCommand.args], { reject: false, stdio: ['ignore', 'pipe', 'pipe'], // Cloud Hypervisor directly processes untrusted guest/device input, so @@ -286,30 +293,41 @@ export async function startCloudHypervisor( extendEnv: false, env: { PATH: '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin' }, }); - context.setProcess(child); + const registerLaunchedProcess = (): { child: ExecaChildProcess; pid: number } => { + const launched = launch(); + context.setProcess(launched); + if (launched.pid === undefined) { + throw new Error('Cloud Hypervisor process did not expose a PID'); + } + return { child: launched, pid: launched.pid }; + }; + const launchedProcess = context.launchReport + ? context.launchReport.checkSync('vmm-launch', registerLaunchedProcess) + : registerLaunchedProcess(); + const { child, pid: processId } = launchedProcess; child.stdout?.on('data', (chunk: Buffer | string) => context.stdoutCapture.append(chunk)); child.stderr?.on('data', (chunk: Buffer | string) => context.stderrCapture.append(chunk)); - if (child.pid === undefined) throw new Error('Cloud Hypervisor process did not expose a PID'); - await cgroup.assign(child.pid); - await cleanupRecord.captureProcess('vmm', child.pid); + await cgroup.assign(processId); + await cleanupRecord.captureProcess('vmm', processId); - await waitForApiSocket(dependencies, paths, config.apiTimeoutMs, child); + await check('api-socket', () => waitForApiSocket(dependencies, paths, config.apiTimeoutMs, child)); await vmmIdentityManager.validateOwnedPaths([paths.apiSocketPath]); const client = dependencies.createClient(paths.apiSocketPath, config.apiTimeoutMs); context.setClient(client); - await client.ping(); + await check('api-ping', () => client.ping()); if (child.pid === undefined) { throw new Error('Cloud Hypervisor launcher did not report a PID for confinement verification'); } - context.setConfinementEvidence(await dependencies.verifyConfinement({ - pid: child.pid, + const pid = child.pid; + context.setConfinementEvidence(await check('confinement', () => dependencies.verifyConfinement({ + pid, expectedExecutable: config.cloudHypervisorBinary, identity, launchPolicy: launchCommand.confinementPolicy, networkNamespace, cgroupPath: paths.cgroupPath, cgroupLimits: cgroup.expectedLimits(), - })); + }))); if (guestConfig) { const virtiofsd = dependencies.createVirtiofsdManager( artifacts.virtiofsdBinary, paths.runDirectory, paths.virtiofsdShareDirectory, @@ -320,11 +338,11 @@ export async function startCloudHypervisor( context.setVirtiofsd(virtiofsd); try { context.setFsDevices( - await virtiofsd.start( + await check('virtiofsd', () => virtiofsd.start( guestConfig.exports, guestConfig.mountEnforcement, guestConfig.enclaveResources?.writableStorageBytes, - ), + )), ); await cleanupRecord.captureVirtiofsdResources(); } catch (error) { @@ -335,7 +353,7 @@ export async function startCloudHypervisor( context.getFsDevices().map((device) => device.socketPath), ); } - await client.vmCreate(buildCloudHypervisorVmConfig({ + await check('vm-create', () => client.vmCreate(buildCloudHypervisorVmConfig({ config, paths, networkPlan, @@ -344,13 +362,15 @@ export async function startCloudHypervisor( ? { enclaveResources: guestConfig.enclaveResources } : {}), fsDevices: context.getFsDevices(), - })); + }))); return client; }, networkPlan !== undefined); } catch (error) { startupError = error; } + managerStartReport?.fail('manager-start', startupError); + const startupEvidenceDirectory = path.join( workDir, 'diagnostics', @@ -370,7 +390,11 @@ export async function startCloudHypervisor( ); } try { - await context.stop(); + if (context.launchReport) { + await context.launchReport.fork('host-invocation-cleanup').check('manager-stop', () => context.stop()); + } else { + await context.stop(); + } } catch (cleanupError) { throw new Error( `Cloud Hypervisor startup failed: ${formatError(startupError)}; ` + diff --git a/src/cloud-hypervisor/manager.ts b/src/cloud-hypervisor/manager.ts index 7c60d826f..562aba25a 100644 --- a/src/cloud-hypervisor/manager.ts +++ b/src/cloud-hypervisor/manager.ts @@ -56,7 +56,7 @@ import { } from './confinement-verifier'; import { startCloudHypervisor } from './manager-start'; import { stopCloudHypervisor } from './manager-stop'; -import { HostPreflightCleanupError } from './host-preflight-progress'; +import { HostPreflightCleanupError, type HostPreflightReporter } from './host-preflight-progress'; import { VirtiofsdManager, type VirtiofsdDevice } from './virtiofsd'; import { DurableCloudHypervisorCleanupRegistry, @@ -269,6 +269,8 @@ export class CloudHypervisorManager { legacyGuestConfig?: CloudHypervisorManagerGuestConfig, private readonly verifiedArtifacts?: CloudHypervisorPreflightResult, private readonly allowTrustedEnclaveExecution = false, + private readonly launchReport?: HostPreflightReporter, + private readonly managerStartReport?: HostPreflightReporter, ) { const profile: CloudHypervisorWorkloadProfile = isWorkloadProfile(profileOrNetworkConfig) ? sealCloudHypervisorWorkloadProfile(profileOrNetworkConfig) @@ -313,6 +315,8 @@ export class CloudHypervisorManager { workloadProfile: this.workloadProfile, allowTrustedEnclaveExecution: this.allowTrustedEnclaveExecution, verifiedArtifacts: this.verifiedArtifacts, + launchReport: this.launchReport, + managerStartReport: this.managerStartReport, stdoutCapture: this.stdoutCapture, stderrCapture: this.stderrCapture, setNetworkPlan: (value) => { this.networkPlan = value; }, @@ -332,20 +336,28 @@ export class CloudHypervisorManager { } async startInstance(): Promise { - if (!this.client) throw new Error('Cloud Hypervisor API is not configured'); - await this.client.vmBoot(); + const client = this.client; + if (!client) throw new Error('Cloud Hypervisor API is not configured'); + if (this.launchReport) await this.launchReport.check('vm-boot', () => client.vmBoot()); + else await client.vmBoot(); this.instanceStarted = true; - if (this.workloadProfile.guest) { - if (!this.vmmIdentity) { + const guestConfig = this.workloadProfile.guest; + if (guestConfig) { + const identity = this.vmmIdentity; + if (!identity) { throw new Error('Cloud Hypervisor VMM identity is not configured'); } - await this.vmmIdentity.validateOwnedPaths([this.paths.vsockSocketPath]); - this.guest = await CloudHypervisorGuestChannel.connect( - this.dependencies, - this.paths.vsockSocketPath, - this.workloadProfile.guest.vsockPort ?? CLOUD_HYPERVISOR_GUEST_VSOCK_PORT, - this.config.apiTimeoutMs, - ); + const connect = async (): Promise => { + await identity.validateOwnedPaths([this.paths.vsockSocketPath]); + return CloudHypervisorGuestChannel.connect( + this.dependencies, + this.paths.vsockSocketPath, + guestConfig.vsockPort ?? CLOUD_HYPERVISOR_GUEST_VSOCK_PORT, + this.config.apiTimeoutMs, + ); + }; + this.guest = this.launchReport + ? await this.launchReport.check('guest-connect', connect) : await connect(); } } diff --git a/src/enclave/cloud-hypervisor-lifecycle.test.ts b/src/enclave/cloud-hypervisor-lifecycle.test.ts index c7527d9a4..01b82882f 100644 --- a/src/enclave/cloud-hypervisor-lifecycle.test.ts +++ b/src/enclave/cloud-hypervisor-lifecycle.test.ts @@ -363,13 +363,15 @@ describe('trusted Cloud Hypervisor enclave lifecycle', () => { await startCloudHypervisorEnclaveLifecycle(config, provider, {}); const run = deriveCloudHypervisorEnclaveRunState(config, resolveEnclavePaths(workDir)); const control = new HostExecutorControlDiagnostics(run); - control.record('plan-entry-policy', new Error('PRIVATE_REQUEST_BYTES'), 'denied'); + control.record('plan-entry-policy', new Error('PRIVATE_REQUEST_BYTES'), 'denied', 'b'.repeat(32)); const diagnostic = new HostExecutorInvocationDiagnostics(run, { runId, entryId: 'script', invocationId: 'b'.repeat(32), executorKind: 'script', } as HostExecutorInvocationPlan); const report = new HostPreflightReporter('host-invocation', diagnostic.publish); + const launch = report.fork('vm-launch'); const launchError = Object.assign(new Error('SECRET request/script/repository'), { code: 'EPERM' }); - await expect(diagnostic.check(report, 'manager-start', () => { throw launchError; })).rejects.toBe(launchError); + await expect(diagnostic.check(report, 'manager-start', () => + launch.check('vm-create', () => { throw launchError; }))).rejects.toBe(launchError); const cleanup = report.fork('host-invocation-cleanup'); const cleanupError = Object.assign(new Error('SECRET Bearer token'), { code: 'EIO' }); const directory = path.join(workDir, 'audit', 'diagnostics', 'cloud-hypervisor', 'host-executor'); @@ -377,7 +379,7 @@ describe('trusted Cloud Hypervisor enclave lifecycle', () => { const before = fs.readdirSync(directory).find(name => JSON.parse(fs.readFileSync(path.join(directory, name), 'utf8')).invocationId)!; expect(JSON.parse(fs.readFileSync(path.join(directory, before), 'utf8'))).toMatchObject({ - failure: { stage: 'host-invocation/manager-start', code: 'EPERM' }, + failure: { stage: 'vm-launch/vm-create', code: 'EPERM' }, }); await expect(diagnostic.check(cleanup, 'manager-stop', () => { throw cleanupError; })).rejects.toBe(cleanupError); throw new Error('shutdown uncertain'); @@ -389,14 +391,14 @@ describe('trusted Cloud Hypervisor enclave lifecycle', () => { JSON.parse(fs.readFileSync(path.join(directory, name), 'utf8')).component === 'host-executor-control')!; const controlContents = fs.readFileSync(path.join(directory, controlFile), 'utf8'); expect(JSON.parse(controlContents)).toMatchObject({ - failure: { phase: 'plan-entry-policy', reason: 'denied' }, + failure: { phase: 'plan-entry-policy', reason: 'denied', invocationId: 'b'.repeat(32) }, }); expect(controlContents).not.toContain('PRIVATE_REQUEST_BYTES'); const invocationFile = files.find(name => name !== controlFile)!; const file = path.join(directory, invocationFile); const contents = fs.readFileSync(file, 'utf8'); expect(JSON.parse(contents)).toMatchObject({ - failure: { stage: 'host-invocation/manager-start', code: 'EPERM' }, + failure: { stage: 'vm-launch/vm-create', code: 'EPERM' }, cleanupFailure: { stage: 'host-invocation-cleanup/manager-stop', code: 'EIO' }, }); expect(contents).not.toMatch(/SECRET|Bearer|token|request\/script\/repository/); diff --git a/src/enclave/host-executor-broker.test.ts b/src/enclave/host-executor-broker.test.ts index 0677221fe..1ff8c4989 100644 --- a/src/enclave/host-executor-broker.test.ts +++ b/src/enclave/host-executor-broker.test.ts @@ -371,6 +371,16 @@ describe('finite-disclosure broker → authenticated Unix host → concrete micr 'version', 'type', 'requestId', 'runId', 'entryId', 'invocationId', 'capability', 'executorKind', 'seedId', 'payload', 'schema', 'schemaHash', 'admissionId', ].sort()); + const files = await fs.readdir(path.join(root, 'journal', 'diagnostics')); + const snapshots = await Promise.all(files.map(async (file) => + JSON.parse(await fs.readFile(path.join(root, 'journal', 'diagnostics', file), 'utf8')))); + const control = snapshots.find(snapshot => snapshot.component === 'host-executor-control'); + expect(control.events).toEqual(expect.arrayContaining([ + expect.objectContaining({ phase: 'invoke-plan', invocationId: plans[0].invocationId }), + expect.objectContaining({ phase: 'backend-start', invocationId: plans[0].invocationId }), + expect.objectContaining({ phase: 'settled', invocationId: plans[0].invocationId }), + ])); + expect(control).not.toHaveProperty('failure'); }); it.each(['script', 'agent'] as const)('rejects invalid %s calls before host invocation', async (role) => { @@ -462,8 +472,13 @@ describe('finite-disclosure broker → authenticated Unix host → concrete micr JSON.parse(await fs.readFile(path.join(root, 'journal', 'diagnostics', file), 'utf8')))); expect(snapshots).toEqual(expect.arrayContaining([expect.objectContaining({ component: 'host-executor-control', - failure: expect.objectContaining({ phase: 'plan-entry-policy', reason: 'denied' }), + failure: expect.objectContaining({ + phase: 'plan-entry-policy', reason: 'denied', + invocationId: requests.find(request => request.type === 'invoke')!.invocationId, + }), })])); + expect(snapshots.flatMap(snapshot => snapshot.events ?? []) + .some(event => event.phase === 'backend-start')).toBe(false); }); it.each(['script', 'agent'] as const)('does not disclose raw %s output or errors', async (role) => { diff --git a/src/enclave/host-executor-invocation-diagnostics.test.ts b/src/enclave/host-executor-invocation-diagnostics.test.ts index c3463ec9f..ee5f96f2a 100644 --- a/src/enclave/host-executor-invocation-diagnostics.test.ts +++ b/src/enclave/host-executor-invocation-diagnostics.test.ts @@ -89,17 +89,35 @@ describe('protected host invocation evidence', () => { for (let i = 0; i < 140; i++) diagnostic.record('invoke-plan'); diagnostic.record('backend-failed', Object.assign(new TypeError('PRIVATE_TOKEN PRIVATE_PAYLOAD'), { code: 'EACCES', stderr: 'PRIVATE_STDERR', - })); + }), undefined, plan.invocationId); + diagnostic.record('cleanup-pending', undefined, undefined, 'c'.repeat(32)); diagnostic.record('shutdown'); const [file] = readHostExecutorInvocationDiagnostics(run); const snapshot = JSON.parse(file.contents); expect(snapshot).toMatchObject({ - component: 'host-executor-control', sequence: 142, dropped: 14, - failure: { phase: 'backend-failed', reason: 'EACCES', errorType: 'TypeError' }, + component: 'host-executor-control', sequence: 143, dropped: 15, + failure: { + phase: 'backend-failed', reason: 'EACCES', errorType: 'TypeError', + invocationId: plan.invocationId, sequence: 141, + }, }); expect(snapshot.events).toHaveLength(128); expect(file.contents).not.toMatch(/PRIVATE_|TOKEN|payload|stderr/); expect(Buffer.byteLength(file.contents)).toBeLessThan(64 * 1024); expect(fs.statSync(path.join(run.journalDir!, 'diagnostics', file.name)).mode & 0o777).toBe(0o600); }); + + it('correlates admitted invocations without retaining malformed identifiers', () => { + const diagnostic = new HostExecutorControlDiagnostics(run); + diagnostic.record('invoke-plan', undefined, undefined, plan.invocationId); + diagnostic.record('backend-start', undefined, undefined, plan.invocationId); + diagnostic.record('request-rejected', new Error('PRIVATE_ERROR'), 'denied', 'PRIVATE_ID'); + const snapshot = JSON.parse(readHostExecutorInvocationDiagnostics(run)[0].contents); + expect(snapshot.events.slice(0, 2)).toEqual([ + expect.objectContaining({ phase: 'invoke-plan', invocationId: plan.invocationId, sequence: 1 }), + expect.objectContaining({ phase: 'backend-start', invocationId: plan.invocationId, sequence: 2 }), + ]); + expect(snapshot.failure).not.toHaveProperty('invocationId'); + expect(JSON.stringify(snapshot)).not.toContain('PRIVATE_'); + }); }); diff --git a/src/enclave/host-executor-journal.ts b/src/enclave/host-executor-journal.ts index c1dd00c76..d3fd4f02d 100644 --- a/src/enclave/host-executor-journal.ts +++ b/src/enclave/host-executor-journal.ts @@ -151,6 +151,15 @@ export type HostExecutorControlPhase = | 'backend-complete' | 'backend-failed' | 'cleanup-pending' | 'settled' | 'shutdown' | 'plan-run-identity' | 'plan-entry-policy' | 'plan-static-seed' | 'plan-selector-policy' | 'plan-path'; +interface HostExecutorControlEvent { + phase: string; + elapsedMs: number; + reason: string; + errorType: string; + sequence: number; + invocationId?: string; +} + export class HostExecutorControlDiagnostics { private readonly file: string; private readonly started = Date.now(); @@ -161,10 +170,8 @@ export class HostExecutorControlDiagnostics { runId: string; sequence: number; dropped: number; - events: Array<{ - phase: string; elapsedMs: number; reason: string; errorType: string; - }>; - failure?: { phase: string; elapsedMs: number; reason: string; errorType: string }; + events: HostExecutorControlEvent[]; + failure?: HostExecutorControlEvent; }; constructor(run: HostExecutorRunState) { @@ -184,9 +191,13 @@ export class HostExecutorControlDiagnostics { phase: HostExecutorControlPhase, error?: unknown, rejection?: HostExecutorError, + invocationId?: string, ): void { const event = { phase, elapsedMs: Math.max(0, Date.now() - this.started), + sequence: this.snapshot.sequence + 1, + ...(typeof invocationId === 'string' && HOST_EXECUTOR_ID_PATTERN.test(invocationId) + ? { invocationId } : {}), reason: rejection ?? (error === undefined ? 'none' : hostPreflightReason(error)), errorType: error instanceof TypeError ? 'TypeError' : error instanceof RangeError ? 'RangeError' @@ -273,7 +284,7 @@ export class HostExecutorInvocationDiagnostics { this.classifyFailure(report, error); } - private classifyFailure(report: HostPreflightReporter, error: unknown): void { + classifyFailure(report: HostPreflightReporter, error: unknown): void { const slot = report.scope === 'host-invocation-cleanup' ? 'cleanupFailure' : 'failure'; const original = error instanceof HostPreflightCleanupError ? error.cause : error; const failure = this.snapshot[slot]!; diff --git a/src/enclave/host-executor-server.ts b/src/enclave/host-executor-server.ts index 057902f14..ac6ae1c05 100644 --- a/src/enclave/host-executor-server.ts +++ b/src/enclave/host-executor-server.ts @@ -393,7 +393,7 @@ export async function startHostExecutorServer(options: HostExecutorServerOptions }; const launch = (plan: HostExecutorInvocationPlan): InvocationRecord => { - diagnostics.record('invocation-register'); + diagnostics.record('invocation-register', undefined, undefined, plan.invocationId); const controller = new AbortController(); const record: InvocationRecord = { plan, @@ -415,7 +415,7 @@ export async function startHostExecutorServer(options: HostExecutorServerOptions record.deadline.unref(); renewLease(record); const cleanupFailed = (): void => { - diagnostics.record('cleanup-pending'); + diagnostics.record('cleanup-pending', undefined, undefined, plan.invocationId); clearTimeout(record.deadline); clearTimeout(record.lease); admissionsOpen = false; @@ -428,12 +428,12 @@ export async function startHostExecutorServer(options: HostExecutorServerOptions }; record.completion = Promise.resolve() .then(() => { - diagnostics.record('backend-start'); + diagnostics.record('backend-start', undefined, undefined, plan.invocationId); return backend.execute(plan, controller.signal); }) .then( (outcome) => { - diagnostics.record('backend-complete'); + diagnostics.record('backend-complete', undefined, undefined, plan.invocationId); if (outcome?.cleanupComplete === false) { cleanupFailed(); } else if (outcome && isValidHostExecutorResult(outcome.outcome, outcome.result)) { @@ -443,7 +443,7 @@ export async function startHostExecutorServer(options: HostExecutorServerOptions } }, (error: unknown) => { - diagnostics.record('backend-failed', error); + diagnostics.record('backend-failed', error, undefined, plan.invocationId); cleanupFailed(); }, ).catch(() => { @@ -475,7 +475,7 @@ export async function startHostExecutorServer(options: HostExecutorServerOptions admissionsOpen = false; throw new RequestRejection('closed'); } - diagnostics.record('invoke-plan'); + diagnostics.record('invoke-plan', undefined, undefined, request.invocationId); return launch(deriveHostExecutorInvocationPlan(runState, request)); }; @@ -504,7 +504,7 @@ export async function startHostExecutorServer(options: HostExecutorServerOptions // Settlement is the broker's acknowledgement; the host no longer // retains the result payload afterwards. record.result = undefined; - diagnostics.record('settled'); + diagnostics.record('settled', undefined, undefined, request.invocationId); } }; @@ -549,6 +549,7 @@ export async function startHostExecutorServer(options: HostExecutorServerOptions diagnostics.record( error instanceof RequestRejection ? error.diagnosticPhase ?? 'request-rejected' : 'request-rejected', error, error instanceof RequestRejection ? error.code : undefined, + request.invocationId, ); if (!(error instanceof RequestRejection)) { admissionsOpen = false;