diff --git a/README.md b/README.md index 04bbf0b90..536be2de9 100644 --- a/README.md +++ b/README.md @@ -43,6 +43,7 @@ use `awf --reflect`. It prints the `/reflect` JSON response to stdout. - **Data protection controls**: DLP scanning (`--enable-dlp`), DNS-over-HTTPS, and agent runtime limits (`--agent-timeout`) - **API proxy capabilities**: OpenAI, Anthropic, Copilot, Gemini, and Google Vertex AI targets with rate limits, token steering, Anthropic auto-cache, and `apiProxy.hostedWeb.{claude,codex}` domain policies - **Infrastructure flexibility**: upstream proxy chaining, host service access, Docker-in-Docker, custom mounts, memory limits, and TTY mode +- **Protected output capture**: opt-in, host-only command stdout/stderr capture with attempt and completeness metadata - **Operational tooling**: pre-download images and inspect logs/stats/summaries/audits from live or saved runs ## CLI subcommands @@ -83,6 +84,7 @@ See [GitHub Actions](docs/github_actions.md) for advanced setup and `awf logs su - [API proxy sidecar](docs/api-proxy-sidecar.md) — secure credential management for LLM APIs - [Authentication architecture](docs/authentication-architecture.md) — deep dive into token handling and credential isolation - [Authentication matrix](docs/auth-matrix.md) — supported static, BYOK, and OIDC provider combinations +- [Protected command output capture](docs/protected-command-output.md) — isolated raw stdout/stderr capture and completion metadata - [SSL Bump](docs/ssl-bump.md) — HTTPS content inspection for URL path filtering - [GitHub Actions](docs/github_actions.md) — CI/CD integration and MCP server setup - [Environment variables](docs/environment.md) — passing environment variables to containers diff --git a/containers/agent/entrypoint.sh b/containers/agent/entrypoint.sh index c9a4b8df5..317189b52 100644 --- a/containers/agent/entrypoint.sh +++ b/containers/agent/entrypoint.sh @@ -2,6 +2,13 @@ set -e configure_output_routing() { +if [ "${AWF_CAPTURE_COMMAND_OUTPUT:-}" = "1" ]; then + # Preserve the container streams for command bytes and keep AWF setup + # diagnostics out of both captured streams. + exec 3>&1 4>&2 + exec >/dev/null 2>&1 + return +fi if [ "${AWF_COMMAND_STDOUT_ONLY:-}" != "1" ]; then return fi @@ -12,7 +19,9 @@ exec 1>&2 } run_command_with_stdout() { -if [ "${AWF_COMMAND_STDOUT_ONLY:-}" = "1" ]; then +if [ "${AWF_CAPTURE_COMMAND_OUTPUT:-}" = "1" ]; then + "$@" >&3 2>&4 3>&- 4>&- +elif [ "${AWF_COMMAND_STDOUT_ONLY:-}" = "1" ]; then "$@" >&3 3>&- else "$@" diff --git a/docs/protected-command-output.md b/docs/protected-command-output.md new file mode 100644 index 000000000..4011d1ae6 --- /dev/null +++ b/docs/protected-command-output.md @@ -0,0 +1,38 @@ +# Protected command output capture + +Use `--capture-command-output ` to ask AWF to retain the command's +raw stdout and stderr for a trusted caller: + +```sh +awf --capture-command-output "$RUNNER_TEMP/awf-capture-$GITHUB_RUN_ID" \ + --allow-domains github.com -- your-command +``` + +The directory must be an absolute path whose parent exists; the directory itself +must not already exist. AWF resolves symlinks and checks the candidate against agent-visible mounts, +including custom read-only mounts and Docker host-path-prefix translations. +It fails before starting the command if the directory could be exposed. A +caller must not assume that `$RUNNER_TEMP` or any other chosen path is private. + +AWF creates `metadata.json` and one `.stdout.bin` and `.stderr.bin` file per +runtime attempt with private permissions. Capture is bounded to 64 MiB total by +default; `--capture-command-output-max-bytes ` can lower that limit. +Output continues to drain and appear on the usual console streams after the +limit is reached. Metadata reports observed and retained byte counts, truncation, +log-drain status, per-attempt exit/outcome, command outcome, console-presentation +failures, and teardown outcome. An interrupted capture records incomplete draining. +A capture is `complete` only when the command exit was observed, all +logs drained, no capture failure or truncation occurred, and teardown completed. +A nonzero command exit can still have a complete capture. + +Stdout and stderr are saved separately. Byte order is preserved within each +stream and attempt; AWF does not claim a total order between the two streams. +Capture currently supports non-TTY Compose-managed runtimes (including Docker +and gVisor). TTY, external microVM runtimes, and configurations that expose a +Docker socket to the agent are rejected explicitly. + +AWF leaves the raw files in the requested host directory and does not copy or +publish them. The caller owns parsing, provenance checks, redaction, and +publication. Captured bytes prove only what AWF observed; they do not make +guest-emitted claims authoritative. Treat the files as sensitive and apply the +caller’s retention policy. diff --git a/scripts/ci/compiler-agent-acceptance-v0.28.66.patch b/scripts/ci/compiler-agent-acceptance-v0.28.66.patch index ff1846a9d..7bfaa6a2f 100644 --- a/scripts/ci/compiler-agent-acceptance-v0.28.66.patch +++ b/scripts/ci/compiler-agent-acceptance-v0.28.66.patch @@ -49,7 +49,18 @@ diff --git a/pkg/workflow/enclaves_agent_acceptance_test.go b/pkg/workflow/encla mcp: version: v0.4.33 enclaves: -@@ -196,7 +200,7 @@ +@@ -183,6 +187,10 @@ + require.NoError(t, os.WriteFile(path, []byte(content), 0o600)) + compiler := NewCompiler() + compiler.SetStrictMode(false) ++ require.True(t, compiler.GetSharedActionCache().Set( ++ "github/gh-aw-actions/setup", "v0.92.3", ++ "26e5d7e7d2345ae4c8dfa3d9017ca2ff9bbf2c82", ++ )) + require.NoError(t, compiler.CompileWorkflow(path)) + lockBytes, err := os.ReadFile(stringutil.MarkdownToLockFile(path)) + require.NoError(t, err) +@@ -196,7 +204,7 @@ `\"topologyAttach\":[\"awmg-mcpg\"]`, `--exclude-env AWF_ENCLAVE_MCP_CAPABILITY`, `--exclude-env AWF_CLOUD_HYPERVISOR_ENCLAVE_AGENT_ROOTFS`, diff --git a/src/agent-entrypoint-output.test.ts b/src/agent-entrypoint-output.test.ts index ac1b0515c..1c884b777 100644 --- a/src/agent-entrypoint-output.test.ts +++ b/src/agent-entrypoint-output.test.ts @@ -49,4 +49,28 @@ describe('agent entrypoint output routing', () => { expect(result.stdout).toContain('[entrypoint] Agentic Workflow Firewall'); expect(result.stdout).toContain('command-output'); }); + + it('keeps setup diagnostics out of both command capture streams', () => { + const entrypoint = path.join(__dirname, '..', 'containers', 'agent', 'entrypoint.sh'); + const result = spawnSync( + '/bin/bash', + [ + '-c', + [ + 'source "$1"', + 'export AWF_CAPTURE_COMMAND_OUTPUT=1', + 'configure_output_routing', + 'print_banner', + 'run_command_with_stdout bash -c \'printf stdout-bytes; printf stderr-bytes >&2\'', + ].join('\n'), + 'entrypoint-output-test', + entrypoint, + ], + { encoding: 'utf8' }, + ); + + expect(result.status).toBe(0); + expect(result.stdout).toBe('stdout-bytes'); + expect(result.stderr).toBe('stderr-bytes'); + }); }); diff --git a/src/cli-options.ts b/src/cli-options.ts index a87426e1b..28a75831f 100644 --- a/src/cli-options.ts +++ b/src/cli-options.ts @@ -293,6 +293,14 @@ program 'Allocate a pseudo-TTY (required for interactive tools like Claude Code)', false ) + .option( + '--capture-command-output ', + 'Capture raw stdout/stderr into protected host-only storage (non-TTY Compose runtimes only)', + ) + .option( + '--capture-command-output-max-bytes ', + 'Maximum total bytes retained across command output capture (default: 67108864; max: 67108864)', + ) // -- Network & Security -- .option( diff --git a/src/cli-workflow.ts b/src/cli-workflow.ts index 045eea4ea..54276c498 100644 --- a/src/cli-workflow.ts +++ b/src/cli-workflow.ts @@ -15,6 +15,7 @@ import { import { HostPreflightReporter } from './cloud-hypervisor/host-preflight-progress'; import { isCloudHypervisorEnclaveSelected } from './enclave/cloud-hypervisor-lifecycle'; import { ensureAgentRuntimeStartMarker } from './agent-runtime-start'; +import type { ProtectedCommandOutputCapture } from './protected-command-output-capture'; /** * Dependencies injected into the main workflow. @@ -39,7 +40,8 @@ export interface WorkflowDependencies { workDir: string, allowedDomains: string[], proxyLogsDir?: string, - agentTimeoutMinutes?: number + agentTimeoutMinutes?: number, + commandOutputCapture?: ProtectedCommandOutputCapture, ) => Promise<{ exitCode: number }>; collectDiagnosticLogs?: (workDir: string) => Promise; /** Trusted unified enclave preflight and staging. */ @@ -91,6 +93,7 @@ interface WorkflowLogger { interface WorkflowOptions extends WorkflowCallbacks { logger: WorkflowLogger; performCleanup: () => Promise; + commandOutputCapture?: ProtectedCommandOutputCapture; } /** @@ -363,7 +366,20 @@ export async function runMainWorkflow( if (config.enableApiProxy && config.agentTimeout !== undefined) { ensureAgentRuntimeStartMarker(config.workDir, config.proxyLogsDir); } - const result = await dependencies.runAgentCommand(config.workDir, config.allowedDomains, config.proxyLogsDir, config.agentTimeout); + const result = options.commandOutputCapture + ? await dependencies.runAgentCommand( + config.workDir, + config.allowedDomains, + config.proxyLogsDir, + config.agentTimeout, + options.commandOutputCapture, + ) + : await dependencies.runAgentCommand( + config.workDir, + config.allowedDomains, + config.proxyLogsDir, + config.agentTimeout, + ); // Step 3.5: Collect diagnostic logs before containers are stopped // Must run BEFORE performCleanup() which calls docker compose down -v. diff --git a/src/cloud-hypervisor/runtime-validation.test.ts b/src/cloud-hypervisor/runtime-validation.test.ts index e9fe746d7..86d708d5c 100644 --- a/src/cloud-hypervisor/runtime-validation.test.ts +++ b/src/cloud-hypervisor/runtime-validation.test.ts @@ -16,6 +16,7 @@ const digest = 'a'.repeat(64); function config(overrides: Partial = {}): WrapperConfig { return { + workDir: '/tmp/awf', containerRuntime: 'cloud-hypervisor', networkIsolation: true, legacySecurity: false, diff --git a/src/commands/build-config.test.ts b/src/commands/build-config.test.ts index 1c5d68ace..e395310d4 100644 --- a/src/commands/build-config.test.ts +++ b/src/commands/build-config.test.ts @@ -55,6 +55,19 @@ describe('buildConfig', () => { }))).toThrow(/primary backend "docker"/); }); + it('maps protected command output CLI options into the runtime config', () => { + const config = buildConfig(makeInputs({ + options: { + ...makeInputs().options, + captureCommandOutput: '/var/tmp/awf-output', + captureCommandOutputMaxBytes: '1024', + }, + })); + + expect(config.commandOutputCaptureDir).toBe('/var/tmp/awf-output'); + expect(config.commandOutputCaptureMaxBytes).toBe(1024); + }); + let savedEnv: Partial>; beforeEach(() => { diff --git a/src/commands/build-config.ts b/src/commands/build-config.ts index 8c17b5a03..0644f773b 100644 --- a/src/commands/build-config.ts +++ b/src/commands/build-config.ts @@ -173,6 +173,10 @@ export function buildConfig(inputs: BuildConfigInputs): WrapperConfig { auditDir: (options.auditDir as string | undefined) || process.env.AWF_AUDIT_DIR, sessionStateDir: (options.sessionStateDir as string | undefined) || process.env.AWF_SESSION_STATE_DIR, + commandOutputCaptureDir: options.captureCommandOutput as string | undefined, + commandOutputCaptureMaxBytes: options.captureCommandOutputMaxBytes === undefined + ? undefined + : Number(options.captureCommandOutputMaxBytes), runnerToolCachePath: options.runnerToolCachePath as string | undefined, enableHostAccess: options.enableHostAccess as boolean, networkIsolation: options.networkIsolation as boolean | undefined, diff --git a/src/commands/main-action.ts b/src/commands/main-action.ts index 399f2de05..f25325131 100644 --- a/src/commands/main-action.ts +++ b/src/commands/main-action.ts @@ -65,6 +65,10 @@ import { disconnectEnclaveGithubGateway, } from '../enclave/github-gateway'; import type { WrapperConfig } from '../types'; +import { + prepareProtectedCommandOutputCapture, + type ProtectedCommandOutputCapture, +} from '../protected-command-output-capture'; import { formatCloudHypervisorDockerFallbackWarning, isCloudHypervisorUnsupportedHostError, @@ -557,6 +561,7 @@ export function createMainAction(getOptionValueSource: OptionSourceResolver) { let agentCommandStarted = false; let hostIptablesSetup = false; let externalRuntimeBackend: ExternalAgentRuntimeBackend | undefined; + let commandOutputCapture: ProtectedCommandOutputCapture | undefined; let cloudHypervisorPrimaryPreflightPassed = false; let performCleanup = buildCleanupFn( config, @@ -603,6 +608,13 @@ export function createMainAction(getOptionValueSource: OptionSourceResolver) { await runDindBootstrap(config); } assertPersistentDebugArtifactsIsolated(config); + commandOutputCapture = prepareProtectedCommandOutputCapture(config); + if (commandOutputCapture) { + config.additionalEnv = { + ...config.additionalEnv, + AWF_CAPTURE_COMMAND_OUTPUT: '1', + }; + } // Log config with redacted secrets - remove API keys entirely // to prevent sensitive data from flowing to logger (CodeQL sensitive data logging) @@ -628,12 +640,37 @@ export function createMainAction(getOptionValueSource: OptionSourceResolver) { registerSignalHandlers({ getContainersStarted: () => containersStarted, keepContainers: config.keepContainers, - fastKillAgentContainer: () => ( - externalRuntimeBackend - ? externalRuntimeBackend.stop() - : fastKillAgentContainer() - ), - performCleanup: (signal) => performCleanup(signal), + fastKillAgentContainer: async () => { + if (externalRuntimeBackend) { + await externalRuntimeBackend.stop(); + } else { + await fastKillAgentContainer(); + } + if (commandOutputCapture) { + if (agentCommandStarted) { + await commandOutputCapture.waitForCommandCompletion(); + } else { + commandOutputCapture.finishCommand(undefined, 'cancelled'); + } + } + }, + performCleanup: async (signal) => { + try { + await performCleanup(signal); + commandOutputCapture?.setTeardown('complete'); + } catch (error) { + commandOutputCapture?.setTeardown('failed'); + throw error; + } finally { + if (signal) { + commandOutputCapture?.finishCommand( + undefined, + config.keepContainers && agentCommandStarted ? 'interrupted' : 'cancelled', + ); + } + commandOutputCapture?.close(); + } + }, cleanupRouting: () => cleanupRoutingState(config), }); @@ -676,16 +713,32 @@ export function createMainAction(getOptionValueSource: OptionSourceResolver) { ? adaptExternalRuntimeBackend(externalRuntimeBackend) : undefined; const workflowRunAgentCommand = externalWorkflowDependencies?.runAgentCommand - ?? ((workDir: string, allowedDomains: string[], proxyLogsDir?: string, agentTimeoutMinutes?: number) => - runAgentCommand(workDir, allowedDomains, proxyLogsDir, agentTimeoutMinutes, config.containerRuntime)); + ?? (( + workDir: string, + allowedDomains: string[], + proxyLogsDir?: string, + agentTimeoutMinutes?: number, + capture?: ProtectedCommandOutputCapture, + ) => capture + ? runAgentCommand( + workDir, allowedDomains, proxyLogsDir, agentTimeoutMinutes, config.containerRuntime, capture, + ) + : runAgentCommand( + workDir, allowedDomains, proxyLogsDir, agentTimeoutMinutes, config.containerRuntime, + )); const trackedRunAgentCommand = async ( workDir: string, allowedDomains: string[], proxyLogsDir?: string, agentTimeoutMinutes?: number, + capture?: ProtectedCommandOutputCapture, ) => { agentCommandStarted = true; - const result = await workflowRunAgentCommand(workDir, allowedDomains, proxyLogsDir, agentTimeoutMinutes); + const result = capture + ? await workflowRunAgentCommand( + workDir, allowedDomains, proxyLogsDir, agentTimeoutMinutes, capture, + ) + : await workflowRunAgentCommand(workDir, allowedDomains, proxyLogsDir, agentTimeoutMinutes); if (result.exitCode !== 0) { emitStartupExitMarker(config, startupExitState, { path: 'workflow-return', exitCode: result.exitCode, containersStarted, @@ -759,7 +812,16 @@ export function createMainAction(getOptionValueSource: OptionSourceResolver) { }, { logger, - performCleanup, + performCleanup: async () => { + try { + await performCleanup(); + commandOutputCapture?.setTeardown('complete'); + } catch (error) { + commandOutputCapture?.setTeardown('failed'); + throw error; + } + }, + commandOutputCapture, onHostIptablesSetup: () => { hostIptablesSetup = true; }, @@ -775,6 +837,7 @@ export function createMainAction(getOptionValueSource: OptionSourceResolver) { recordWrite: 'not-attempted', cleanup: 'completed', }); } + commandOutputCapture?.close(); console.error(`Process exiting with code: ${exitCode}`); process.exit(exitCode); return; @@ -798,6 +861,14 @@ export function createMainAction(getOptionValueSource: OptionSourceResolver) { cleanupOutcome = 'failed'; logger.warn('Cleanup after a fatal error failed.', cleanupError); } + if (commandOutputCapture) { + commandOutputCapture.finishCommand( + undefined, + 'failed', + ); + commandOutputCapture.setTeardown(cleanupOutcome === 'completed' ? 'complete' : 'failed'); + commandOutputCapture.close(); + } emitStartupExitMarker(config, startupExitState, { ...exitMarker, cleanup: cleanupOutcome }); cleanupRoutingState(config); const fatalExitCode = findRoutingFailure(error)?.exitCode ?? 1; diff --git a/src/commands/validators/config-assembly.ts b/src/commands/validators/config-assembly.ts index 096bce30f..965e9670d 100644 --- a/src/commands/validators/config-assembly.ts +++ b/src/commands/validators/config-assembly.ts @@ -22,6 +22,7 @@ import { assertNvxSelection, isPrimaryNvxRuntime, } from '../../nvx/runtime-validation'; +import { assertProtectedCommandOutputCaptureSupported } from '../../protected-command-output-capture'; import { assertFilesystemWritePolicyCompatibility } from '../../filesystem-policy'; import { formatCloudHypervisorDockerFallbackWarning, @@ -93,6 +94,12 @@ export function assembleAndValidateConfig( dockerHostPathPrefix: networkOptions.dockerHostPathPrefixResolution.dockerHostPathPrefix, }); + try { + assertProtectedCommandOutputCaptureSupported(config); + } catch (error) { + logger.error(`❌ ${error instanceof Error ? error.message : String(error)}`); + process.exit(1); + } validateInfrastructureOptions(config); try { assertCloudHypervisorSelection(config); diff --git a/src/container-lifecycle.ts b/src/container-lifecycle.ts index 8d9e0fdbc..b45e4c399 100644 --- a/src/container-lifecycle.ts +++ b/src/container-lifecycle.ts @@ -24,6 +24,7 @@ import { checkSquidLogs } from './squid-log-reader'; import { isGvisorRuntime } from './container-runtime'; import { removeConflictingComposeNetworks } from './compose-network-conflicts'; import { captureEnclaveStartupDiagnostics } from './enclave/startup-diagnostics'; +import type { ProtectedCommandOutputCapture, CapturedOutputStream, CommandAttemptOutcome } from './protected-command-output-capture'; const GVISOR_RETRYABLE_AGENT_EXIT_CODES = new Set([134, 139]); const MAX_GVISOR_AGENT_RETRIES = 1; @@ -404,7 +405,14 @@ async function isGvisorStartupCrash(containerName: string): Promise { /** * Runs the agent command in the container and reports any blocked domains */ -export async function runAgentCommand(workDir: string, allowedDomains: string[], proxyLogsDir?: string, agentTimeoutMinutes?: number, containerRuntime?: string): Promise<{ exitCode: number; blockedDomains: string[] }> { +export async function runAgentCommand( + workDir: string, + allowedDomains: string[], + proxyLogsDir?: string, + agentTimeoutMinutes?: number, + containerRuntime?: string, + commandOutputCapture?: ProtectedCommandOutputCapture, +): Promise<{ exitCode: number; blockedDomains: string[] }> { logger.info('Executing agent command...'); try { @@ -415,17 +423,137 @@ export async function runAgentCommand(workDir: string, allowedDomains: string[], ? agentStartTimeMs + agentTimeoutMinutes * 60 * 1000 : undefined; - const executeAgentAttempt = async (logsSince?: string): Promise => { + let attemptNumber = 0; + const executeAgentAttempt = async ( + logsSince?: string, + ): Promise<{ exitCode: number; outcome: Exclude }> => { // Stream logs in real-time using docker logs -f (follow mode) // Run this in the background and wait for the container to exit separately const logArgs = ['logs', ...(logsSince ? ['--since', logsSince] : []), '-f', AGENT_CONTAINER_NAME]; + const currentAttempt = commandOutputCapture ? ++attemptNumber : 0; + commandOutputCapture?.beginAttempt(currentAttempt); const logsProcess = execa('docker', logArgs, { - stdio: 'inherit', + stdio: commandOutputCapture ? ['ignore', 'pipe', 'pipe'] : 'inherit', + ...(commandOutputCapture ? { encoding: null, buffer: false } : {}), reject: false, env: getLocalDockerEnv(), }); + let outputStreamFailed = false; + const forwardOutput = ( + source: NodeJS.ReadableStream | null, + destination: NodeJS.WriteStream, + stream: CapturedOutputStream, + ): Promise => new Promise(resolve => { + if (!source) { + outputStreamFailed = true; + resolve(); + return; + } + let destinationUnavailable = false; + let sourceEnded = false; + let pendingWrites = 0; + let settled = false; + const presentationFailures = new Set<'error' | 'closed' | 'backpressure'>(); + const cleanupDestinationListeners = (): void => { + if (!sourceEnded || pendingWrites !== 0) return; + destination.off('error', onDestinationError); + destination.off('close', onDestinationClose); + }; + const settle = (): void => { + cleanupDestinationListeners(); + if (sourceEnded && (pendingWrites === 0 || destinationUnavailable) && !settled) { + settled = true; + resolve(); + } + }; + const markDestinationUnavailable = (reason: 'error' | 'closed' | 'backpressure'): void => { + if (presentationFailures.has(reason)) return; + presentationFailures.add(reason); + destinationUnavailable = true; + commandOutputCapture!.recordPresentationFailure(stream, reason); + settle(); + }; + const onDestinationError = (): void => markDestinationUnavailable('error'); + const onDestinationClose = (): void => { + if (!destination.writableFinished) markDestinationUnavailable('closed'); + }; + destination.on('error', onDestinationError); + destination.once('close', onDestinationClose); + source.once('end', () => { + sourceEnded = true; + settle(); + }); + source.once('close', () => { + if (!(source as NodeJS.ReadableStream & { readableEnded?: boolean }).readableEnded) { + outputStreamFailed = true; + } + sourceEnded = true; + settle(); + }); + source.on('data', (value: Buffer | string) => { + const chunk = Buffer.isBuffer(value) ? value : Buffer.from(value); + commandOutputCapture!.recordOutput(currentAttempt, stream, chunk); + if (destinationUnavailable) return; + if (destination.destroyed || !destination.writable) { + markDestinationUnavailable('closed'); + return; + } + try { + pendingWrites++; + const writeCompleted = (error?: Error | null): void => { + if (error) markDestinationUnavailable('error'); + pendingWrites--; + settle(); + }; + const canContinue = destination.write(chunk, writeCompleted); + if (!canContinue && !destinationUnavailable) { + markDestinationUnavailable('backpressure'); + } + } catch { + markDestinationUnavailable('error'); + pendingWrites = Math.max(0, pendingWrites - 1); + settle(); + } + }); + source.on('error', () => { + outputStreamFailed = true; + sourceEnded = true; + settle(); + }); + }); + const outputDrainPromises: Promise[] = []; + if (commandOutputCapture) { + outputDrainPromises.push(forwardOutput(logsProcess.stdout, process.stdout, 'stdout')); + outputDrainPromises.push(forwardOutput(logsProcess.stderr, process.stderr, 'stderr')); + } + const recordAttemptCompletion = async ( + exitCode: number, + outcome: Exclude, + ): Promise<{ exitCode: number; outcome: Exclude }> => { + let drainTimeout: ReturnType | undefined; + const drainResult = await Promise.race([ + Promise.all([logsProcess, ...outputDrainPromises]).then(([logsResult]) => ({ + completed: true as const, + logsDrained: !outputStreamFailed && logsResult.exitCode === 0, + })), + new Promise<{ completed: false; logsDrained: false }>(resolve => { + drainTimeout = setTimeout(() => resolve({ completed: false, logsDrained: false }), 5_000); + }), + ]); + if (drainTimeout) clearTimeout(drainTimeout); + if (!drainResult.completed) { + const processWithKill = logsProcess as typeof logsProcess & { kill?: (signal?: string) => void }; + processWithKill.kill?.('SIGTERM'); + logsProcess.stdout?.destroy(); + logsProcess.stderr?.destroy(); + } + const logsDrained = drainResult.logsDrained; + commandOutputCapture?.finishAttempt(currentAttempt, { exitCode, outcome, logsDrained }); + return { exitCode, outcome }; + }; let exitCode: number; + let outcome: Exclude = 'exited'; if (overallDeadlineMs !== undefined) { const remainingMs = overallDeadlineMs - Date.now(); @@ -434,8 +562,7 @@ export async function runAgentCommand(workDir: string, allowedDomains: string[], // No time left (budget exhausted by a previous attempt). logger.warn(`Agent command timed out after ${agentTimeoutMinutes} minutes, stopping container...`); await execa('docker', ['stop', '-t', '10', AGENT_CONTAINER_NAME], { reject: false, env: getLocalDockerEnv() }); - await logsProcess; - return 124; + return recordAttemptCompletion(124, 'timed_out'); } logger.info(`Agent timeout: ${agentTimeoutMinutes} minutes`); @@ -454,6 +581,7 @@ export async function runAgentCommand(workDir: string, allowedDomains: string[], const raceResult = await Promise.race([waitPromise, timeoutPromise]); if (raceResult.type === 'timeout') { + outcome = 'timed_out'; logger.warn(`Agent command timed out after ${agentTimeoutMinutes} minutes, stopping container...`); // Stop the container gracefully (10 second grace period before SIGKILL) await execa('docker', ['stop', '-t', '10', AGENT_CONTAINER_NAME], { reject: false, env: getLocalDockerEnv() }); @@ -470,14 +598,15 @@ export async function runAgentCommand(workDir: string, allowedDomains: string[], } // Wait for the logs process to finish (it should exit automatically when container stops) - await logsProcess; - return exitCode; + return recordAttemptCompletion(exitCode, outcome); }; - let exitCode = await executeAgentAttempt(); + let attemptResult = await executeAgentAttempt(); + let exitCode = attemptResult.exitCode; - if (isGvisorRuntime(containerRuntime)) { + if (isGvisorRuntime(containerRuntime) && !isAgentExternallyKilled()) { for (let attempt = 1; attempt <= MAX_GVISOR_AGENT_RETRIES; attempt++) { + if (isAgentExternallyKilled()) break; if (!GVISOR_RETRYABLE_AGENT_EXIT_CODES.has(exitCode)) { break; } @@ -491,6 +620,7 @@ export async function runAgentCommand(workDir: string, allowedDomains: string[], ); break; } + if (isAgentExternallyKilled()) break; logger.warn( `gVisor agent exited with code ${exitCode} before startup completed; retrying container launch (${attempt}/${MAX_GVISOR_AGENT_RETRIES})...` @@ -501,7 +631,19 @@ export async function runAgentCommand(workDir: string, allowedDomains: string[], stderr: 'inherit', env: getLocalDockerEnv(), }); - exitCode = await executeAgentAttempt(logsSince); + if (isAgentExternallyKilled()) { + await execa('docker', ['stop', '-t', '3', AGENT_CONTAINER_NAME], { + reject: false, + env: getLocalDockerEnv(), + }); + if (commandOutputCapture) { + attemptResult = await executeAgentAttempt(logsSince); + exitCode = attemptResult.exitCode; + } + break; + } + attemptResult = await executeAgentAttempt(logsSince); + exitCode = attemptResult.exitCode; } } @@ -510,9 +652,14 @@ export async function runAgentCommand(workDir: string, allowedDomains: string[], // unreliable and the signal handler will drive the rest of the shutdown. if (isAgentExternallyKilled()) { logger.debug('Agent was externally killed, skipping post-run analysis'); + commandOutputCapture?.finishCommand(exitCode || 143, 'cancelled'); return { exitCode: exitCode || 143, blockedDomains: [] }; } + commandOutputCapture?.finishCommand( + exitCode, + attemptResult.outcome, + ); logger.debug(`Agent exit code: ${exitCode}`); // Small delay to ensure Squid logs are flushed to disk diff --git a/src/enclave/cloud-hypervisor-agent-acceptance.test.ts b/src/enclave/cloud-hypervisor-agent-acceptance.test.ts index c78ff7d3d..24cdb63ba 100644 --- a/src/enclave/cloud-hypervisor-agent-acceptance.test.ts +++ b/src/enclave/cloud-hypervisor-agent-acceptance.test.ts @@ -14,6 +14,7 @@ const sha = '0123456789abcdef0123456789abcdef01234567'; function config(): WrapperConfig { return { + workDir: '/tmp/awf', containerRuntime: 'cloud-hypervisor', networkIsolation: true, enableApiProxy: true, diff --git a/src/enclave/dynamic-delegation-e2e.test.ts b/src/enclave/dynamic-delegation-e2e.test.ts index dee3797d7..b270a58a8 100644 --- a/src/enclave/dynamic-delegation-e2e.test.ts +++ b/src/enclave/dynamic-delegation-e2e.test.ts @@ -764,6 +764,7 @@ describe('dynamic repository enclave delegation service integration suite', () = // Invalid sensitivity const badSensitivity = dynamicEnclavePolicyFixture({ sensitivity: 'invalid-sens' }); const errors = validateEnclavesConfig({ + workDir: makeWorkDir(), enclaves: normalizeEnclavesConfig([ { agent: { model: 'gpt-4o-mini' }, dynamic: badSensitivity as never }, ]), diff --git a/src/enclave/mount-policy.test.ts b/src/enclave/mount-policy.test.ts index ee5816945..2de780431 100644 --- a/src/enclave/mount-policy.test.ts +++ b/src/enclave/mount-policy.test.ts @@ -115,9 +115,9 @@ describe('enclave private-root mount policy', () => { fs.writeFileSync(socket, ''); fs.symlinkSync(socket, alias); expect(findDockerSocketExposingMount({ - ...config(workDir, [`${alias}:/run/docker.sock`]), + ...config(workDir, [`${alias}:/data/docker.sock`]), awfDockerHost: `unix://${socket}`, - })).toBe(`${alias}:/run/docker.sock`); + })).toBe(`${alias}:/data/docker.sock`); }); it('resolves a missing suffix through a symlinked ancestor', () => { diff --git a/src/enclave/mount-policy.ts b/src/enclave/mount-policy.ts index 4b58d300a..a6562960e 100644 --- a/src/enclave/mount-policy.ts +++ b/src/enclave/mount-policy.ts @@ -43,8 +43,10 @@ export function resolvePathThroughExistingAncestor(candidate: string): string { function pathsOverlap(left: string, right: string): boolean { const relativeLeft = path.relative(left, right); const relativeRight = path.relative(right, left); - const leftContainsRight = relativeLeft === '' || (!relativeLeft.startsWith('..') && !path.isAbsolute(relativeLeft)); - const rightContainsLeft = relativeRight === '' || (!relativeRight.startsWith('..') && !path.isAbsolute(relativeRight)); + const leftContainsRight = relativeLeft === '' || + (relativeLeft !== '..' && !relativeLeft.startsWith(`..${path.sep}`) && !path.isAbsolute(relativeLeft)); + const rightContainsLeft = relativeRight === '' || + (relativeRight !== '..' && !relativeRight.startsWith(`..${path.sep}`) && !path.isAbsolute(relativeRight)); return leftContainsRight || rightContainsLeft; } @@ -59,7 +61,7 @@ function daemonVisiblePath(source: string, prefix: string | undefined): string { } /** - * Returns the first custom bind that exposes the Docker socket (or a parent + * Returns the first effective bind that exposes the Docker socket (or a parent * directory containing it) to the primary agent. */ export function findDockerSocketExposingMount(config: WrapperConfig): string | undefined { @@ -72,30 +74,67 @@ export function findDockerSocketExposingMount(config: WrapperConfig): string | u hostLiteral: path.resolve(socketPath), hostResolved: resolvePathThroughExistingAncestor(socketPath), daemonLiteral: path.resolve(daemonVisiblePath(socketPath, config.dockerHostPathPrefix)), - daemonResolved: resolvePathThroughExistingAncestor( - daemonVisiblePath(socketPath, config.dockerHostPathPrefix), - ), + daemonResolved: resolvePathThroughExistingAncestor(daemonVisiblePath(socketPath, config.dockerHostPathPrefix)), })); - for (const volume of config.volumeMounts ?? []) { - const source = mountSource(volume); - if (!source) continue; + const mounts: Array<{ label: string; source: string; target: string; result: string }> = [ + ...collectAgentVisiblePaths(config, process.env, process.cwd()) + .filter(({ label }) => !label.startsWith('custom volume ')) + .map(({ label, source }) => ({ + label, + source, + target: source, + result: label, + })), + ...(config.volumeMounts ?? []).flatMap((volume) => { + const [source, target] = volume.split(':'); + return source && target && path.isAbsolute(source) && path.isAbsolute(target) + ? [{ + label: `custom volume ${volume}`, + source, + target: target.startsWith('/host/') ? target : `/host${target}`, + result: volume, + }] + : []; + }), + ]; + + const isMaskedSocket = (source: string, target: string, socketPath: string): boolean => { + const relativeSocket = path.relative(source, socketPath); + if ( + relativeSocket === '..' + || relativeSocket.startsWith(`..${path.sep}`) + || path.isAbsolute(relativeSocket) + ) return false; + const exposedPath = path.posix.join( + target.startsWith('/host/') ? target : `/host${target}`, + relativeSocket, + ); + return exposedPath === '/host/var/run/docker.sock' || exposedPath === '/host/run/docker.sock'; + }; + + for (const mount of mounts) { + const source = mount.source; + if (!path.isAbsolute(source)) continue; const literalSource = path.resolve(source); const resolvedSource = resolvePathThroughExistingAncestor(source); - const literalDaemonSource = path.resolve( - daemonVisiblePath(source, config.dockerHostPathPrefix), - ); - const daemonSource = resolvePathThroughExistingAncestor( - daemonVisiblePath(source, config.dockerHostPathPrefix), - ); - if (sockets.some( - (socket) => pathsOverlap(literalSource, socket.hostLiteral) - || pathsOverlap(resolvedSource, socket.hostResolved) - || pathsOverlap(literalDaemonSource, socket.daemonLiteral) - || pathsOverlap(daemonSource, socket.daemonResolved), - )) { - return volume; + const literalDaemonSource = path.resolve(daemonVisiblePath(source, config.dockerHostPathPrefix)); + const daemonSource = resolvePathThroughExistingAncestor(daemonVisiblePath(source, config.dockerHostPathPrefix)); + for (const socket of sockets) { + const candidates = [ + { source: literalSource, socket: socket.hostLiteral }, + { source: resolvedSource, socket: socket.hostResolved }, + { source: literalDaemonSource, socket: socket.daemonLiteral }, + { source: daemonSource, socket: socket.daemonResolved }, + ]; + if (candidates.some(({ source: candidateSource, socket: candidateSocket }) => + pathsOverlap(candidateSource, candidateSocket) && + !isMaskedSocket(candidateSource, mount.target, candidateSocket) + )) { + return mount.result; + } } } + return undefined; } @@ -118,6 +157,9 @@ function collectAgentVisiblePaths( { label: 'sbx system tools', source: '/usr/local/bin' }, { label: 'Compose chroot home', source: `${config.workDir}-chroot-home` }, { label: 'AWF work directory', source: config.workDir }, + ...(config.containerWorkDir && path.isAbsolute(config.containerWorkDir) + ? [{ label: 'container working directory', source: config.containerWorkDir }] + : []), ...[...systemDirectories(false), ...systemDirectories(true)].map((source) => ({ label: 'Compose system mount', source, @@ -166,27 +208,33 @@ function collectAgentVisiblePaths( */ export function assertPrivateRootIsolated( config: WrapperConfig, - roots: Pick, + roots: Pick & Partial>, env: NodeJS.ProcessEnv = process.env, cwd = process.cwd(), label = 'enclave', ): void { const privateRoot = resolvePathThroughExistingAncestor(roots.root); + const privateLiteralRoot = path.resolve(roots.root); const privateDaemonRoot = resolvePathThroughExistingAncestor( daemonVisiblePath(roots.root, config.dockerHostPathPrefix), ); + const privateLiteralDaemonRoot = path.resolve(daemonVisiblePath(roots.root, config.dockerHostPathPrefix)); const visiblePaths = [ ...collectAgentVisiblePaths(config, env, cwd), - { label: `${label} ingress`, source: roots.ingressRoot }, + ...(roots.ingressRoot ? [{ label: `${label} ingress`, source: roots.ingressRoot }] : []), ]; for (const visible of visiblePaths) { + const literalVisible = path.resolve(visible.source); const resolvedVisible = resolvePathThroughExistingAncestor(visible.source); + const literalDaemonVisible = path.resolve(daemonVisiblePath(visible.source, config.dockerHostPathPrefix)); const resolvedDaemonVisible = resolvePathThroughExistingAncestor( daemonVisiblePath(visible.source, config.dockerHostPathPrefix), ); if ( - pathsOverlap(privateRoot, resolvedVisible) + pathsOverlap(privateLiteralRoot, literalVisible) + || pathsOverlap(privateRoot, resolvedVisible) + || pathsOverlap(privateLiteralDaemonRoot, literalDaemonVisible) || pathsOverlap(privateDaemonRoot, resolvedDaemonVisible) ) { throw markHostPreflightError(new Error( @@ -235,6 +283,34 @@ export function assertEnclavePrivateRootIsolated( assertPrivateRootIsolated(config, paths, env, cwd, 'enclave'); } +export function assertPrivateCommandOutputRootIsolated( + config: WrapperConfig, + root: string, + env: NodeJS.ProcessEnv = process.env, + cwd = process.cwd(), +): void { + assertPrivateRootIsolated(config, { root }, env, cwd, 'protected command output'); + const resolvedRoot = resolvePathThroughExistingAncestor(root); + const managedDirectories = [ + { label: 'AWF debug artifacts', source: ENCLAVE_DEBUG_ARTIFACT_ROOT }, + { label: 'resolved config publication', source: RESOLVED_CONFIG_PUBLICATION_ROOT }, + { label: 'host executor storage', source: HOST_EXECUTOR_STORAGE_ROOT }, + { label: 'audit directory', source: config.auditDir }, + { label: 'proxy logs directory', source: config.proxyLogsDir }, + { label: 'token log directory', source: config.tokenLogDir }, + ]; + for (const managed of managedDirectories) { + if (!managed.source) continue; + const resolvedManaged = resolvePathThroughExistingAncestor(path.resolve(managed.source)); + if (pathsOverlap(resolvedRoot, resolvedManaged)) { + throw markHostPreflightError(new Error( + `Unsafe protected command output root "${root}" overlaps AWF-managed ${managed.label} ` + + `"${managed.source}"`, + ), 'private-root-overlap'); + } + } +} + /** * Check actual virtio-fs sources, including RUNNER_TEMP/AGENT_TOOLSDIRECTORY * and aliases that the Compose-oriented visible-path union cannot describe. diff --git a/src/enclave/preflight.test.ts b/src/enclave/preflight.test.ts index 028c92757..992e5aa5c 100644 --- a/src/enclave/preflight.test.ts +++ b/src/enclave/preflight.test.ts @@ -468,6 +468,14 @@ describe('validateEnclavesConfig', () => { it.each([ '/var/run/docker.sock:/var/run/docker.sock', + '/var/run/docker.sock:/run/docker.sock', + ])('accepts a custom socket bind covered by the Docker socket mask: %s', (volume) => { + expect(validateEnclavesConfig(config({ volumeMounts: [volume] }))).toEqual([]); + }); + + it.each([ + '/var/run/docker.sock:/data/docker.sock', + '/run/docker.sock:/data/docker.sock', '/var/run:/host-run:ro', ])('rejects a custom bind that exposes the Docker socket: %s', (volume) => { expect(validateEnclavesConfig(config({ volumeMounts: [volume] })).join('\n')) diff --git a/src/protected-command-output-capture.test.ts b/src/protected-command-output-capture.test.ts new file mode 100644 index 000000000..9031d0bf5 --- /dev/null +++ b/src/protected-command-output-capture.test.ts @@ -0,0 +1,454 @@ +import fs from 'fs'; +import * as path from 'path'; +import type { WrapperConfig } from './types'; +import { + prepareProtectedCommandOutputCapture, + protectedCommandOutputCaptureTestHelpers, +} from './protected-command-output-capture'; +import { assertPrivateCommandOutputRootIsolated } from './enclave/mount-policy'; + +describe('protected command output capture', () => { + let testRoot: string; + + beforeEach(() => { + testRoot = fs.mkdtempSync(path.join('/var/tmp', 'awf-output-capture-')); + }); + + it('rejects capture roots under automatically mounted container working directories', () => { + const containerWorkDir = path.join(testRoot, 'container-work'); + fs.mkdirSync(containerWorkDir); + expect(() => assertPrivateCommandOutputRootIsolated( + config({ containerWorkDir }), + path.join(containerWorkDir, 'capture'), + )).toThrow(/container working directory/); + expect(() => prepareProtectedCommandOutputCapture(config({ + commandOutputCaptureDir: path.join(testRoot, 'capture-workdir'), + containerWorkDir: path.join(testRoot, 'capture-workdir'), + }))).toThrow(/container working directory/); + }); + + afterEach(() => { + jest.restoreAllMocks(); + fs.rmSync(testRoot, { recursive: true, force: true }); + }); + + it('rejects a symlink substituted before opening without changing its target', () => { + const directory = path.join(testRoot, 'capture'); + const target = path.join(testRoot, 'target'); + fs.mkdirSync(target, { mode: 0o755 }); + fs.writeFileSync(path.join(target, 'sentinel'), 'untouched'); + const originalMode = fs.statSync(target).mode; + const openSync = fs.openSync; + jest.spyOn(fs, 'openSync').mockImplementation((file, flags, mode) => { + if (file === directory) { + fs.rmdirSync(directory); + fs.symlinkSync(target, directory); + } + return openSync(file, flags, mode); + }); + + expect(() => prepareProtectedCommandOutputCapture(config())).toThrow(); + expect(fs.statSync(target).mode).toBe(originalMode); + expect(fs.readdirSync(target)).toEqual(['sentinel']); + expect(fs.readFileSync(path.join(target, 'sentinel'), 'utf8')).toBe('untouched'); + }); + + it('validates directory ownership through the descriptor before changing permissions', () => { + const fstatSync = fs.fstatSync; + const statSpy = jest.spyOn(fs, 'fstatSync').mockImplementationOnce(fd => ({ + ...fstatSync(fd), + isDirectory: () => true, + uid: (process.getuid?.() ?? 0) + 1, + } as fs.Stats)); + const chmodSpy = jest.spyOn(fs, 'fchmodSync'); + const closeSpy = jest.spyOn(fs, 'closeSync'); + + expect(() => prepareProtectedCommandOutputCapture(config())).toThrow(/unsafe protected output directory/); + expect(chmodSpy).not.toHaveBeenCalled(); + expect(closeSpy).toHaveBeenCalledWith(statSpy.mock.calls[0][0]); + expect(fs.readdirSync(path.join(testRoot, 'capture'))).toEqual([]); + }); + + it('pins permissions and capture files to the opened directory after pathname replacement', () => { + const directory = path.join(testRoot, 'capture'); + const original = path.join(testRoot, 'original'); + const fchmodSync = fs.fchmodSync; + jest.spyOn(fs, 'fchmodSync').mockImplementationOnce((fd, mode) => { + fs.renameSync(directory, original); + fs.mkdirSync(directory, { mode: 0o755 }); + return fchmodSync(fd, mode); + }); + + const capture = prepareProtectedCommandOutputCapture(config())!; + capture.beginAttempt(1); + capture.recordOutput(1, 'stdout', Buffer.from('pinned')); + capture.close(); + + expect(fs.readdirSync(directory)).toEqual([]); + expect(fs.statSync(directory).mode & 0o777).not.toBe(0o700); + expect(fs.statSync(original).mode & 0o777).toBe(0o700); + expect(fs.readFileSync(path.join(original, 'attempt-001.stdout.bin'), 'utf8')).toBe('pinned'); + }); + + it.each(['fstatSync', 'fchmodSync', 'fsyncSync'] as const)( + 'closes all acquired descriptors when %s fails without deleting a replacement directory', + operation => { + const directory = path.join(testRoot, 'capture'); + const original = path.join(testRoot, 'original'); + const failure = new Error(`${operation} failed`); + const openSpy = jest.spyOn(fs, 'openSync'); + const closeSync = fs.closeSync; + const closeSpy = jest.spyOn(fs, 'closeSync').mockImplementationOnce(fd => { + closeSync(fd); + throw new Error('close failed'); + }); + jest.spyOn(fs, operation).mockImplementationOnce(() => { + fs.renameSync(directory, original); + fs.mkdirSync(directory); + fs.writeFileSync(path.join(directory, 'sentinel'), 'untouched'); + throw failure; + }); + + expect(() => prepareProtectedCommandOutputCapture(config())).toThrow(failure); + const acquiredFds = openSpy.mock.results + .filter(result => result.type === 'return') + .map(result => result.value); + for (const fd of acquiredFds) { + expect(closeSpy).toHaveBeenCalledWith(fd); + expect(() => fs.fstatSync(fd)).toThrow(); + } + expect(fs.readFileSync(path.join(directory, 'sentinel'), 'utf8')).toBe('untouched'); + }, + ); + + it('accounts for successful short writes before a later write fails', () => { + let capturedBytes = 0; + let firstWrite = true; + const writer = (_fd: number, _bytes: Buffer, _offset: number, _length: number, _position: number | null): number => { + if (firstWrite) { + firstWrite = false; + return 2; + } + throw new Error('disk full'); + }; + + expect(() => protectedCommandOutputCaptureTestHelpers.writeAll( + 1, + Buffer.from('abcd'), + undefined, + written => { capturedBytes += written; }, + writer, + )).toThrow('disk full'); + expect(capturedBytes).toBe(2); + }); + + it('hands private artifacts back to the sudo invoking identity without widening permissions', () => { + if (process.getuid?.() !== 0) return; + const uid = process.env.SUDO_UID; + const gid = process.env.SUDO_GID; + process.env.SUDO_UID = '12345'; + process.env.SUDO_GID = '12345'; + try { + const capture = prepareProtectedCommandOutputCapture(config())!; + capture.close(); + } finally { + if (uid === undefined) delete process.env.SUDO_UID; + else process.env.SUDO_UID = uid; + if (gid === undefined) delete process.env.SUDO_GID; + else process.env.SUDO_GID = gid; + } + + const directory = path.join(testRoot, 'capture'); + expect(fs.statSync(directory).uid).toBe(12345); + for (const name of ['metadata.json', 'attempt-001.stdout.bin', 'attempt-001.stderr.bin']) { + const stat = fs.statSync(path.join(directory, name)); + expect(stat.uid).toBe(12345); + expect(stat.mode & 0o777).toBe(0o600); + } + expect(fs.statSync(directory).mode & 0o777).toBe(0o700); + }); + + function config(overrides: Partial = {}): WrapperConfig { + return { + workDir: path.join(testRoot, 'work'), + commandOutputCaptureDir: path.join(testRoot, 'capture'), + ...overrides, + } as WrapperConfig; + } + + it('rejects temporary, workspace, custom-mount, and symlink aliases before creating the sink', () => { + expect(() => prepareProtectedCommandOutputCapture(config({ + commandOutputCaptureDir: path.join('/tmp', 'awf-protected-output'), + }))).toThrow(/temporary directory/); + + const captureRoot = path.join(testRoot, 'capture'); + expect(() => assertPrivateCommandOutputRootIsolated( + config(), + captureRoot, + { GITHUB_WORKSPACE: testRoot }, + process.cwd(), + )).toThrow(/workspace/); + expect(() => assertPrivateCommandOutputRootIsolated( + config({ volumeMounts: [`${testRoot}:/data:ro`] }), + captureRoot, + )).toThrow(/custom volume/); + + expect(() => assertPrivateCommandOutputRootIsolated( + config(), + path.join('/tmp', '..awf-capture'), + )).toThrow(/temporary directory/); + + const workspace = path.join(testRoot, 'workspace'); + const external = path.join(testRoot, 'external'); + fs.mkdirSync(workspace); + fs.mkdirSync(external); + fs.symlinkSync(external, path.join(workspace, 'alias')); + expect(() => assertPrivateCommandOutputRootIsolated( + config(), + path.join(workspace, 'alias', 'capture'), + { GITHUB_WORKSPACE: workspace }, + )).toThrow(/workspace/); + + const alias = path.join(testRoot, 'alias'); + fs.symlinkSync(testRoot, alias); + expect(() => assertPrivateCommandOutputRootIsolated( + config({ volumeMounts: [`${testRoot}:/data:ro`] }), + path.join(alias, 'capture'), + )).toThrow(/custom volume/); + }); + + it('validates split-filesystem paths as well as runner-visible mounts', () => { + expect(() => assertPrivateCommandOutputRootIsolated( + config({ + dockerHostPathPrefix: '/host', + volumeMounts: ['/host/var/tmp:/data:ro'], + }), + path.join(testRoot, 'capture'), + )).toThrow(/custom volume/); + }); + + it('rejects AWF-managed artifact and log directories as capture destinations', () => { + expect(() => assertPrivateCommandOutputRootIsolated( + config({ auditDir: testRoot }), + path.join(testRoot, 'capture'), + )).toThrow(/AWF-managed audit directory/); + expect(() => assertPrivateCommandOutputRootIsolated( + config({ proxyLogsDir: testRoot }), + path.join(testRoot, 'capture'), + )).toThrow(/AWF-managed proxy logs directory/); + }); + + it('pre-creates private sinks and preserves exact stream bytes with nonzero command status', () => { + const capture = prepareProtectedCommandOutputCapture(config())!; + expect(fs.existsSync(path.join(testRoot, 'capture', 'attempt-001.stdout.bin'))).toBe(true); + expect(fs.statSync(path.join(testRoot, 'capture', 'attempt-001.stdout.bin')).mode & 0o777).toBe(0o600); + capture.beginAttempt(1); + capture.recordOutput(1, 'stdout', Buffer.from([0x00, 0xff, 0x41])); + capture.recordOutput(1, 'stderr', Buffer.from([0x0a, 0x00, 0x42])); + capture.finishAttempt(1, { exitCode: 9, outcome: 'exited', logsDrained: true }); + capture.finishCommand(9, 'exited'); + capture.setTeardown('complete'); + capture.close(); + + expect(fs.readFileSync(path.join(testRoot, 'capture', 'attempt-001.stdout.bin'))) + .toEqual(Buffer.from([0x00, 0xff, 0x41])); + expect(fs.readFileSync(path.join(testRoot, 'capture', 'attempt-001.stderr.bin'))) + .toEqual(Buffer.from([0x0a, 0x00, 0x42])); + const metadata = JSON.parse(fs.readFileSync(path.join(testRoot, 'capture', 'metadata.json'), 'utf8')); + expect(metadata).toMatchObject({ + status: 'complete', + command: { outcome: 'exited', exitCode: 9 }, + teardown: 'complete', + capturedBytes: 6, + observedBytes: 6, + }); + expect(metadata.ordering).toContain('ordering is guaranteed only within each stream'); + expect(metadata.attempts[0].attemptId).toMatch(new RegExp(`^${capture.invocationId}:1$`)); + }); + + it('reports truncation and incomplete log draining rather than marking a partial capture complete', () => { + const capture = prepareProtectedCommandOutputCapture(config({ + commandOutputCaptureMaxBytes: 4, + }))!; + capture.beginAttempt(1); + capture.recordOutput(1, 'stdout', Buffer.from('abc')); + capture.recordOutput(1, 'stderr', Buffer.from('def')); + capture.finishAttempt(1, { exitCode: 0, outcome: 'exited', logsDrained: false }); + capture.finishCommand(0, 'exited'); + capture.setTeardown('complete'); + capture.close(); + + const directory = path.join(testRoot, 'capture'); + const metadata = JSON.parse(fs.readFileSync(path.join(directory, 'metadata.json'), 'utf8')); + expect(fs.readFileSync(path.join(directory, 'attempt-001.stdout.bin'), 'utf8')).toBe('abc'); + expect(fs.readFileSync(path.join(directory, 'attempt-001.stderr.bin'), 'utf8')).toBe('d'); + expect(metadata).toMatchObject({ + status: 'incomplete', + truncated: true, + capturedBytes: 4, + observedBytes: 6, + attempts: [{ logsDrained: false }], + }); + }); + + it('keeps runtime retries distinct and labels timeout/cancellation as incomplete', () => { + const capture = prepareProtectedCommandOutputCapture(config({ containerRuntime: 'gvisor' }))!; + capture.beginAttempt(1); + capture.recordOutput(1, 'stdout', Buffer.from('first')); + capture.finishAttempt(1, { exitCode: 139, outcome: 'exited', logsDrained: true }); + capture.beginAttempt(2); + capture.recordOutput(2, 'stdout', Buffer.from('second')); + capture.finishAttempt(2, { exitCode: 0, outcome: 'exited', logsDrained: true }); + capture.finishCommand(0, 'exited'); + capture.setTeardown('complete'); + capture.close(); + + const directory = path.join(testRoot, 'capture'); + const metadata = JSON.parse(fs.readFileSync(path.join(directory, 'metadata.json'), 'utf8')); + expect(metadata.status).toBe('complete'); + expect(metadata.attempts.map((attempt: { attemptId: string }) => attempt.attemptId)).toEqual([ + `${capture.invocationId}:1`, + `${capture.invocationId}:2`, + ]); + expect(fs.readFileSync(path.join(directory, 'attempt-001.stdout.bin'), 'utf8')).toBe('first'); + expect(fs.readFileSync(path.join(directory, 'attempt-002.stdout.bin'), 'utf8')).toBe('second'); + + for (const outcome of ['timed_out', 'cancelled'] as const) { + const partialRoot = path.join(testRoot, `capture-${outcome}`); + const partial = prepareProtectedCommandOutputCapture(config({ + commandOutputCaptureDir: partialRoot, + }))!; + partial.beginAttempt(1); + partial.finishAttempt(1, { exitCode: outcome === 'timed_out' ? 124 : 143, outcome, logsDrained: true }); + partial.finishCommand(outcome === 'timed_out' ? 124 : 143, outcome); + partial.setTeardown('complete'); + partial.close(); + const partialMetadata = JSON.parse(fs.readFileSync(path.join(partialRoot, 'metadata.json'), 'utf8')); + expect(partialMetadata).toMatchObject({ + status: 'incomplete', + command: { outcome }, + }); + } + }); + + it('records capture write failures separately from the observed command exit', () => { + const capture = prepareProtectedCommandOutputCapture(config())!; + const internalCapture = capture as unknown as { + attempts: Array<{ streams: { stdout: { fd: number } } }>; + }; + capture.beginAttempt(1); + fs.closeSync(internalCapture.attempts[0].streams.stdout.fd); + capture.recordOutput(1, 'stdout', Buffer.from('not written')); + capture.finishAttempt(1, { exitCode: 0, outcome: 'exited', logsDrained: true }); + capture.finishCommand(0, 'exited'); + capture.setTeardown('complete'); + capture.close(); + + const metadata = JSON.parse(fs.readFileSync(path.join(testRoot, 'capture', 'metadata.json'), 'utf8')); + expect(metadata).toMatchObject({ + status: 'incomplete', + command: { outcome: 'exited', exitCode: 0 }, + captureFailure: expect.stringContaining('write stdout failed'), + }); + }); + + it('waits for attempt output draining before allowing cancellation teardown', async () => { + const capture = prepareProtectedCommandOutputCapture(config())!; + capture.beginAttempt(1); + let drained = false; + const completion = capture.waitForCommandCompletion().then(() => { drained = true; }); + await Promise.resolve(); + expect(drained).toBe(false); + + capture.finishAttempt(1, { exitCode: 143, outcome: 'cancelled', logsDrained: true }); + capture.finishCommand(143, 'cancelled'); + await completion; + expect(drained).toBe(true); + capture.setTeardown('complete'); + capture.close(); + }); + + it('bounds cancellation waiting when command collection never completes', async () => { + jest.useFakeTimers(); + const capture = prepareProtectedCommandOutputCapture(config())!; + capture.beginAttempt(1); + + try { + const completion = capture.waitForCommandCompletion(); + await jest.advanceTimersByTimeAsync(2_000); + await completion; + } finally { + jest.useRealTimers(); + } + capture.setTeardown('complete'); + capture.close(); + + const metadata = JSON.parse(fs.readFileSync(path.join(testRoot, 'capture', 'metadata.json'), 'utf8')); + expect(metadata).toMatchObject({ + status: 'incomplete', + command: { outcome: 'interrupted' }, + attempts: [{ outcome: 'interrupted', logsDrained: false }], + }); + }); + + it('records interrupted commands without claiming their output was drained', () => { + const capture = prepareProtectedCommandOutputCapture(config())!; + capture.beginAttempt(1); + capture.recordOutput(1, 'stdout', Buffer.from('partial')); + capture.finishCommand(undefined, 'interrupted'); + capture.setTeardown('complete'); + capture.close(); + + const metadata = JSON.parse(fs.readFileSync(path.join(testRoot, 'capture', 'metadata.json'), 'utf8')); + expect(metadata).toMatchObject({ + status: 'incomplete', + command: { outcome: 'interrupted' }, + attempts: [{ outcome: 'interrupted', logsDrained: false }], + }); + }); + + it('keeps captured-byte completeness independent from console presentation failure', () => { + const capture = prepareProtectedCommandOutputCapture(config())!; + capture.beginAttempt(1); + capture.recordOutput(1, 'stdout', Buffer.from('raw')); + capture.recordPresentationFailure('stdout', 'error'); + capture.finishAttempt(1, { exitCode: 0, outcome: 'exited', logsDrained: true }); + capture.finishCommand(0, 'exited'); + capture.setTeardown('complete'); + capture.close(); + + const metadata = JSON.parse(fs.readFileSync(path.join(testRoot, 'capture', 'metadata.json'), 'utf8')); + expect(metadata).toMatchObject({ + status: 'complete', + capturedBytes: 3, + presentationFailures: ['stdout: error'], + }); + }); + + it('rejects TTY and external runtime capture requests explicitly', () => { + expect(() => prepareProtectedCommandOutputCapture(config({ tty: true }))).toThrow(/does not support TTY/); + expect(() => prepareProtectedCommandOutputCapture(config({ containerRuntime: 'sbx' }))) + .toThrow(/not supported by the "sbx" runtime/); + expect(() => prepareProtectedCommandOutputCapture(config({ enableDind: true }))) + .toThrow(/agent can access a Docker socket/); + expect(() => prepareProtectedCommandOutputCapture(config({ + volumeMounts: ['/var/run/docker.sock:/data/docker.sock'], + }))).toThrow(/agent can access a Docker socket/); + const maskedSocketMount = prepareProtectedCommandOutputCapture(config({ + volumeMounts: ['/var/run/docker.sock:/run/docker.sock'], + })); + expect(maskedSocketMount).toBeDefined(); + maskedSocketMount?.close(); + expect(() => prepareProtectedCommandOutputCapture(config({ + awfDockerHost: 'unix:///tmp/docker.sock', + }))).toThrow(/agent can access a Docker socket/); + const mountedWorkDir = path.join(testRoot, 'socket-workdir'); + fs.mkdirSync(mountedWorkDir); + expect(() => prepareProtectedCommandOutputCapture(config({ + containerWorkDir: mountedWorkDir, + awfDockerHost: `unix://${path.join(mountedWorkDir, 'docker.sock')}`, + }))).toThrow(/agent can access a Docker socket/); + expect(() => prepareProtectedCommandOutputCapture(config({ commandOutputCaptureDir: 'relative/path' }))) + .toThrow(/absolute path/); + }); +}); diff --git a/src/protected-command-output-capture.ts b/src/protected-command-output-capture.ts new file mode 100644 index 000000000..0b4fa6b25 --- /dev/null +++ b/src/protected-command-output-capture.ts @@ -0,0 +1,432 @@ +import * as fs from 'fs'; +import * as path from 'path'; +import { randomUUID } from 'crypto'; +import type { WrapperConfig } from './types'; +import { resolveArtifactOwner } from './resolved-config-artifact'; +import { + assertPrivateCommandOutputRootIsolated, + findDockerSocketExposingMount, +} from './enclave/mount-policy'; +import { isGvisorRuntime, runtimeUsesComposeAgent } from './container-runtime'; + +export const PROTECTED_COMMAND_OUTPUT_MAX_BYTES = 64 * 1024 * 1024; +const COMMAND_COMPLETION_WAIT_TIMEOUT_MS = 2_000; + +export type CapturedOutputStream = 'stdout' | 'stderr'; +export type CommandAttemptOutcome = + | 'running' | 'exited' | 'timed_out' | 'cancelled' | 'interrupted' | 'failed'; + +interface StreamState { + file: string; + fd: number; + observedBytes: number; + capturedBytes: number; +} + +interface AttemptState { + attemptId: string; + startedAt?: string; + endedAt?: string; + exitCode?: number; + outcome: 'not_started' | CommandAttemptOutcome; + logsDrained?: boolean; + streams: Record; +} + +export interface ProtectedCommandOutputCapture { + readonly invocationId: string; + beginAttempt(attempt: number): void; + recordOutput(attempt: number, stream: CapturedOutputStream, chunk: Buffer): void; + recordPresentationFailure(stream: CapturedOutputStream, reason: 'error' | 'closed' | 'backpressure'): void; + finishAttempt( + attempt: number, + result: { exitCode: number; outcome: Exclude; logsDrained: boolean }, + ): void; + finishCommand(exitCode: number | undefined, outcome: Exclude): void; + waitForCommandCompletion(): Promise; + setTeardown(outcome: 'complete' | 'failed'): void; + close(): void; +} + +interface CaptureMetadata { + schemaVersion: 1; + invocationId: string; + runtime: string; + ordering: string; + maxBytes: number; + status: 'running' | 'complete' | 'incomplete'; + command: { outcome: 'pending' | CommandAttemptOutcome; exitCode?: number }; + teardown: 'pending' | 'complete' | 'failed'; + observedBytes: number; + capturedBytes: number; + truncated: boolean; + captureFailure?: string; + presentationFailures: string[]; + attempts: Array<{ + attemptId: string; + stdout: { file: string; observedBytes: number; capturedBytes: number }; + stderr: { file: string; observedBytes: number; capturedBytes: number }; + startedAt?: string; + endedAt?: string; + exitCode?: number; + outcome: AttemptState['outcome']; + logsDrained?: boolean; + }>; +} + +type SyncWriter = (fd: number, bytes: Buffer, offset: number, length: number, position: number | null) => number; + +function writeAll( + fd: number, + bytes: Buffer, + position?: number, + onWrite?: (bytes: number) => void, + writer: SyncWriter = fs.writeSync, +): void { + let offset = 0; + while (offset < bytes.length) { + const written = writer(fd, bytes, offset, bytes.length - offset, position === undefined ? null : position + offset); + if (written <= 0) throw new Error('zero-byte write'); + offset += written; + onWrite?.(written); + } +} + +function openPrivateFile(file: string): number { + const flags = fs.constants.O_WRONLY | fs.constants.O_CREAT | fs.constants.O_EXCL | (fs.constants.O_NOFOLLOW ?? 0); + const fd = fs.openSync(file, flags, 0o600); + const stat = fs.fstatSync(fd); + if (!stat.isFile() || stat.nlink !== 1 || stat.uid !== (process.getuid?.() ?? stat.uid)) { + fs.closeSync(fd); + throw new Error(`Refusing unsafe protected output file: ${file}`); + } + fs.fchmodSync(fd, 0o600); + return fd; +} + +class ProtectedCommandOutputCaptureSession implements ProtectedCommandOutputCapture { + readonly invocationId = randomUUID(); + private readonly metadataFd: number; + private readonly directoryFd: number; + private readonly attempts: AttemptState[]; + private currentAttempt?: number; + private commandOutcome: CaptureMetadata['command']['outcome'] = 'pending'; + private commandExitCode?: number; + private teardown: CaptureMetadata['teardown'] = 'pending'; + private truncated = false; + private captureFailure?: string; + private readonly presentationFailures = new Set(); + private closed = false; + private metadataInitialized = false; + private commandStarted = false; + private resolveCommandCompletion!: () => void; + private readonly commandCompletion = new Promise(resolve => { + this.resolveCommandCompletion = resolve; + }); + + constructor( + private readonly directory: string, + private readonly runtime: string, + private readonly maxBytes: number, + maxAttempts: number, + ) { + fs.mkdirSync(directory, { mode: 0o700 }); + const directoryFd = fs.openSync( + directory, + fs.constants.O_RDONLY | fs.constants.O_DIRECTORY | (fs.constants.O_NOFOLLOW ?? 0), + ); + + const openedFds: number[] = [directoryFd]; + let metadataFd: number | undefined; + const attempts: AttemptState[] = []; + try { + const dirStat = fs.fstatSync(directoryFd); + if (!dirStat.isDirectory() || dirStat.uid !== (process.getuid?.() ?? dirStat.uid)) { + throw new Error(`Refusing unsafe protected output directory: ${directory}`); + } + fs.fchmodSync(directoryFd, 0o700); + metadataFd = openPrivateFile(`/proc/self/fd/${directoryFd}/metadata.json`); + openedFds.push(metadataFd); + for (let index = 1; index <= maxAttempts; index++) { + const prefix = `attempt-${String(index).padStart(3, '0')}`; + const stdoutFile = `${prefix}.stdout.bin`; + const stderrFile = `${prefix}.stderr.bin`; + const stdoutPath = `/proc/self/fd/${directoryFd}/${stdoutFile}`; + const stdoutFd = openPrivateFile(stdoutPath); + openedFds.push(stdoutFd); + const stderrPath = `/proc/self/fd/${directoryFd}/${stderrFile}`; + const stderrFd = openPrivateFile(stderrPath); + openedFds.push(stderrFd); + attempts.push({ + attemptId: `${this.invocationId}:${index}`, + outcome: 'not_started', + streams: { + stdout: { file: stdoutFile, fd: stdoutFd, observedBytes: 0, capturedBytes: 0 }, + stderr: { file: stderrFile, fd: stderrFd, observedBytes: 0, capturedBytes: 0 }, + }, + }); + } + this.directoryFd = directoryFd; + this.metadataFd = metadataFd; + this.attempts = attempts; + this.writeMetadata(); + this.metadataInitialized = true; + } catch (error) { + for (const fd of openedFds.reverse()) { + try { + fs.closeSync(fd); + } catch { + // Keep closing remaining descriptors without masking the initialization error. + } + } + // The pathname may have been replaced; never recursively delete it on failure. + throw error; + } + } + + beginAttempt(attempt: number): void { + const state = this.getAttempt(attempt); + state.startedAt = new Date().toISOString(); + state.outcome = 'running'; + this.commandStarted = true; + this.currentAttempt = attempt; + this.writeMetadata(); + } + + recordOutput(attempt: number, stream: CapturedOutputStream, chunk: Buffer): void { + if (this.closed) return; + const state = this.getAttempt(attempt).streams[stream]; + state.observedBytes += chunk.length; + if (this.captureFailure) return; + + const remaining = Math.max(0, this.maxBytes - this.totalCapturedBytes()); + const length = Math.min(chunk.length, remaining); + if (length < chunk.length) this.truncated = true; + if (length === 0) return; + + try { + writeAll(state.fd, chunk.subarray(0, length), undefined, written => { + state.capturedBytes += written; + }); + } catch (error) { + this.captureFailure = `write ${stream} failed: ${error instanceof Error ? error.message : String(error)}`; + } + } + + recordPresentationFailure(stream: CapturedOutputStream, reason: 'error' | 'closed' | 'backpressure'): void { + this.presentationFailures.add(`${stream}: ${reason}`); + this.writeMetadata(); + } + + finishAttempt( + attempt: number, + result: { exitCode: number; outcome: Exclude; logsDrained: boolean }, + ): void { + const state = this.getAttempt(attempt); + state.endedAt = new Date().toISOString(); + state.exitCode = result.exitCode; + state.outcome = result.outcome; + state.logsDrained = result.logsDrained; + for (const stream of Object.values(state.streams)) { + try { + fs.fsyncSync(stream.fd); + } catch (error) { + this.captureFailure ??= `flush failed: ${error instanceof Error ? error.message : String(error)}`; + } + } + if (this.currentAttempt === attempt) this.currentAttempt = undefined; + this.writeMetadata(); + } + + finishCommand(exitCode: number | undefined, outcome: Exclude): void { + if (this.commandOutcome !== 'pending') return; + if (exitCode !== undefined) this.commandExitCode = exitCode; + this.commandOutcome = outcome; + if (outcome !== 'exited' && this.currentAttempt !== undefined) { + const attempt = this.getAttempt(this.currentAttempt); + attempt.endedAt = new Date().toISOString(); + attempt.outcome = outcome; + attempt.logsDrained = false; + this.currentAttempt = undefined; + } + this.writeMetadata(); + this.resolveCommandCompletion(); + } + + waitForCommandCompletion(): Promise { + if (!this.commandStarted) return Promise.resolve(); + let timeout: ReturnType | undefined; + return Promise.race([ + this.commandCompletion, + new Promise(resolve => { + timeout = setTimeout(() => { + this.finishCommand(undefined, 'interrupted'); + resolve(); + }, COMMAND_COMPLETION_WAIT_TIMEOUT_MS); + }), + ]).finally(() => { + if (timeout) clearTimeout(timeout); + }); + } + + setTeardown(outcome: 'complete' | 'failed'): void { + this.teardown = outcome; + this.writeMetadata(); + } + + close(): void { + if (this.closed) return; + this.writeMetadata(); + let ownershipHandoffFailed = false; + const transferOwnership = (fd: number, owner: { uid: number; gid: number }): void => { + try { + fs.fchownSync(fd, owner.uid, owner.gid); + } catch (error) { + ownershipHandoffFailed = true; + this.captureFailure ??= `ownership handoff failed: ${error instanceof Error ? error.message : String(error)}`; + } + }; + try { + const owner = resolveArtifactOwner(); + for (const attempt of this.attempts) { + for (const stream of Object.values(attempt.streams)) transferOwnership(stream.fd, owner); + } + transferOwnership(this.metadataFd, owner); + transferOwnership(this.directoryFd, owner); + } catch (error) { + ownershipHandoffFailed = true; + this.captureFailure ??= `ownership handoff failed: ${error instanceof Error ? error.message : String(error)}`; + } + if (ownershipHandoffFailed) { + this.writeMetadata(); + } + for (const attempt of this.attempts) { + for (const stream of Object.values(attempt.streams)) { + try { + fs.closeSync(stream.fd); + } catch (error) { + this.captureFailure ??= `close failed: ${error instanceof Error ? error.message : String(error)}`; + } + } + } + this.writeMetadata(); + try { + fs.closeSync(this.metadataFd); + } catch { + this.captureFailure ??= 'metadata close failed'; + } finally { + this.closed = true; + } + fs.closeSync(this.directoryFd); + } + + private getAttempt(number: number): AttemptState { + const attempt = this.attempts.find((candidate, index) => index + 1 === number); + if (!attempt) throw new Error(`Protected output capture has no attempt ${number}`); + return attempt; + } + + private totalCapturedBytes(): number { + return this.attempts.reduce((sum, attempt) => + sum + Object.values(attempt.streams).reduce((streamSum, stream) => streamSum + stream.capturedBytes, 0), 0); + } + + private buildMetadata(): CaptureMetadata { + const observedBytes = this.attempts.reduce((sum, attempt) => + sum + Object.values(attempt.streams).reduce((streamSum, stream) => streamSum + stream.observedBytes, 0), 0); + const capturedBytes = this.totalCapturedBytes(); + const complete = this.commandOutcome === 'exited' + && this.teardown === 'complete' + && !this.truncated + && !this.captureFailure + && this.attempts.filter(attempt => attempt.outcome !== 'not_started').every(attempt => attempt.logsDrained); + + return { + schemaVersion: 1, + invocationId: this.invocationId, + runtime: this.runtime, + ordering: 'stdout and stderr are separate byte streams; ordering is guaranteed only within each stream and attempt', + maxBytes: this.maxBytes, + status: this.commandOutcome === 'pending' ? 'running' : complete ? 'complete' : 'incomplete', + command: { outcome: this.commandOutcome, ...(this.commandExitCode === undefined ? {} : { exitCode: this.commandExitCode }) }, + teardown: this.teardown, + observedBytes, + capturedBytes, + truncated: this.truncated, + ...(this.captureFailure ? { captureFailure: this.captureFailure } : {}), + presentationFailures: [...this.presentationFailures], + attempts: this.attempts.map(attempt => ({ + attemptId: attempt.attemptId, + stdout: { + file: attempt.streams.stdout.file, + observedBytes: attempt.streams.stdout.observedBytes, + capturedBytes: attempt.streams.stdout.capturedBytes, + }, + stderr: { + file: attempt.streams.stderr.file, + observedBytes: attempt.streams.stderr.observedBytes, + capturedBytes: attempt.streams.stderr.capturedBytes, + }, + ...(attempt.startedAt ? { startedAt: attempt.startedAt } : {}), + ...(attempt.endedAt ? { endedAt: attempt.endedAt } : {}), + ...(attempt.exitCode === undefined ? {} : { exitCode: attempt.exitCode }), + outcome: attempt.outcome, + ...(attempt.logsDrained === undefined ? {} : { logsDrained: attempt.logsDrained }), + })), + }; + } + + private writeMetadata(): void { + if (this.closed) return; + try { + const contents = Buffer.from(`${JSON.stringify(this.buildMetadata(), null, 2)}\n`); + fs.ftruncateSync(this.metadataFd, 0); + writeAll(this.metadataFd, contents, 0); + fs.fsyncSync(this.metadataFd); + } catch (error) { + if (!this.metadataInitialized) throw error; + this.captureFailure ??= `metadata update failed: ${error instanceof Error ? error.message : String(error)}`; + } + } +} + +export function prepareProtectedCommandOutputCapture( + config: WrapperConfig, +): ProtectedCommandOutputCapture | undefined { + const directory = config.commandOutputCaptureDir; + if (!directory) return undefined; + assertProtectedCommandOutputCaptureSupported(config); + + assertPrivateCommandOutputRootIsolated(config, directory); + const maxAttempts = isGvisorRuntime(config.containerRuntime) ? 2 : 1; + return new ProtectedCommandOutputCaptureSession( + directory, + config.containerRuntime ?? 'docker', + config.commandOutputCaptureMaxBytes ?? PROTECTED_COMMAND_OUTPUT_MAX_BYTES, + maxAttempts, + ); +} + +export function assertProtectedCommandOutputCaptureSupported(config: WrapperConfig): void { + const directory = config.commandOutputCaptureDir; + const maxBytes = config.commandOutputCaptureMaxBytes; + if (!directory) { + if (maxBytes !== undefined) throw new Error('--capture-command-output-max-bytes requires --capture-command-output'); + return; + } + if (!path.isAbsolute(directory)) throw new Error('Protected command output directory must be an absolute path'); + if (config.tty) throw new Error('Protected command output capture does not support TTY mode'); + if (config.enableDind || findDockerSocketExposingMount(config)) { + throw new Error('Protected command output capture is not supported when the agent can access a Docker socket'); + } + if (maxBytes !== undefined && (!Number.isSafeInteger(maxBytes) || maxBytes < 1 || maxBytes > PROTECTED_COMMAND_OUTPUT_MAX_BYTES)) { + throw new Error(`Protected command output byte limit must be an integer between 1 and ${PROTECTED_COMMAND_OUTPUT_MAX_BYTES}`); + } + if (!runtimeUsesComposeAgent(config.containerRuntime)) { + throw new Error(`Protected command output capture is not supported by the "${config.containerRuntime}" runtime`); + } +} + +/** @internal Exported for focused short-write accounting tests. */ +// ts-prune-ignore-next +export const protectedCommandOutputCaptureTestHelpers = { writeAll }; diff --git a/src/run-agent-command.test.ts b/src/run-agent-command.test.ts index 07bbee29f..2a5087530 100644 --- a/src/run-agent-command.test.ts +++ b/src/run-agent-command.test.ts @@ -1,5 +1,6 @@ import { runAgentCommand, fastKillAgentContainer } from './container-lifecycle'; import { containerLifecycleTestHelpers } from './container-lifecycle.test-utils'; +import { markAgentExternallyKilled } from './container-lifecycle-state'; import { logger } from './logger'; import { SQUID_CONTAINER_NAME } from './constants'; import * as fs from 'fs'; @@ -8,9 +9,15 @@ import * as path from 'path'; // Mock execa module import { mockExecaFn } from './test-helpers/mock-execa.test-utils'; import { useTempDir } from './test-helpers/docker-test-fixtures.test-utils'; +import { PassThrough } from 'stream'; +import type { ProtectedCommandOutputCapture } from './protected-command-output-capture'; // eslint-disable-next-line @typescript-eslint/no-require-imports jest.mock('execa', () => require('./test-helpers/mock-execa.test-utils').execaMockFactory()); +function invokeWriteCallback(callback: unknown, error?: Error): void { + if (typeof callback === 'function') (callback as (error?: Error | null) => void)(error); +} + describe('runAgentCommand', () => { const { getDir } = useTempDir(); @@ -141,6 +148,293 @@ describe('runAgentCommand', () => { expect(result.blockedDomains).toEqual([]); }); + it('captures raw streams and drains them if a runner-facing output stream fails', async () => { + const stdout = new PassThrough(); + const stderr = new PassThrough(); + let endedStreams = 0; + let resolveLogs: ((value: { stdout: Buffer; stderr: Buffer; exitCode: number }) => void) | undefined; + const logsProcess = Object.assign( + new Promise<{ stdout: Buffer; stderr: Buffer; exitCode: number }>(resolve => { resolveLogs = resolve; }), + { stdout, stderr }, + ); + stdout.on('end', () => { + if (++endedStreams === 2) resolveLogs?.({ stdout: Buffer.alloc(0), stderr: Buffer.alloc(0), exitCode: 0 }); + }); + stderr.on('end', () => { + if (++endedStreams === 2) resolveLogs?.({ stdout: Buffer.alloc(0), stderr: Buffer.alloc(0), exitCode: 0 }); + }); + mockExecaFn + .mockReturnValueOnce(logsProcess as any) + .mockResolvedValueOnce({ stdout: '7', stderr: '', exitCode: 0 } as any); + const capture = { + invocationId: 'test-invocation', + beginAttempt: jest.fn(), + recordOutput: jest.fn(), + recordPresentationFailure: jest.fn(), + finishAttempt: jest.fn(), + finishCommand: jest.fn(), + waitForCommandCompletion: jest.fn().mockResolvedValue(undefined), + setTeardown: jest.fn(), + close: jest.fn(), + } as ProtectedCommandOutputCapture; + const stdoutWrite = jest.spyOn(process.stdout, 'write') + .mockImplementationOnce((_chunk, callback) => { + setImmediate(() => { + const error = Object.assign(new Error('broken pipe'), { code: 'EPIPE' }); + process.stdout.emit('error', error); + invokeWriteCallback(callback, error); + }); + return true; + }) + .mockImplementation((_chunk, callback) => { + invokeWriteCallback(callback); + return true; + }); + const stderrWrite = jest.spyOn(process.stderr, 'write').mockImplementation((_chunk, callback) => { + invokeWriteCallback(callback); + return true; + }); + + try { + setImmediate(() => { + stdout.end(Buffer.from([0x00, 0xff, 0x41])); + stderr.end(Buffer.from([0x0a, 0x00, 0x42])); + }); + const result = await runAgentCommand(getDir(), ['github.com'], undefined, undefined, undefined, capture); + + expect(result.exitCode).toBe(7); + expect(capture.beginAttempt).toHaveBeenCalledWith(1); + expect(capture.recordOutput).toHaveBeenCalledWith(1, 'stdout', Buffer.from([0x00, 0xff, 0x41])); + expect(capture.recordOutput).toHaveBeenCalledWith(1, 'stderr', Buffer.from([0x0a, 0x00, 0x42])); + expect(capture.recordPresentationFailure).toHaveBeenCalledWith('stdout', 'error'); + expect(capture.finishAttempt).toHaveBeenCalledWith(1, { + exitCode: 7, + outcome: 'exited', + logsDrained: true, + }); + expect(capture.finishCommand).toHaveBeenCalledWith(7, 'exited'); + expect(stderrWrite).toHaveBeenCalledWith(Buffer.from([0x0a, 0x00, 0x42]), expect.any(Function)); + expect(mockExecaFn).toHaveBeenCalledWith( + 'docker', + ['logs', '-f', 'awf-agent'], + expect.objectContaining({ buffer: false, encoding: null }), + ); + } finally { + stdoutWrite.mockRestore(); + stderrWrite.mockRestore(); + } + }); + + it('continues draining raw output after console backpressure', async () => { + const stdout = new PassThrough(); + const stderr = new PassThrough(); + let endedStreams = 0; + let resolveLogs: ((value: { stdout: Buffer; stderr: Buffer; exitCode: number }) => void) | undefined; + const logsProcess = Object.assign( + new Promise<{ stdout: Buffer; stderr: Buffer; exitCode: number }>(resolve => { resolveLogs = resolve; }), + { stdout, stderr }, + ); + const finishLogs = (): void => { + if (++endedStreams === 2) resolveLogs?.({ stdout: Buffer.alloc(0), stderr: Buffer.alloc(0), exitCode: 0 }); + }; + stdout.on('end', finishLogs); + stderr.on('end', finishLogs); + mockExecaFn + .mockReturnValueOnce(logsProcess as any) + .mockResolvedValueOnce({ stdout: '0', stderr: '', exitCode: 0 } as any); + const capture = { + invocationId: 'backpressure-capture', + beginAttempt: jest.fn(), + recordOutput: jest.fn(), + recordPresentationFailure: jest.fn(), + finishAttempt: jest.fn(), + finishCommand: jest.fn(), + waitForCommandCompletion: jest.fn().mockResolvedValue(undefined), + setTeardown: jest.fn(), + close: jest.fn(), + } as ProtectedCommandOutputCapture; + const stdoutWrite = jest.spyOn(process.stdout, 'write').mockReturnValue(false); + const stderrWrite = jest.spyOn(process.stderr, 'write').mockImplementation((_chunk, callback) => { + invokeWriteCallback(callback); + return true; + }); + + try { + setImmediate(() => { + stdout.write(Buffer.from('first')); + stdout.end(Buffer.from('second')); + stderr.end(); + }); + + const result = await runAgentCommand(getDir(), ['github.com'], undefined, undefined, undefined, capture); + + expect(result.exitCode).toBe(0); + expect(capture.recordOutput).toHaveBeenCalledWith(1, 'stdout', Buffer.from('first')); + expect(capture.recordOutput).toHaveBeenCalledWith(1, 'stdout', Buffer.from('second')); + expect(capture.recordPresentationFailure).toHaveBeenCalledWith('stdout', 'backpressure'); + expect(capture.finishAttempt).toHaveBeenCalledWith(1, { + exitCode: 0, + outcome: 'exited', + logsDrained: true, + }); + } finally { + stdoutWrite.mockRestore(); + stderrWrite.mockRestore(); + } + }); + + it('bounds a stalled log follower and records that the output was not drained', async () => { + jest.useFakeTimers(); + const stdout = new PassThrough(); + const stderr = new PassThrough(); + const kill = jest.fn(); + const logsProcess = Object.assign(new Promise(() => {}), { stdout, stderr, kill }); + mockExecaFn + .mockReturnValueOnce(logsProcess as any) + .mockResolvedValueOnce({ stdout: '0', stderr: '', exitCode: 0 } as any); + const capture = { + invocationId: 'stalled-log-follower', + beginAttempt: jest.fn(), + recordOutput: jest.fn(), + recordPresentationFailure: jest.fn(), + finishAttempt: jest.fn(), + finishCommand: jest.fn(), + waitForCommandCompletion: jest.fn().mockResolvedValue(undefined), + setTeardown: jest.fn(), + close: jest.fn(), + } as ProtectedCommandOutputCapture; + + try { + const resultPromise = runAgentCommand(getDir(), ['github.com'], undefined, undefined, undefined, capture); + await jest.advanceTimersByTimeAsync(5_250); + const result = await resultPromise; + + expect(result.exitCode).toBe(0); + expect(kill).toHaveBeenCalledWith('SIGTERM'); + expect(capture.finishAttempt).toHaveBeenCalledWith(1, { + exitCode: 0, + outcome: 'exited', + logsDrained: false, + }); + } finally { + jest.useRealTimers(); + } + }); + + it('does not retry a gVisor startup exit after external cancellation', async () => { + const stdout = new PassThrough(); + const stderr = new PassThrough(); + let endedStreams = 0; + let resolveLogs: ((value: { stdout: Buffer; stderr: Buffer; exitCode: number }) => void) | undefined; + const logsProcess = Object.assign( + new Promise<{ stdout: Buffer; stderr: Buffer; exitCode: number }>(resolve => { resolveLogs = resolve; }), + { stdout, stderr }, + ); + const finishLogs = (): void => { + if (++endedStreams === 2) resolveLogs?.({ stdout: Buffer.alloc(0), stderr: Buffer.alloc(0), exitCode: 0 }); + }; + stdout.on('end', finishLogs); + stderr.on('end', finishLogs); + mockExecaFn + .mockReturnValueOnce(logsProcess as any) + .mockResolvedValueOnce({ stdout: '139', stderr: '', exitCode: 0 } as any); + const capture = { + invocationId: 'cancelled-gvisor', + beginAttempt: jest.fn(), + recordOutput: jest.fn(), + recordPresentationFailure: jest.fn(), + finishAttempt: jest.fn(), + finishCommand: jest.fn(), + waitForCommandCompletion: jest.fn().mockResolvedValue(undefined), + setTeardown: jest.fn(), + close: jest.fn(), + } as ProtectedCommandOutputCapture; + markAgentExternallyKilled(); + + setImmediate(() => { + stdout.end(); + stderr.end(); + }); + const result = await runAgentCommand( + getDir(), ['github.com'], undefined, undefined, 'gvisor', capture, + ); + + expect(result.exitCode).toBe(139); + expect(mockExecaFn).not.toHaveBeenCalledWith('docker', ['inspect', '--format', expect.any(String), 'awf-agent'], expect.anything()); + expect(mockExecaFn).not.toHaveBeenCalledWith('docker', ['start', 'awf-agent'], expect.anything()); + expect(capture.finishCommand).toHaveBeenCalledWith(139, 'cancelled'); + }); + + it('collects a retried gVisor attempt when cancellation arrives during docker start', async () => { + const createLogsProcess = (stdoutBytes: Buffer) => { + const stdout = new PassThrough(); + const stderr = new PassThrough(); + let endedStreams = 0; + let resolveLogs: ((value: { stdout: Buffer; stderr: Buffer; exitCode: number }) => void) | undefined; + const logsProcess = Object.assign( + new Promise<{ stdout: Buffer; stderr: Buffer; exitCode: number }>(resolve => { resolveLogs = resolve; }), + { stdout, stderr }, + ); + const finishLogs = (): void => { + if (++endedStreams === 2) resolveLogs?.({ stdout: Buffer.alloc(0), stderr: Buffer.alloc(0), exitCode: 0 }); + }; + stdout.on('end', finishLogs); + stderr.on('end', finishLogs); + setImmediate(() => { + stdout.end(stdoutBytes); + stderr.end(); + }); + return logsProcess; + }; + const startedAt = new Date(Date.now() - 1000).toISOString(); + const finishedAt = new Date().toISOString(); + const firstLogs = createLogsProcess(Buffer.from('first attempt')); + const retryLogs = createLogsProcess(Buffer.from('retry output')); + mockExecaFn + .mockReturnValueOnce(firstLogs as any) + .mockResolvedValueOnce({ stdout: '139', stderr: '', exitCode: 0 } as any) + .mockResolvedValueOnce({ stdout: `${startedAt} ${finishedAt}`, stderr: '', exitCode: 0 } as any) + .mockImplementationOnce(async (_command: string, args: string[]) => { + if (args[0] === 'start') markAgentExternallyKilled(); + return { stdout: '', stderr: '', exitCode: 0 } as any; + }) + .mockResolvedValueOnce({ stdout: '', stderr: '', exitCode: 0 } as any) + .mockReturnValueOnce(retryLogs as any) + .mockResolvedValueOnce({ stdout: '143', stderr: '', exitCode: 0 } as any); + const capture = { + invocationId: 'cancelled-retry', + beginAttempt: jest.fn(), + recordOutput: jest.fn(), + recordPresentationFailure: jest.fn(), + finishAttempt: jest.fn(), + finishCommand: jest.fn(), + waitForCommandCompletion: jest.fn().mockResolvedValue(undefined), + setTeardown: jest.fn(), + close: jest.fn(), + } as ProtectedCommandOutputCapture; + const stdoutWrite = jest.spyOn(process.stdout, 'write').mockReturnValue(false); + const stderrWrite = jest.spyOn(process.stderr, 'write').mockReturnValue(false); + + try { + const result = await runAgentCommand( + getDir(), ['github.com'], undefined, undefined, 'gvisor', capture, + ); + + expect(result.exitCode).toBe(143); + expect(capture.beginAttempt).toHaveBeenNthCalledWith(2, 2); + expect(capture.recordOutput).toHaveBeenCalledWith(2, 'stdout', Buffer.from('retry output')); + expect(capture.finishAttempt).toHaveBeenCalledWith(2, { + exitCode: 143, + outcome: 'exited', + logsDrained: true, + }); + expect(capture.finishCommand).toHaveBeenCalledWith(143, 'cancelled'); + } finally { + stdoutWrite.mockRestore(); + stderrWrite.mockRestore(); + } + }); + it('should return exit code 124 when agent times out', async () => { jest.useFakeTimers(); try { diff --git a/src/types/volume-options.ts b/src/types/volume-options.ts index d19363884..968ee7075 100644 --- a/src/types/volume-options.ts +++ b/src/types/volume-options.ts @@ -114,6 +114,14 @@ export interface VolumeOptions { */ sessionStateDir?: string; + /** + * Host-only directory for opt-in full command stdout/stderr capture. + * The directory must be new, absolute, and outside every agent-visible mount. + * AWF writes `metadata.json` and per-attempt stream files there. + */ + commandOutputCaptureDir?: string; + commandOutputCaptureMaxBytes?: number; + /** * Host runner tool cache directory to mount read-only into chroot mode. *