ManagedProcess: Capture vmexec stderr and convert to Containerization Error (#411)

Fixes #277

When vmexec fails, it logs to stderr and exits with code 1. Previously,
the error details were lost. This change captures stderr and converts it
into a proper ContainerizationError.

Signed-off-by: Rahul Thennarasu <rahulthennarasu07@gmail.com>

Sources/Integration/ContainerTests.swift

@@ -1227,4 +1227,23 @@ extension IntegrationSuite {
             throw error
         }
     }
+
+    func testNonExistentBinary() async throws {
+        let id = "test-non-existent-binary"
+
+        let bs = try await bootstrap(id)
+        let container = try LinuxContainer(id, rootfs: bs.rootfs, vmm: bs.vmm) { config in
+            config.process.arguments = ["foo-bar-baz"]
+            config.bootLog = bs.bootLog
+        }
+
+        try await container.create()
+        do {
+            try await container.start()
+        } catch {
+            return
+        }
+        try await container.stop()
+        throw IntegrationError.assert(msg: "container start should have failed")
+    }
 }

vminitd/Sources/vmexec/ExecCommand.swift

@@ -34,16 +34,21 @@ struct ExecCommand: ParsableCommand {
     var parentPid: Int
 
     func run() throws {
-        LoggingSystem.bootstrap(App.standardError)
-        let log = Logger(label: "vmexec")
+        do {
+            LoggingSystem.bootstrap(App.standardError)
+            let log = Logger(label: "vmexec")
 
-        let src = URL(fileURLWithPath: processPath)
-        let processBytes = try Data(contentsOf: src)
-        let process = try JSONDecoder().decode(
-            ContainerizationOCI.Process.self,
-            from: processBytes
-        )
-        try execInNamespaces(process: process, log: log)
+            let src = URL(fileURLWithPath: processPath)
+            let processBytes = try Data(contentsOf: src)
+            let process = try JSONDecoder().decode(
+                ContainerizationOCI.Process.self,
+                from: processBytes
+            )
+            try execInNamespaces(process: process, log: log)
+        } catch {
+            App.writeError(error)
+            throw error
+        }
     }
 
     static func enterNS(pidFd: Int32, nsType: Int32) throws {

vminitd/Sources/vmexec/RunCommand.swift

@@ -32,12 +32,17 @@ struct RunCommand: ParsableCommand {
     var bundlePath: String
 
     mutating func run() throws {
-        LoggingSystem.bootstrap(App.standardError)
-        let log = Logger(label: "vmexec")
+        do {
+            LoggingSystem.bootstrap(App.standardError)
+            let log = Logger(label: "vmexec")
 
-        let bundle = try ContainerizationOCI.Bundle.load(path: URL(filePath: bundlePath))
-        let ociSpec = try bundle.loadConfig()
-        try execInNamespace(spec: ociSpec, log: log)
+            let bundle = try ContainerizationOCI.Bundle.load(path: URL(filePath: bundlePath))
+            let ociSpec = try bundle.loadConfig()
+            try execInNamespace(spec: ociSpec, log: log)
+        } catch {
+            App.writeError(error)
+            throw error
+        }
     }
 
     private func childRootSetup(rootfs: ContainerizationOCI.Root, mounts: [ContainerizationOCI.Mount], log: Logger) throws {

vminitd/Sources/vmexec/vmexec.swift

@@ -182,4 +182,20 @@ extension App {
             message: message
         )
     }
+
+    static func writeError(_ error: Error) {
+        let errorPipe = FileHandle(fileDescriptor: 5)
+
+        let errorMessage: String
+        if let czError = error as? ContainerizationError {
+            errorMessage = czError.description
+        } else {
+            errorMessage = String(describing: error)
+        }
+
+        if let data = errorMessage.data(using: .utf8) {
+            try? errorPipe.write(contentsOf: data)
+        }
+        try? errorPipe.close()
+    }
 }

vminitd/Sources/vminitd/ManagedProcess.swift

@@ -63,6 +63,7 @@ final class ManagedProcess: Sendable {
     private let owningPid: Int32?
     private let ackPipe: Pipe
     private let syncPipe: Pipe
+    private let errorPipe: Pipe
     private let terminal: Bool
     private let bundle: ContainerizationOCI.Bundle
     private let cgroupManager: Cgroup2Manager?
@@ -95,6 +96,10 @@ final class ManagedProcess: Sendable {
         try ackPipe.setCloexec()
         self.ackPipe = ackPipe
 
+        let errorPipe = Pipe()
+        try errorPipe.setCloexec()
+        self.errorPipe = errorPipe
+
         let args: [String]
         if let owningPid {
             args = [
@@ -114,6 +119,7 @@ final class ManagedProcess: Sendable {
             extraFiles: [
                 syncPipe.fileHandleForWriting,
                 ackPipe.fileHandleForReading,
+                errorPipe.fileHandleForWriting,
             ]
         )
 
@@ -149,104 +155,119 @@ final class ManagedProcess: Sendable {
 
 extension ManagedProcess {
     func start() throws -> Int32 {
-        try self.state.withLock {
-            log.info(
-                "starting managed process",
-                metadata: [
-                    "id": "\(id)"
-                ])
-
-            // Start the underlying process.
-            try command.start()
-            defer {
-                try? self.ackPipe.fileHandleForWriting.close()
-                try? self.syncPipe.fileHandleForReading.close()
-                try? self.ackPipe.fileHandleForReading.close()
-                try? self.syncPipe.fileHandleForWriting.close()
-            }
-
-            // Close our side of any pipes.
-            try $0.io.closeAfterExec()
-            try self.ackPipe.fileHandleForReading.close()
-            try self.syncPipe.fileHandleForWriting.close()
-
-            let size = MemoryLayout<Int32>.size
-            guard let piddata = try syncPipe.fileHandleForReading.read(upToCount: size) else {
-                throw ContainerizationError(.internalError, message: "no PID data from sync pipe")
-            }
-
-            guard piddata.count == size else {
-                throw ContainerizationError(.internalError, message: "invalid payload")
-            }
-
-            let pid = piddata.withUnsafeBytes { ptr in
-                ptr.load(as: Int32.self)
-            }
-
-            log.info(
-                "got back pid data",
-                metadata: [
-                    "pid": "\(pid)"
-                ])
-            $0.pid = pid
-
-            // This should probably happen in vmexec, but we don't need to set any cgroup
-            // toggles so the problem is much simpler to just do it here.
-            if let owningPid {
-                let cgManager = try Cgroup2Manager.loadFromPid(pid: owningPid)
-                try cgManager.addProcess(pid: pid)
-            }
-
-            log.info(
-                "sending pid acknowledgement",
-                metadata: [
-                    "pid": "\(pid)"
-                ])
-            try self.ackPipe.fileHandleForWriting.write(contentsOf: Self.ackPid.data(using: .utf8)!)
-
-            if self.terminal {
+        do {
+            return try self.state.withLock {
                 log.info(
-                    "wait for PTY FD",
+                    "starting managed process",
                     metadata: [
                         "id": "\(id)"
                     ])
 
-                // Wait for a new write that will contain the pty fd if we asked for one.
-                guard let ptyFd = try self.syncPipe.fileHandleForReading.read(upToCount: size) else {
-                    throw ContainerizationError(
-                        .internalError,
-                        message: "no PTY data from sync pipe"
-                    )
+                // Start the underlying process.
+                try command.start()
+
+                defer {
+                    try? self.ackPipe.fileHandleForWriting.close()
+                    try? self.syncPipe.fileHandleForReading.close()
+                    try? self.ackPipe.fileHandleForReading.close()
+                    try? self.syncPipe.fileHandleForWriting.close()
+                    try? self.errorPipe.fileHandleForWriting.close()
                 }
-                let fd = ptyFd.withUnsafeBytes { ptr in
+
+                // Close our side of any pipes.
+                try $0.io.closeAfterExec()
+                try self.ackPipe.fileHandleForReading.close()
+                try self.syncPipe.fileHandleForWriting.close()
+
+                let size = MemoryLayout<Int32>.size
+                guard let piddata = try syncPipe.fileHandleForReading.read(upToCount: size) else {
+                    throw ContainerizationError(.internalError, message: "no PID data from sync pipe")
+                }
+
+                guard piddata.count == size else {
+                    throw ContainerizationError(.internalError, message: "invalid payload")
+                }
+
+                let pid = piddata.withUnsafeBytes { ptr in
                     ptr.load(as: Int32.self)
                 }
+
                 log.info(
-                    "received PTY FD from container, attaching",
+                    "got back pid data",
                     metadata: [
-                        "id": "\(id)"
+                        "pid": "\(pid)"
+                    ])
+                $0.pid = pid
+
+                // This should probably happen in vmexec, but we don't need to set any cgroup
+                // toggles so the problem is much simpler to just do it here.
+                if let owningPid {
+                    let cgManager = try Cgroup2Manager.loadFromPid(pid: owningPid)
+                    try cgManager.addProcess(pid: pid)
+                }
+
+                log.info(
+                    "sending pid acknowledgement",
+                    metadata: [
+                        "pid": "\(pid)"
+                    ])
+                try self.ackPipe.fileHandleForWriting.write(contentsOf: Self.ackPid.data(using: .utf8)!)
+
+                if self.terminal {
+                    log.info(
+                        "wait for PTY FD",
+                        metadata: [
+                            "id": "\(id)"
+                        ])
+
+                    // Wait for a new write that will contain the pty fd if we asked for one.
+                    guard let ptyFd = try self.syncPipe.fileHandleForReading.read(upToCount: size) else {
+                        throw ContainerizationError(
+                            .internalError,
+                            message: "no PTY data from sync pipe"
+                        )
+                    }
+                    let fd = ptyFd.withUnsafeBytes { ptr in
+                        ptr.load(as: Int32.self)
+                    }
+                    log.info(
+                        "received PTY FD from container, attaching",
+                        metadata: [
+                            "id": "\(id)"
+                        ])
+
+                    try $0.io.attach(pid: pid, fd: fd)
+                    try self.ackPipe.fileHandleForWriting.write(contentsOf: Self.ackConsole.data(using: .utf8)!)
+                }
+
+                // Wait for the syncPipe to close (after exec).
+                _ = try self.syncPipe.fileHandleForReading.readToEnd()
+
+                log.info(
+                    "started managed process",
+                    metadata: [
+                        "pid": "\(pid)",
+                        "id": "\(id)",
                     ])
 
-                try $0.io.attach(pid: pid, fd: fd)
-                try self.ackPipe.fileHandleForWriting.write(contentsOf: Self.ackConsole.data(using: .utf8)!)
+                return pid
             }
-
-            // Wait for the syncPipe to close (after exec).
-            _ = try self.syncPipe.fileHandleForReading.readToEnd()
-
-            log.info(
-                "started managed process",
-                metadata: [
-                    "pid": "\(pid)",
-                    "id": "\(id)",
-                ])
-
-            return pid
+        } catch {
+            if let errorData = try? self.errorPipe.fileHandleForReading.readToEnd(),
+                let errorString = String(data: errorData, encoding: .utf8),
+                !errorString.isEmpty
+            {
+                throw ContainerizationError(
+                    .internalError,
+                    message: "vmexec error: \(errorString.trimmingCharacters(in: .whitespacesAndNewlines))"
+                )
+            }
+            throw error
         }
     }
 
     func setExit(_ status: Int32) {
-        self.state.withLock {
+        self.state.withLock { state in
             self.log.info(
                 "managed process exit",
                 metadata: [
@@ -254,20 +275,20 @@ extension ManagedProcess {
                 ])
 
             let exitStatus = ExitStatus(exitStatus: status, exitedAt: Date.now)
-            $0.exitStatus = exitStatus
+            state.exitStatus = exitStatus
 
             do {
-                try $0.io.close()
+                try state.io.close()
             } catch {
                 self.log.error("failed to close I/O for process: \(error)")
             }
 
-            for waiter in $0.waiters {
+            for waiter in state.waiters {
                 waiter.resume(returning: exitStatus)
             }
 
-            self.log.debug("\($0.waiters.count) managed process waiters signaled")
-            $0.waiters.removeAll()
+            self.log.debug("\(state.waiters.count) managed process waiters signaled")
+            state.waiters.removeAll()
         }
     }