CI observability enhancements. (#1193)

- Adds a a `--log-root` option to `swift system start`, propagating the
value as `CONTAINER_LOG_ROOT` to services for logging to files instead
of the OS log facility. This is not a "production" capability as it
neither merges nor rotates logs.
- Currently we don't collect logs on CI builds, and we don't have
permission to run the `log` command there. The PR adds `--log-root` to
the CI test phase, archives the results, and uploads the archive as an
artifact.
- Use FilePath from swift-system for the log root. Foundation URL is a
bit of a footgun for filesystem paths, so unless we identify a
showstopper, we should incrementally transition to this type everywhere
except where we really need network URLs.
- Output the hostname of the CI runner at the start of the test phase so
we can identify runner-specific issues where they exist.
- Fix formatting for log messages with multiple metadata items, and fix
unstructured messages on instances that weren't found using `grep -r
'log\.' Sources`.
- Adds command reference documentation for `--log-root`.

Sources/Helpers/APIServer/APIServer+Start.swift

@@ -17,6 +17,7 @@
 import ArgumentParser
 import ContainerAPIClient
 import ContainerAPIService
+import ContainerLog
 import ContainerNetworkService
 import ContainerPlugin
 import ContainerResource
@@ -24,6 +25,7 @@ import ContainerXPC
 import DNSServer
 import Foundation
 import Logging
+import SystemPackage
 
 extension APIServer {
     struct Start: AsyncParsableCommand {
@@ -43,9 +45,12 @@ extension APIServer {
 
         var installRoot = InstallRoot.url
 
+        var logRoot = LogRoot.path
+
         func run() async throws {
-            let commandName = Self.configuration.commandName ?? "container-apiserver"
-            let log = APIServer.setupLogger(debug: debug)
+            let commandName = APIServer._commandName
+            let logPath = logRoot.map { $0.appending("\(commandName).log") }
+            let log = ServiceLogger.bootstrap(category: "APIServer", debug: debug, logPath: logPath)
             log.info("starting helper", metadata: ["name": "\(commandName)"])
             defer {
                 log.info("stopping helper", metadata: ["name": "\(commandName)"])
@@ -91,6 +96,7 @@ extension APIServer {
                         log.info("starting XPC server")
                         try await server.listen()
                     }
+
                     // start up host table DNS
                     group.addTask {
                         let hostsResolver = ContainerDNSHandler(networkService: networkService)
@@ -113,7 +119,12 @@ extension APIServer {
                     /*
                     group.addTask {
                         let localhostResolver = LocalhostDNSHandler(log: log)
-                        try localhostResolver.monitorResolvers()
+                        do {
+                            try localhostResolver.monitorResolvers()
+                        } catch {
+                            log.error("could not initialize resolver monitor", metadata: ["error": "\(error)"])
+                            throw error
+                        }
                     
                         let nxDomainResolver = NxDomainResolver()
                         let compositeResolver = CompositeResolver(handlers: [localhostResolver, nxDomainResolver])
@@ -131,7 +142,12 @@ extension APIServer {
                     */
                 }
             } catch {
-                log.error("helper failed", metadata: ["name": "\(commandName)", "error": "\(error)"])
+                log.error(
+                    "helper failed",
+                    metadata: [
+                        "name": "\(commandName)",
+                        "error": "\(error)",
+                    ])
                 APIServer.exit(withError: error)
             }
         }
@@ -178,6 +194,7 @@ extension APIServer {
             return try PluginLoader(
                 appRoot: appRoot,
                 installRoot: installRoot,
+                logRoot: logRoot,
                 pluginDirectories: pluginDirectories,
                 pluginFactories: pluginFactories,
                 log: log
@@ -209,7 +226,12 @@ extension APIServer {
         private func initializeHealthCheckService(log: Logger, routes: inout [XPCRoute: XPCServer.RouteHandler]) {
             log.info("initializing health check service")
 
-            let svc = HealthCheckHarness(appRoot: appRoot, installRoot: installRoot, log: log)
+            let svc = HealthCheckHarness(
+                appRoot: appRoot,
+                installRoot: installRoot,
+                logRoot: logRoot,
+                log: log
+            )
             routes[XPCRoute.ping] = svc.ping
         }
 

Sources/Helpers/APIServer/APIServer.swift

@@ -15,9 +15,7 @@
 //===----------------------------------------------------------------------===//
 
 import ArgumentParser
-import ContainerLog
 import ContainerVersion
-import Logging
 
 @main
 struct APIServer: AsyncParsableCommand {
@@ -27,18 +25,4 @@ struct APIServer: AsyncParsableCommand {
         version: ReleaseVersion.singleLine(appName: "container-apiserver"),
         subcommands: [Start.self],
     )
-
-    static func setupLogger(debug: Bool) -> Logger {
-        LoggingSystem.bootstrap { label in
-            OSLogHandler(
-                label: label,
-                category: "APIServer"
-            )
-        }
-        var log = Logger(label: "com.apple.container")
-        if debug {
-            log.logLevel = .debug
-        }
-        return log
-    }
 }

Sources/Helpers/APIServer/DirectoryWatcher.swift

@@ -66,7 +66,12 @@ public class DirectoryWatcher {
                 let files = try FileManager.default.contentsOfDirectory(atPath: directoryURL.path)
                 try handler(files.map { directoryURL.appending(path: $0) })
             } catch {
-                self.log.error("failed to run DirectoryWatcher handler", metadata: ["error": "\(error)", "path": "\(directoryURL.path)"])
+                self.log.error(
+                    "failed to run DirectoryWatcher handler",
+                    metadata: [
+                        "error": "\(error)",
+                        "path": "\(directoryURL.path)",
+                    ])
             }
         }
 

Sources/Helpers/Images/ImagesHelper.swift

@@ -54,11 +54,14 @@ extension ImagesHelper {
 
         var installRoot = InstallRoot.url
 
+        var logRoot = LogRoot.path
+
         private static let unpackStrategy = SnapshotStore.defaultUnpackStrategy
 
         func run() async throws {
             let commandName = ImagesHelper._commandName
-            let log = setupLogger()
+            let logPath = logRoot.map { $0.appending("\(commandName).log") }
+            let log = ServiceLogger.bootstrap(category: "ImagesHelper", debug: debug, logPath: logPath)
             log.info("starting helper", metadata: ["name": "\(commandName)"])
             defer {
                 log.info("stopping helper", metadata: ["name": "\(commandName)"])
@@ -77,7 +80,12 @@ extension ImagesHelper {
                 log.info("starting XPC server")
                 try await xpc.listen()
             } catch {
-                log.error("helper failed", metadata: ["name": "\(commandName)", "error": "\(error)"])
+                log.error(
+                    "helper failed",
+                    metadata: [
+                        "name": "\(commandName)",
+                        "error": "\(error)",
+                    ])
                 ImagesHelper.exit(withError: error)
             }
         }
@@ -114,19 +122,5 @@ extension ImagesHelper {
             routes[ImagesServiceXPCRoute.contentIngestCancel.rawValue] = harness.cancelIngestSession
             routes[ImagesServiceXPCRoute.contentIngestComplete.rawValue] = harness.completeIngestSession
         }
-
-        private func setupLogger() -> Logger {
-            LoggingSystem.bootstrap { label in
-                OSLogHandler(
-                    label: label,
-                    category: "ImagesHelper"
-                )
-            }
-            var log = Logger(label: "com.apple.container")
-            if debug {
-                log.logLevel = .debug
-            }
-            return log
-        }
     }
 }

Sources/Helpers/NetworkVmnet/NetworkVmnetHelper+Start.swift

@@ -15,8 +15,10 @@
 //===----------------------------------------------------------------------===//
 
 import ArgumentParser
+import ContainerLog
 import ContainerNetworkService
 import ContainerNetworkServiceClient
+import ContainerPlugin
 import ContainerResource
 import ContainerXPC
 import ContainerizationError
@@ -64,9 +66,12 @@ extension NetworkVmnetHelper {
             return .reserved
         }()
 
+        var logRoot = LogRoot.path
+
         func run() async throws {
             let commandName = NetworkVmnetHelper._commandName
-            let log = setupLogger(id: id, debug: debug)
+            let logPath = logRoot.map { $0.appending("\(commandName)-\(id).log") }
+            let log = ServiceLogger.bootstrap(category: "NetworkVmnetHelper", metadata: ["id": "\(id)"], debug: debug, logPath: logPath)
             log.info("starting helper", metadata: ["name": "\(commandName)"])
             defer {
                 log.info("stopping helper", metadata: ["name": "\(commandName)"])
@@ -110,7 +115,12 @@ extension NetworkVmnetHelper {
                 log.info("starting XPC server")
                 try await xpc.listen()
             } catch {
-                log.error("helper failed", metadata: ["name": "\(commandName)", "error": "\(error)"])
+                log.error(
+                    "helper failed",
+                    metadata: [
+                        "name": "\(commandName)",
+                        "error": "\(error)",
+                    ])
                 NetworkVmnetHelper.exit(withError: error)
             }
         }

Sources/Helpers/NetworkVmnet/NetworkVmnetHelper.swift

@@ -15,9 +15,7 @@
 //===----------------------------------------------------------------------===//
 
 import ArgumentParser
-import ContainerLog
 import ContainerVersion
-import Logging
 
 @main
 struct NetworkVmnetHelper: AsyncParsableCommand {
@@ -29,19 +27,4 @@ struct NetworkVmnetHelper: AsyncParsableCommand {
             Start.self
         ]
     )
-
-    static func setupLogger(id: String, debug: Bool) -> Logger {
-        LoggingSystem.bootstrap { label in
-            OSLogHandler(
-                label: label,
-                category: "NetworkVmnetHelper"
-            )
-        }
-        var log = Logger(label: "com.apple.container")
-        if debug {
-            log.logLevel = .debug
-        }
-        log[metadataKey: "id"] = "\(id)"
-        return log
-    }
 }

Sources/Helpers/RuntimeLinux/RuntimeLinuxHelper+Start.swift

@@ -16,6 +16,7 @@
 
 import ArgumentParser
 import ContainerLog
+import ContainerPlugin
 import ContainerResource
 import ContainerSandboxService
 import ContainerSandboxServiceClient
@@ -42,13 +43,16 @@ extension RuntimeLinuxHelper {
         @Option(name: .shortAndLong, help: "Root directory for the sandbox")
         var root: String
 
+        var logRoot = LogRoot.path
+
         var machServiceLabel: String {
             "\(Self.label).\(uuid)"
         }
 
         func run() async throws {
             let commandName = RuntimeLinuxHelper._commandName
-            let log = RuntimeLinuxHelper.setupLogger(debug: debug, metadata: ["uuid": "\(uuid)"])
+            let logPath = logRoot.map { $0.appending("\(commandName)-\(uuid).log") }
+            let log = ServiceLogger.bootstrap(category: "RuntimeLinuxHelper", metadata: ["uuid": "\(uuid)"], debug: debug, logPath: logPath)
             log.info("starting helper", metadata: ["name": "\(commandName)"])
             defer {
                 log.info("stopping helper", metadata: ["name": "\(commandName)"])
@@ -117,7 +121,12 @@ extension RuntimeLinuxHelper {
                     _ = try await group.next()
                 }
             } catch {
-                log.error("helper failed", metadata: ["name": "\(commandName)", "error": "\(error)"])
+                log.error(
+                    "helper failed",
+                    metadata: [
+                        "name": "\(commandName)",
+                        "error": "\(error)",
+                    ])
                 try? await eventLoopGroup.shutdownGracefully()
                 RuntimeLinuxHelper.Start.exit(withError: error)
             }

Sources/Helpers/RuntimeLinux/RuntimeLinuxHelper.swift

@@ -15,10 +15,7 @@
 //===----------------------------------------------------------------------===//
 
 import ArgumentParser
-import ContainerLog
 import ContainerVersion
-import Logging
-import OSLog
 
 @main
 struct RuntimeLinuxHelper: AsyncParsableCommand {
@@ -30,24 +27,4 @@ struct RuntimeLinuxHelper: AsyncParsableCommand {
             Start.self
         ]
     )
-
-    package static func setupLogger(debug: Bool, metadata: [String: Logging.Logger.Metadata.Value] = [:]) -> Logging.Logger {
-        LoggingSystem.bootstrap { label in
-            OSLogHandler(
-                label: label,
-                category: "RuntimeLinuxHelper"
-            )
-        }
-
-        var log = Logger(label: "com.apple.container")
-        if debug {
-            log.logLevel = .debug
-        }
-
-        for (key, val) in metadata {
-            log[metadataKey: key] = val
-        }
-
-        return log
-    }
 }