diff --git a/Sources/Basics/Observability.swift b/Sources/Basics/Observability.swift index 404d42a85c4..e254d2cc5b2 100644 --- a/Sources/Basics/Observability.swift +++ b/Sources/Basics/Observability.swift @@ -56,6 +56,10 @@ public class ObservabilitySystem { func handleDiagnostic(scope: ObservabilityScope, diagnostic: Diagnostic) { self.underlying(scope, diagnostic) } + + func printToOutput(message: String) { + self.diagnosticsHandler.printToOutput(message: message) + } } public static var NOOP: ObservabilityScope { @@ -128,6 +132,10 @@ public final class ObservabilityScope: DiagnosticsEmitterProtocol, Sendable, Cus return parent?.errorsReportedInAnyScope ?? false } + public func print(message: String) { + self.diagnosticsHandler.printToOutput(message: message) + } + // DiagnosticsEmitterProtocol public func emit(_ diagnostic: Diagnostic) { var diagnostic = diagnostic @@ -150,6 +158,10 @@ public final class ObservabilityScope: DiagnosticsEmitterProtocol, Sendable, Cus self.underlying.handleDiagnostic(scope: scope, diagnostic: diagnostic) } + public func printToOutput(message: String) { + self.underlying.printToOutput(message: message) + } + var errorsReported: Bool { self._errorsReported.get() ?? false } @@ -160,6 +172,8 @@ public final class ObservabilityScope: DiagnosticsEmitterProtocol, Sendable, Cus public protocol DiagnosticsHandler: Sendable { func handleDiagnostic(scope: ObservabilityScope, diagnostic: Diagnostic) + + func printToOutput(message: String) } /// Helper protocol to share default behavior. diff --git a/Sources/CoreCommands/SwiftCommandObservabilityHandler.swift b/Sources/CoreCommands/SwiftCommandObservabilityHandler.swift index aa49fffcc94..f726d9d317e 100644 --- a/Sources/CoreCommands/SwiftCommandObservabilityHandler.swift +++ b/Sources/CoreCommands/SwiftCommandObservabilityHandler.swift @@ -116,6 +116,12 @@ public struct SwiftCommandObservabilityHandler: ObservabilityHandlerProvider { } } + func printToOutput(message: String) { + self.queue.async(group: self.sync) { + self.write(message) + } + } + // for raw output reporting func print(_ output: String, verbose: Bool) { self.queue.async(group: self.sync) { diff --git a/Sources/SwiftBuildSupport/SwiftBuildSystem.swift b/Sources/SwiftBuildSupport/SwiftBuildSystem.swift index bf0e98161cf..3858c75e6c5 100644 --- a/Sources/SwiftBuildSupport/SwiftBuildSystem.swift +++ b/Sources/SwiftBuildSupport/SwiftBuildSystem.swift @@ -174,6 +174,445 @@ private final class PlanningOperationDelegate: SWBPlanningOperationDelegate, Sen } } +/// Convenience extensions to extract taskID and targetID from the LocationContext. +extension SwiftBuildMessage.LocationContext { + var taskID: Int? { + switch self { + case .task(let id, _), .globalTask(let id): + return id + case .target, .global: + return nil + } + } + + var targetID: Int? { + switch self { + case .task(_, let id), .target(let id): + return id + case .global, .globalTask: + return nil + } + } +} + +/// Handler for SwiftBuildMessage events sent by the SWBBuildOperation. +public final class SwiftBuildSystemMessageHandler { + private let observabilityScope: ObservabilityScope + private let logLevel: Basics.Diagnostic.Severity + private var buildState: BuildState = .init() + private let enableBacktraces: Bool + private let buildDelegate: SPMBuildCore.BuildSystemDelegate? + + public typealias BuildSystemCallback = (SwiftBuildSystem) -> Void + + let progressAnimation: ProgressAnimationProtocol + var serializedDiagnosticPathsByTargetName: [String: [Basics.AbsolutePath]] = [:] + + /// Tracks the diagnostics that we have not yet emitted. + private var unprocessedDiagnostics: [SwiftBuildMessage.DiagnosticInfo] = [] + /// Tracks the task IDs for failed tasks. + private var failedTasks: [Int] = [] + /// Tracks the tasks by their signature for which we have already emitted output. + private var tasksEmitted: Set = [] + /// Tracks the tasks by their ID for which we have already emitted output. + private var taskIDsEmitted: Set = [] + + public init( + observabilityScope: ObservabilityScope, + outputStream: OutputByteStream, + logLevel: Basics.Diagnostic.Severity, + enableBacktraces: Bool = false, + buildDelegate: SPMBuildCore.BuildSystemDelegate? = nil + ) + { + self.observabilityScope = observabilityScope + self.logLevel = logLevel + self.progressAnimation = ProgressAnimation.ninja( + stream: outputStream, + verbose: self.logLevel.isVerbose + ) + self.enableBacktraces = enableBacktraces + self.buildDelegate = buildDelegate + } + + struct BuildState { + private var targetsByID: [Int: SwiftBuild.SwiftBuildMessage.TargetStartedInfo] = [:] + private var activeTasks: [Int: SwiftBuild.SwiftBuildMessage.TaskStartedInfo] = [:] + private var completedTasks: [Int: SwiftBuild.SwiftBuildMessage.TaskCompleteInfo] = [:] + private var taskDataBuffer: TaskDataBuffer = .init() + private var taskIDToSignature: [Int: String] = [:] + var collectedBacktraceFrames = SWBBuildOperationCollectedBacktraceFrames() + + /// Rich model to store data buffers for a given `SwiftBuildMessage.LocationContext` or + /// a `SwiftBuildMessage.LocationContext2`. + struct TaskDataBuffer { + private var taskSignatureBuffer: [String: Data] = [:] + private var taskIDBuffer: [Int: Data] = [:] + private var targetIDBuffer: [Int: Data] = [:] + private var globalBuffer: Data = Data() + + subscript(key: String) -> Data? { + self.taskSignatureBuffer[key] + } + + subscript(key: String, default defaultValue: Data) -> Data { + get { self.taskSignatureBuffer[key] ?? defaultValue } + set { self.taskSignatureBuffer[key] = newValue } + } + + subscript(key: SwiftBuildMessage.LocationContext, default defaultValue: Data) -> Data { + get { + // Check each ID kind and try to fetch the associated buffer. + // If unable to get a non-nil result, then follow through to the + // next check. + if let taskID = key.taskID, + let result = self.taskIDBuffer[taskID] { + return result + } else if let targetID = key.targetID, + let result = self.targetIDBuffer[targetID] { + return result + } else if !self.globalBuffer.isEmpty { + return self.globalBuffer + } else { + return defaultValue + } + } + + set { + if let taskID = key.taskID { + self.taskIDBuffer[taskID] = newValue + if let targetID = key.targetID { + self.targetIDBuffer[targetID] = newValue + } + } else if let targetID = key.targetID { + self.targetIDBuffer[targetID] = newValue + } else { + self.globalBuffer = newValue + } + } + } + + subscript(key: SwiftBuildMessage.LocationContext2) -> Data? { + get { + if let taskSignature = key.taskSignature { + return self.taskSignatureBuffer[taskSignature] + } else if let targetID = key.targetID { + return self.targetIDBuffer[targetID] + } + + return nil + } + + set { + if let taskSignature = key.taskSignature { + self.taskSignatureBuffer[taskSignature] = newValue + } else if let targetID = key.targetID { + self.targetIDBuffer[targetID] = newValue + } + } + } + + subscript(task: SwiftBuildMessage.TaskStartedInfo) -> Data? { + get { + guard let result = self.taskSignatureBuffer[task.taskSignature] else { + // Default to checking targetID and taskID. + if let result = self.taskIDBuffer[task.taskID] { + return result + } else if let targetID = task.targetID, + let result = self.targetIDBuffer[targetID] { + return result + } + + // Return global buffer if none of the above are found. + return self.globalBuffer + } + + return result + } + } + } + + mutating func started(task: SwiftBuild.SwiftBuildMessage.TaskStartedInfo) throws { + if activeTasks[task.taskID] != nil { + throw Diagnostics.fatalError + } + activeTasks[task.taskID] = task + taskIDToSignature[task.taskID] = task.taskSignature + } + + mutating func completed(task: SwiftBuild.SwiftBuildMessage.TaskCompleteInfo) throws -> SwiftBuild.SwiftBuildMessage.TaskStartedInfo { + guard let startedTaskInfo = activeTasks[task.taskID] else { + throw Diagnostics.fatalError + } + if completedTasks[task.taskID] != nil { + throw Diagnostics.fatalError + } + self.completedTasks[task.taskID] = task + return startedTaskInfo + } + + mutating func started(target: SwiftBuild.SwiftBuildMessage.TargetStartedInfo) throws { + if targetsByID[target.targetID] != nil { + throw Diagnostics.fatalError + } + targetsByID[target.targetID] = target + } + + func target(for task: SwiftBuild.SwiftBuildMessage.TaskStartedInfo) throws -> SwiftBuild.SwiftBuildMessage.TargetStartedInfo? { + guard let id = task.targetID else { + return nil + } + guard let target = targetsByID[id] else { + throw Diagnostics.fatalError + } + return target + } + + func taskSignature(for id: Int) -> String? { + if let signature = taskIDToSignature[id] { + return signature + } + return nil + } + + mutating func appendToBuffer(_ info: SwiftBuildMessage.OutputInfo) { + // Attempt to key by taskSignature; at times this may not be possible, + // in which case we'd need to fall back to using LocationContext. + guard let taskSignature = info.locationContext2.taskSignature else { + // If we cannot find the task signature from the locationContext2, + // use deprecated locationContext instead to find task signature. + // If this fails to find an associated task signature, track + // relevant IDs from the location context in the task buffer. + if let taskID = info.locationContext.taskID, + let taskSignature = self.taskSignature(for: taskID) { + self.taskDataBuffer[taskSignature, default: .init()].append(info.data) + } + + self.taskDataBuffer[info.locationContext, default: .init()].append(info.data) + + return + } + + self.taskDataBuffer[taskSignature, default: .init()].append(info.data) + } + + func dataBuffer(for task: SwiftBuild.SwiftBuildMessage.TaskStartedInfo) -> Data? { + guard let data = taskDataBuffer[task.taskSignature] else { + // Fallback to checking taskID and targetID. + return taskDataBuffer[task] + } + + return data + } + } + + private func emitInfoAsDiagnostic(info: SwiftBuildMessage.DiagnosticInfo) { + let fixItsDescription = if info.fixIts.hasContent { + ": " + info.fixIts.map { String(describing: $0) }.joined(separator: ", ") + } else { + "" + } + let message = if let locationDescription = info.location.userDescription { + "\(locationDescription) \(info.message)\(fixItsDescription)" + } else { + "\(info.message)\(fixItsDescription)" + } + let severity: Diagnostic.Severity = switch info.kind { + case .error: .error + case .warning: .warning + case .note: .info + case .remark: .debug + } + self.observabilityScope.emit(severity: severity, message: "\(message)\n") + + for childDiagnostic in info.childDiagnostics { + emitInfoAsDiagnostic(info: childDiagnostic) + } + } + + private func emitDiagnosticCompilerOutput(_ info: SwiftBuildMessage.TaskStartedInfo) { + // Don't redundantly emit task output. + guard !self.tasksEmitted.contains(info.taskSignature) else { + return + } + guard hasUnprocessedDiagnostics(info) else { + return + } + // Assure we have a data buffer to decode. + guard let buffer = buildState.dataBuffer(for: info) else { + return + } + + // Decode the buffer to a string + let decodedOutput = String(decoding: buffer, as: UTF8.self) + + // Emit message. + observabilityScope.print(message: decodedOutput) + + // Record that we've emitted the output for a given task signature. + self.tasksEmitted.insert(info.taskSignature) + self.taskIDsEmitted.insert(info.taskID) + } + + private func hasUnprocessedDiagnostics(_ info: SwiftBuildMessage.TaskStartedInfo) -> Bool { + let diagnosticTaskSignature = unprocessedDiagnostics.compactMap(\.locationContext2.taskSignature) + let diagnosticTaskIDs = unprocessedDiagnostics.compactMap(\.locationContext.taskID) + + return diagnosticTaskSignature.contains(info.taskSignature) || diagnosticTaskIDs.contains(info.taskID) + } + + private func handleTaskOutput( + _ info: SwiftBuildMessage.TaskCompleteInfo, + _ startedInfo: SwiftBuildMessage.TaskStartedInfo, + _ enableTaskBacktraces: Bool + ) throws { + if info.result != .success { + emitFailedTaskOutput(info, startedInfo) + } else if let data = buildState.dataBuffer(for: startedInfo), !tasksEmitted.contains(startedInfo.taskSignature) { + let decodedOutput = String(decoding: data, as: UTF8.self) + if !decodedOutput.isEmpty { + observabilityScope.emit(info: decodedOutput) + } + } + + // Handle task backtraces, if applicable. + if enableTaskBacktraces { + if let id = SWBBuildOperationBacktraceFrame.Identifier(taskSignatureData: Data(startedInfo.taskSignature.utf8)), + let backtrace = SWBTaskBacktrace(from: id, collectedFrames: buildState.collectedBacktraceFrames) { + let formattedBacktrace = backtrace.renderTextualRepresentation() + if !formattedBacktrace.isEmpty { + self.observabilityScope.emit(info: "Task backtrace:\n\(formattedBacktrace)") + } + } + } + } + + private func emitFailedTaskOutput( + _ info: SwiftBuildMessage.TaskCompleteInfo, + _ startedInfo: SwiftBuildMessage.TaskStartedInfo + ) { + // Assure that the task has failed. + guard info.result != .success else { + return + } + // Don't redundantly emit task output. + guard !tasksEmitted.contains(startedInfo.taskSignature) else { + return + } + + // Track failed tasks. + self.failedTasks.append(info.taskID) + + // Check for existing diagnostics with matching taskID/taskSignature. + // If we've captured the compiler output with formatted diagnostics keyed by + // this task's signature, emit them. + // Note that this is a workaround instead of emitting directly from a `DiagnosticInfo` + // message, as here we receive the formatted code snippet directly from the compiler. + emitDiagnosticCompilerOutput(startedInfo) + + let message = "\(startedInfo.ruleInfo) failed with a nonzero exit code." + // If we have the command line display string available, then we + // should continue to emit this as an error. Otherwise, this doesn't + // give enough information to the user for it to be useful so we can + // demote it to an info-level log. + if let cmdLineDisplayStr = startedInfo.commandLineDisplayString { + self.observabilityScope.emit(severity: .error, message: "\(message) Command line: \(cmdLineDisplayStr)") + } else { + self.observabilityScope.emit(severity: .info, message: message) + } + + // Track that we have emitted output for this task. + tasksEmitted.insert(startedInfo.taskSignature) + taskIDsEmitted.insert(info.taskID) + } + + public func emitEvent(_ message: SwiftBuild.SwiftBuildMessage) throws -> BuildSystemCallback? { + var callback: BuildSystemCallback? = nil + + guard !self.logLevel.isQuiet else { return callback } + + switch message { + case .buildCompleted(let info): + progressAnimation.complete(success: info.result == .ok) + if info.result == .cancelled { + callback = { [weak self] buildSystem in + self?.buildDelegate?.buildSystemDidCancel(buildSystem) + } + } else { + callback = { [weak self] buildSystem in + self?.buildDelegate?.buildSystem(buildSystem, didFinishWithResult: info.result == .ok) + } + } + case .didUpdateProgress(let progressInfo): + var step = Int(progressInfo.percentComplete) + if step < 0 { step = 0 } + let message = if let targetName = progressInfo.targetName { + "\(targetName) \(progressInfo.message)" + } else { + "\(progressInfo.message)" + } + progressAnimation.update(step: step, total: 100, text: message) + callback = { [weak self] buildSystem in + self?.buildDelegate?.buildSystem(buildSystem, didUpdateTaskProgress: message) + } + case .diagnostic(let info): + if info.appendToOutputStream { + emitInfoAsDiagnostic(info: info) + } else { + unprocessedDiagnostics.append(info) + } + case .output(let info): + // Append to buffer-per-task storage + buildState.appendToBuffer(info) + case .taskStarted(let info): + try buildState.started(task: info) + + if let commandLineDisplay = info.commandLineDisplayString { + self.observabilityScope.emit(info: "\(info.executionDescription)\n\(commandLineDisplay)") + } else { + self.observabilityScope.emit(info: "\(info.executionDescription)") + } + + let targetInfo = try buildState.target(for: info) + callback = { [weak self] buildSystem in + self?.buildDelegate?.buildSystem(buildSystem, willStartCommand: BuildSystemCommand(info, targetInfo: targetInfo)) + self?.buildDelegate?.buildSystem(buildSystem, didStartCommand: BuildSystemCommand(info, targetInfo: targetInfo)) + } + case .taskComplete(let info): + let startedInfo = try buildState.completed(task: info) + + // Handler for failed tasks, if applicable. + try handleTaskOutput(info, startedInfo, self.enableBacktraces) + + let targetInfo = try buildState.target(for: startedInfo) + callback = { [weak self] buildSystem in + self?.buildDelegate?.buildSystem(buildSystem, didFinishCommand: BuildSystemCommand(startedInfo, targetInfo: targetInfo)) + } + if let targetName = targetInfo?.targetName { + try serializedDiagnosticPathsByTargetName[targetName, default: []].append(contentsOf: startedInfo.serializedDiagnosticsPaths.compactMap { + try Basics.AbsolutePath(validating: $0.pathString) + }) + } + case .targetStarted(let info): + try buildState.started(target: info) + case .backtraceFrame(let info): + if self.enableBacktraces { + buildState.collectedBacktraceFrames.add(frame: info) + } + case .planningOperationStarted, .planningOperationCompleted, .reportBuildDescription, .reportPathMap, .preparedForIndex, .buildStarted, .preparationComplete, .targetUpToDate, .targetComplete, .taskUpToDate: + break + case .buildDiagnostic, .targetDiagnostic, .taskDiagnostic: + break // deprecated + case .buildOutput, .targetOutput, .taskOutput: + break // deprecated + @unknown default: + break + } + + return callback + } +} + public final class SwiftBuildSystem: SPMBuildCore.BuildSystem { private let buildParameters: BuildParameters private let packageGraphLoader: () async throws -> ModulesGraph @@ -233,6 +672,10 @@ public final class SwiftBuildSystem: SPMBuildCore.BuildSystem { public var hasIntegratedAPIDigesterSupport: Bool { true } + public var enableTaskBacktraces: Bool { + self.buildParameters.outputParameters.enableTaskBacktraces + } + public init( buildParameters: BuildParameters, packageGraphLoader: @escaping () async throws -> ModulesGraph, @@ -537,12 +980,14 @@ public final class SwiftBuildSystem: SPMBuildCore.BuildSystem { return try await withService(connectionMode: .inProcessStatic(swiftbuildServiceEntryPoint)) { service in let derivedDataPath = self.buildParameters.dataPath - let progressAnimation = ProgressAnimation.ninja( - stream: self.outputStream, - verbose: self.logLevel.isVerbose + let buildMessageHandler = SwiftBuildSystemMessageHandler( + observabilityScope: self.observabilityScope, + outputStream: self.outputStream, + logLevel: self.logLevel, + enableBacktraces: self.enableTaskBacktraces, + buildDelegate: self.delegate ) - var serializedDiagnosticPathsByTargetName: [String: [Basics.AbsolutePath]] = [:] do { try await withSession(service: service, name: self.buildParameters.pifManifest.pathString, toolchainPath: self.buildParameters.toolchain.toolchainDir, packageManagerResourcesDirectory: self.packageManagerResourcesDirectory) { session, _ in self.outputStream.send("Building for \(self.buildParameters.configuration == .debug ? "debugging" : "production")...\n") @@ -582,148 +1027,6 @@ public final class SwiftBuildSystem: SPMBuildCore.BuildSystem { let request = try await self.makeBuildRequest(session: session, configuredTargets: configuredTargets, derivedDataPath: derivedDataPath, symbolGraphOptions: symbolGraphOptions) - struct BuildState { - private var targetsByID: [Int: SwiftBuild.SwiftBuildMessage.TargetStartedInfo] = [:] - private var activeTasks: [Int: SwiftBuild.SwiftBuildMessage.TaskStartedInfo] = [:] - var collectedBacktraceFrames = SWBBuildOperationCollectedBacktraceFrames() - - mutating func started(task: SwiftBuild.SwiftBuildMessage.TaskStartedInfo) throws { - if activeTasks[task.taskID] != nil { - throw Diagnostics.fatalError - } - activeTasks[task.taskID] = task - } - - mutating func completed(task: SwiftBuild.SwiftBuildMessage.TaskCompleteInfo) throws -> SwiftBuild.SwiftBuildMessage.TaskStartedInfo { - guard let task = activeTasks[task.taskID] else { - throw Diagnostics.fatalError - } - return task - } - - mutating func started(target: SwiftBuild.SwiftBuildMessage.TargetStartedInfo) throws { - if targetsByID[target.targetID] != nil { - throw Diagnostics.fatalError - } - targetsByID[target.targetID] = target - } - - mutating func target(for task: SwiftBuild.SwiftBuildMessage.TaskStartedInfo) throws -> SwiftBuild.SwiftBuildMessage.TargetStartedInfo? { - guard let id = task.targetID else { - return nil - } - guard let target = targetsByID[id] else { - throw Diagnostics.fatalError - } - return target - } - } - - func emitEvent(_ message: SwiftBuild.SwiftBuildMessage, buildState: inout BuildState) throws { - guard !self.logLevel.isQuiet else { return } - switch message { - case .buildCompleted(let info): - progressAnimation.complete(success: info.result == .ok) - if info.result == .cancelled { - self.delegate?.buildSystemDidCancel(self) - } else { - self.delegate?.buildSystem(self, didFinishWithResult: info.result == .ok) - } - case .didUpdateProgress(let progressInfo): - var step = Int(progressInfo.percentComplete) - if step < 0 { step = 0 } - let message = if let targetName = progressInfo.targetName { - "\(targetName) \(progressInfo.message)" - } else { - "\(progressInfo.message)" - } - progressAnimation.update(step: step, total: 100, text: message) - self.delegate?.buildSystem(self, didUpdateTaskProgress: message) - case .diagnostic(let info): - func emitInfoAsDiagnostic(info: SwiftBuildMessage.DiagnosticInfo) { - let fixItsDescription = if info.fixIts.hasContent { - ": " + info.fixIts.map { String(describing: $0) }.joined(separator: ", ") - } else { - "" - } - let message = if let locationDescription = info.location.userDescription { - "\(locationDescription) \(info.message)\(fixItsDescription)" - } else { - "\(info.message)\(fixItsDescription)" - } - let severity: Diagnostic.Severity = switch info.kind { - case .error: .error - case .warning: .warning - case .note: .info - case .remark: .debug - } - self.observabilityScope.emit(severity: severity, message: "\(message)\n") - - for childDiagnostic in info.childDiagnostics { - emitInfoAsDiagnostic(info: childDiagnostic) - } - } - - emitInfoAsDiagnostic(info: info) - case .output(let info): - self.observabilityScope.emit(info: "\(String(decoding: info.data, as: UTF8.self))") - case .taskStarted(let info): - try buildState.started(task: info) - - if let commandLineDisplay = info.commandLineDisplayString { - self.observabilityScope.emit(info: "\(info.executionDescription)\n\(commandLineDisplay)") - } else { - self.observabilityScope.emit(info: "\(info.executionDescription)") - } - - if self.logLevel.isVerbose { - if let commandLineDisplay = info.commandLineDisplayString { - self.outputStream.send("\(info.executionDescription)\n\(commandLineDisplay)") - } else { - self.outputStream.send("\(info.executionDescription)") - } - } - let targetInfo = try buildState.target(for: info) - self.delegate?.buildSystem(self, willStartCommand: BuildSystemCommand(info, targetInfo: targetInfo)) - self.delegate?.buildSystem(self, didStartCommand: BuildSystemCommand(info, targetInfo: targetInfo)) - case .taskComplete(let info): - let startedInfo = try buildState.completed(task: info) - if info.result != .success { - self.observabilityScope.emit(severity: .error, message: "\(startedInfo.ruleInfo) failed with a nonzero exit code. Command line: \(startedInfo.commandLineDisplayString ?? "")") - } - let targetInfo = try buildState.target(for: startedInfo) - self.delegate?.buildSystem(self, didFinishCommand: BuildSystemCommand(startedInfo, targetInfo: targetInfo)) - if let targetName = targetInfo?.targetName { - serializedDiagnosticPathsByTargetName[targetName, default: []].append(contentsOf: startedInfo.serializedDiagnosticsPaths.compactMap { - try? Basics.AbsolutePath(validating: $0.pathString) - }) - } - if self.buildParameters.outputParameters.enableTaskBacktraces { - if let id = SWBBuildOperationBacktraceFrame.Identifier(taskSignatureData: Data(startedInfo.taskSignature.utf8)), - let backtrace = SWBTaskBacktrace(from: id, collectedFrames: buildState.collectedBacktraceFrames) { - let formattedBacktrace = backtrace.renderTextualRepresentation() - if !formattedBacktrace.isEmpty { - self.observabilityScope.emit(info: "Task backtrace:\n\(formattedBacktrace)") - } - } - } - case .targetStarted(let info): - try buildState.started(target: info) - case .backtraceFrame(let info): - if self.buildParameters.outputParameters.enableTaskBacktraces { - buildState.collectedBacktraceFrames.add(frame: info) - } - case .planningOperationStarted, .planningOperationCompleted, .reportBuildDescription, .reportPathMap, .preparedForIndex, .buildStarted, .preparationComplete, .targetUpToDate, .targetComplete, .taskUpToDate: - break - case .buildDiagnostic, .targetDiagnostic, .taskDiagnostic: - break // deprecated - case .buildOutput, .targetOutput, .taskOutput: - break // deprecated - @unknown default: - break - } - } - let operation = try await session.createBuildOperation( request: request, delegate: PlanningOperationDelegate(), @@ -731,7 +1034,6 @@ public final class SwiftBuildSystem: SPMBuildCore.BuildSystem { ) var buildDescriptionID: SWBBuildDescriptionID? = nil - var buildState = BuildState() for try await event in try await operation.start() { if case .reportBuildDescription(let info) = event { if buildDescriptionID != nil { @@ -739,7 +1041,9 @@ public final class SwiftBuildSystem: SPMBuildCore.BuildSystem { } buildDescriptionID = SWBBuildDescriptionID(info.buildDescriptionID) } - try emitEvent(event, buildState: &buildState) + if let delegateCallback = try buildMessageHandler.emitEvent(event) { + delegateCallback(self) + } } await operation.waitForCompletion() @@ -747,8 +1051,8 @@ public final class SwiftBuildSystem: SPMBuildCore.BuildSystem { switch operation.state { case .succeeded: guard !self.logLevel.isQuiet else { return } - progressAnimation.update(step: 100, total: 100, text: "") - progressAnimation.complete(success: true) + buildMessageHandler.progressAnimation.update(step: 100, total: 100, text: "") + buildMessageHandler.progressAnimation.complete(success: true) let duration = ContinuousClock.Instant.now - buildStartTime let formattedDuration = duration.formatted(.units(allowed: [.seconds], fractionalPart: .show(length: 2, rounded: .up))) self.outputStream.send("Build complete! (\(formattedDuration))\n") @@ -815,7 +1119,7 @@ public final class SwiftBuildSystem: SPMBuildCore.BuildSystem { } return BuildResult( - serializedDiagnosticPathsByTargetName: .success(serializedDiagnosticPathsByTargetName), + serializedDiagnosticPathsByTargetName: .success(buildMessageHandler.serializedDiagnosticPathsByTargetName), symbolGraph: SymbolGraphResult( outputLocationForTarget: { target, buildParameters in return ["\(buildParameters.triple.archName)", "\(target).symbolgraphs"] diff --git a/Sources/_InternalTestSupport/Observability.swift b/Sources/_InternalTestSupport/Observability.swift index 2d934abf8dc..ae68e3df7ad 100644 --- a/Sources/_InternalTestSupport/Observability.swift +++ b/Sources/_InternalTestSupport/Observability.swift @@ -75,6 +75,10 @@ public struct TestingObservability { self.diagnostics.append(diagnostic) } + func printToOutput(message: String) { + print(message) + } + var hasErrors: Bool { self.diagnostics.get().hasErrors } diff --git a/Tests/BasicsTests/ObservabilitySystemTests.swift b/Tests/BasicsTests/ObservabilitySystemTests.swift index c7ae9a1b582..51a50fa64ed 100644 --- a/Tests/BasicsTests/ObservabilitySystemTests.swift +++ b/Tests/BasicsTests/ObservabilitySystemTests.swift @@ -309,6 +309,10 @@ struct ObservabilitySystemTest { func handleDiagnostic(scope: ObservabilityScope, diagnostic: Diagnostic) { self._diagnostics.append(diagnostic) } + + func printToOutput(message: String) { + print(message) + } } } diff --git a/Tests/SwiftBuildSupportTests/SwiftBuildSystemMessageHandlerTests.swift b/Tests/SwiftBuildSupportTests/SwiftBuildSystemMessageHandlerTests.swift new file mode 100644 index 00000000000..f69f3cbebec --- /dev/null +++ b/Tests/SwiftBuildSupportTests/SwiftBuildSystemMessageHandlerTests.swift @@ -0,0 +1,336 @@ +//===----------------------------------------------------------------------===// +// +// This source file is part of the Swift open source project +// +// Copyright (c) 2025 Apple Inc. and the Swift project authors +// Licensed under Apache License v2.0 with Runtime Library Exception +// +// See http://swift.org/LICENSE.txt for license information +// See http://swift.org/CONTRIBUTORS.txt for the list of Swift project authors +// +//===----------------------------------------------------------------------===// + +import Basics +import Foundation +import struct SWBUtil.AbsolutePath +import Testing +@_spi(Testing) +import SwiftBuild +import SwiftBuildSupport + +import TSCBasic +import _InternalTestSupport + + +@Suite +struct SwiftBuildSystemMessageHandlerTests { + private func createMessageHandler( + _ logLevel: Basics.Diagnostic.Severity = .warning + ) -> (handler: SwiftBuildSystemMessageHandler, outputStream: BufferedOutputByteStream, observability: TestingObservability) { + let observability = ObservabilitySystem.makeForTesting() + let outputStream = BufferedOutputByteStream() + + let handler = SwiftBuildSystemMessageHandler( + observabilityScope: observability.topScope, + outputStream: outputStream, + logLevel: logLevel + ) + + return (handler, outputStream, observability) + } + + @Test + func testNoDiagnosticsReported() throws { + let (messageHandler, outputStream, observability) = createMessageHandler() + + let events: [SwiftBuildMessage] = [ + .taskStartedInfo(), + .taskCompleteInfo(), + .buildCompletedInfo() + ] + + for event in events { + _ = try messageHandler.emitEvent(event) + } + + // Check output stream + let output = outputStream.bytes.description + #expect(!output.contains("error")) + + // Check observability diagnostics + expectNoDiagnostics(observability.diagnostics) + } + + @Test + func testSimpleDiagnosticReported() throws { + let (messageHandler, _, observability) = createMessageHandler() + + let events: [SwiftBuildMessage] = [ + .taskStartedInfo(taskSignature: "simple-diagnostic"), + .diagnosticInfo(locationContext2: .init(taskSignature: "simple-diagnostic"), message: "Simple diagnostic", appendToOutputStream: true), + .taskCompleteInfo(taskSignature: "simple-diagnostic") // Handler only emits when a task is completed. + ] + + for event in events { + _ = try messageHandler.emitEvent(event) + } + + #expect(observability.hasErrorDiagnostics) + + try expectDiagnostics(observability.diagnostics) { result in + result.check(diagnostic: "Simple diagnostic", severity: .error) + } + } + + @Test + func testManyDiagnosticsReported() throws { + let (messageHandler, _, observability) = createMessageHandler() + + let events: [SwiftBuildMessage] = [ + .taskStartedInfo(taskID: 1, taskSignature: "simple-diagnostic"), + .diagnosticInfo( + locationContext2: .init(taskSignature: "simple-diagnostic"), + message: "Simple diagnostic", + appendToOutputStream: true + ), + .taskStartedInfo(taskID: 2, taskSignature: "another-diagnostic"), + .taskStartedInfo(taskID: 3, taskSignature: "warning-diagnostic"), + .diagnosticInfo( + kind: .warning, + locationContext2: .init(taskSignature: "warning-diagnostic"), + message: "Warning diagnostic", + appendToOutputStream: true + ), + .taskCompleteInfo(taskID: 1, taskSignature: "simple-diagnostic"), + .diagnosticInfo( + kind: .warning, + locationContext2: .init(taskSignature: "warning-diagnostic"), + message: "Another warning diagnostic", + appendToOutputStream: true + ), + .taskCompleteInfo(taskID: 3, taskSignature: "warning-diagnostic"), + .diagnosticInfo( + kind: .note, + locationContext2: .init(taskSignature: "another-diagnostic"), + message: "Another diagnostic", + appendToOutputStream: true + ), + .taskCompleteInfo(taskID: 2, taskSignature: "another-diagnostic") + ] + + for event in events { + _ = try messageHandler.emitEvent(event) + } + + #expect(observability.hasErrorDiagnostics) + + try expectDiagnostics(observability.diagnostics) { result in + result.check(diagnostic: "Simple diagnostic", severity: .error) + result.check(diagnostic: "Another diagnostic", severity: .debug) + result.check(diagnostic: "Another warning diagnostic", severity: .warning) + result.check(diagnostic: "Warning diagnostic", severity: .warning) + } + } + + @Test + func testCompilerOutputDiagnosticsWithoutDuplicatedLogging() throws { + let (messageHandler, outputStream, observability) = createMessageHandler() + + let simpleDiagnosticString: String = "[error]: Simple diagnostic\n" + let simpleOutputInfo: SwiftBuildMessage = .outputInfo( + data: data(simpleDiagnosticString), + locationContext: .task(taskID: 1, targetID: 1), + locationContext2: .init(targetID: 1, taskSignature: "simple-diagnostic") + ) + + let warningDiagnosticString: String = "[warning]: Warning diagnostic\n" + let warningOutputInfo: SwiftBuildMessage = .outputInfo( + data: data(warningDiagnosticString), + locationContext: .task(taskID: 3, targetID: 1), + locationContext2: .init(targetID: 1, taskSignature: "warning-diagnostic") + ) + + let anotherDiagnosticString = "[note]: Another diagnostic\n" + let anotherOutputInfo: SwiftBuildMessage = .outputInfo( + data: data(anotherDiagnosticString), + locationContext: .task(taskID: 2, targetID: 1), + locationContext2: .init(targetID: 1, taskSignature: "another-diagnostic") + ) + + let anotherWarningDiagnosticString: String = "[warning]: Another warning diagnostic\n" + let anotherWarningOutputInfo: SwiftBuildMessage = .outputInfo( + data: data(anotherWarningDiagnosticString), + locationContext: .task(taskID: 3, targetID: 1), + locationContext2: .init(targetID: 1, taskSignature: "warning-diagnostic") + ) + + let events: [SwiftBuildMessage] = [ + .taskStartedInfo(taskID: 1, taskSignature: "simple-diagnostic"), + .diagnosticInfo( + locationContext2: .init(taskSignature: "simple-diagnostic"), + message: "Simple diagnostic", + appendToOutputStream: true + ), + .taskStartedInfo(taskID: 2, taskSignature: "another-diagnostic"), + .taskStartedInfo(taskID: 3, taskSignature: "warning-diagnostic"), + .diagnosticInfo( + kind: .warning, + locationContext2: .init(taskSignature: "warning-diagnostic"), + message: "Warning diagnostic", + appendToOutputStream: true + ), + anotherWarningOutputInfo, + simpleOutputInfo, + .taskCompleteInfo(taskID: 1, taskSignature: "simple-diagnostic"), + .diagnosticInfo( + kind: .warning, + locationContext2: .init(taskSignature: "warning-diagnostic"), + message: "Another warning diagnostic", + appendToOutputStream: true + ), + warningOutputInfo, + .taskCompleteInfo(taskID: 3, taskSignature: "warning-diagnostic"), + .diagnosticInfo( + kind: .note, + locationContext2: .init(taskSignature: "another-diagnostic"), + message: "Another diagnostic", + appendToOutputStream: true + ), + anotherOutputInfo, + .taskCompleteInfo(taskID: 2, taskSignature: "another-diagnostic") + ] + + for event in events { + _ = try messageHandler.emitEvent(event) + } + + // TODO bp this output stream will not contain the bytes of textual output; + // must augment the print use-case within the observability scope to fetch + // that data to complete this assertion. + let outputText = outputStream.bytes.description + #expect(outputText.contains("error")) + } +} + +private func data(_ message: String) -> Data { + Data(message.utf8) +} + +/// Convenience inits for testing +extension SwiftBuildMessage { + /// SwiftBuildMessage.TaskStartedInfo + package static func taskStartedInfo( + taskID: Int = 1, + targetID: Int? = nil, + taskSignature: String = "mock-task-signature", + parentTaskID: Int? = nil, + ruleInfo: String = "mock-rule", + interestingPath: SwiftBuild.AbsolutePath? = nil, + commandLineDisplayString: String? = nil, + executionDescription: String = "execution description", + serializedDiagnosticsPath: [SwiftBuild.AbsolutePath] = [] + ) -> SwiftBuildMessage { + .taskStarted( + .init( + taskID: taskID, + targetID: targetID, + taskSignature: taskSignature, + parentTaskID: parentTaskID, + ruleInfo: ruleInfo, + interestingPath: interestingPath, + commandLineDisplayString: commandLineDisplayString, + executionDescription: executionDescription, + serializedDiagnosticsPaths: serializedDiagnosticsPath + ) + ) + } + + /// SwiftBuildMessage.TaskCompletedInfo + package static func taskCompleteInfo( + taskID: Int = 1, + taskSignature: String = "mock-task-signature", + result: TaskCompleteInfo.Result = .success, + signalled: Bool = false, + metrics: TaskCompleteInfo.Metrics? = nil + ) -> SwiftBuildMessage { + .taskComplete( + .init( + taskID: taskID, + taskSignature: taskSignature, + result: result, + signalled: signalled, + metrics: metrics + ) + ) + } + + /// SwiftBuildMessage.DiagnosticInfo + package static func diagnosticInfo( + kind: DiagnosticInfo.Kind = .error, + location: DiagnosticInfo.Location = .unknown, + locationContext: LocationContext = .task(taskID: 1, targetID: 1), + locationContext2: LocationContext2 = .init(), + component: DiagnosticInfo.Component = .default, + message: String = "Mock diagnostic message.", + optionName: String? = nil, + appendToOutputStream: Bool = false, + childDiagnostics: [DiagnosticInfo] = [], + sourceRanges: [DiagnosticInfo.SourceRange] = [], + fixIts: [SwiftBuildMessage.DiagnosticInfo.FixIt] = [] + ) -> SwiftBuildMessage { + .diagnostic( + .init( + kind: kind, + location: location, + locationContext: locationContext, + locationContext2: locationContext2, + component: component, + message: message, + optionName: optionName, + appendToOutputStream: appendToOutputStream, + childDiagnostics: childDiagnostics, + sourceRanges: sourceRanges, + fixIts: fixIts + ) + ) + } + + /// SwiftBuildMessage.BuildStartedInfo + package static func buildStartedInfo( + baseDirectory: SwiftBuild.AbsolutePath, + derivedDataPath: SwiftBuild.AbsolutePath? = nil + ) -> SwiftBuildMessage.BuildStartedInfo { + .init( + baseDirectory: baseDirectory, + derivedDataPath: derivedDataPath + ) + } + + /// SwiftBuildMessage.BuildCompleteInfo + package static func buildCompletedInfo( + result: BuildCompletedInfo.Result = .ok, + metrics: BuildOperationMetrics? = nil + ) -> SwiftBuildMessage { + .buildCompleted( + .init( + result: result, + metrics: metrics + ) + ) + } + + /// SwiftBuildMessage.OutputInfo + package static func outputInfo( + data: Data, + locationContext: LocationContext = .task(taskID: 1, targetID: 1), + locationContext2: LocationContext2 = .init(targetID: 1, taskSignature: "mock-task-signature") + ) -> SwiftBuildMessage { + .output( + .init( + data: data, + locationContext: locationContext, + locationContext2: locationContext2 + ) + ) + } +}