command plugin: Optionally print build logs during packageManager.build

When a plugin asks for a target to be built by calling
packageManager.build, SwiftPM accumulates the build log in a buffer
and returns the whole log when the build completes.   No feedback
is printed on the console while the build is running, so if the
target is large the user can't tell whether the build is making
progress or is stuck.

This commit adds the option to echo logs to the console as they are
produced, in addition to accumulating them in a buffer.   Console
echoing is turned off by default.

Author: euanh

Fixtures/Miscellaneous/Plugins/CommandPluginTestStub/Plugins/diagnostics-stub/diagnostics_stub.swift

@@ -5,6 +5,26 @@ import PackagePlugin
 struct diagnostics_stub: CommandPlugin {
     // This is a helper for testing plugin diagnostics.  It sends different messages to SwiftPM depending on its arguments.
     func performCommand(context: PluginContext, arguments: [String]) async throws {
+        // Build a target, possibly asking SwiftPM to echo the logs as they are produced.
+        if arguments.contains("build") {
+            // If echoLogs is true, SwiftPM will print build logs to stderr as they are produced.
+            // SwiftPM does not add a prefix to these logs.
+            let result = try packageManager.build(
+                .product("placeholder"),
+                parameters: .init(echoLogs: arguments.contains("echologs"))
+            )
+
+            // To verify that logs are also returned correctly to the plugin,
+            // print the accumulated log buffer lines with a prefix to
+            // distinguish them from echoed logs.   These logs are normal output
+            // from the plugin and will be printed on stdout.
+            if arguments.contains("printlogs") {
+                for line in result.logText.components(separatedBy: "\n") {
+                    print("command plugin: packageManager.build logtext: \(line)")
+                }
+            }
+        }
+
         // Anything a plugin writes to standard output appears on standard output.
         // Printing to stderr will also go to standard output because SwiftPM combines
         // stdout and stderr before launching the plugin.

Sources/Commands/Utilities/PluginDelegate.swift

@@ -16,6 +16,7 @@ import Foundation
 import PackageModel
 import SPMBuildCore
 
+import protocol TSCBasic.OutputByteStream
 import class TSCBasic.BufferedOutputByteStream
 import class TSCBasic.Process
 import struct TSCBasic.ProcessResult
@@ -66,6 +67,40 @@ final class PluginDelegate: PluginInvocationDelegate {
         }
     }
 
+    class TeeOutputByteStream: OutputByteStream {
+        var downstreams: [OutputByteStream]
+
+        public init(_ downstreams: [OutputByteStream]) {
+            self.downstreams = downstreams
+        }
+
+        var position: Int {
+            return 0 // should be related to the downstreams somehow
+        }
+
+        public func write(_ byte: UInt8) {
+            for downstream in downstreams {
+                downstream.write(byte)
+            }
+        }
+
+        func write<C: Collection>(_ bytes: C) where C.Element == UInt8 {
+            for downstream in downstreams {
+                downstream.write(bytes)
+            }
+		}
+
+        public func flush() {
+            for downstream in downstreams {
+                downstream.flush()
+            }
+        }
+
+        public func addStream(_ stream: OutputByteStream) {
+            self.downstreams.append(stream)
+        }
+    }
+
     private func performBuildForPlugin(
         subset: PluginInvocationBuildSubset,
         parameters: PluginInvocationBuildParameters
@@ -112,7 +147,12 @@ final class PluginDelegate: PluginInvocationDelegate {
         }
 
         // Create a build operation. We have to disable the cache in order to get a build plan created.
-        let outputStream = BufferedOutputByteStream()
+        let bufferedOutputStream = BufferedOutputByteStream()
+        let outputStream = TeeOutputByteStream([bufferedOutputStream])
+        if parameters.echoLogs {
+            outputStream.addStream(swiftTool.outputStream)
+        }
+
         let buildSystem = try swiftTool.createBuildSystem(
             explicitBuildSystem: .native,
             explicitProduct: explicitProduct,
@@ -151,7 +191,7 @@ final class PluginDelegate: PluginInvocationDelegate {
         }
         return PluginInvocationBuildResult(
             succeeded: success,
-            logText: outputStream.bytes.cString,
+            logText: bufferedOutputStream.bytes.cString,
             builtArtifacts: builtArtifacts)
     }
 

Sources/PackagePlugin/PackageManagerProxy.swift

@@ -59,7 +59,10 @@ public struct PackageManager {
 
         /// Controls the amount of detail in the log returned in the build result.
         public var logging: BuildLogVerbosity
-        
+
+        /// Whether to print build logs to the console
+        public var echoLogs: Bool
+
         /// Additional flags to pass to all C compiler invocations.
         public var otherCFlags: [String] = []
 
@@ -72,9 +75,10 @@ public struct PackageManager {
         /// Additional flags to pass to all linker invocations.
         public var otherLinkerFlags: [String] = []
 
-        public init(configuration: BuildConfiguration = .debug, logging: BuildLogVerbosity = .concise) {
+        public init(configuration: BuildConfiguration = .debug, logging: BuildLogVerbosity = .concise, echoLogs: Bool = false) {
             self.configuration = configuration
             self.logging = logging
+            self.echoLogs = echoLogs
         }
     }
 
@@ -314,6 +318,7 @@ fileprivate extension PluginToHostMessage.BuildParameters {
     init(_ parameters: PackageManager.BuildParameters) {
         self.configuration = .init(parameters.configuration)
         self.logging = .init(parameters.logging)
+        self.echoLogs = parameters.echoLogs
         self.otherCFlags = parameters.otherCFlags
         self.otherCxxFlags = parameters.otherCxxFlags
         self.otherSwiftcFlags = parameters.otherSwiftcFlags

Sources/PackagePlugin/PluginMessages.swift

@@ -303,6 +303,7 @@ enum PluginToHostMessage: Codable {
             enum LogVerbosity: String, Codable {
                 case concise, verbose, debug
             }
+            var echoLogs: Bool
             var otherCFlags: [String]
             var otherCxxFlags: [String]
             var otherSwiftcFlags: [String]

Sources/SPMBuildCore/Plugins/PluginInvocation.swift

@@ -867,6 +867,7 @@ public struct PluginInvocationBuildParameters {
     public enum LogVerbosity: String {
         case concise, verbose, debug
     }
+    public var echoLogs: Bool
     public var otherCFlags: [String]
     public var otherCxxFlags: [String]
     public var otherSwiftcFlags: [String]
@@ -979,6 +980,7 @@ fileprivate extension PluginInvocationBuildParameters {
     init(_ parameters: PluginToHostMessage.BuildParameters) {
         self.configuration = .init(parameters.configuration)
         self.logging = .init(parameters.logging)
+        self.echoLogs = parameters.echoLogs
         self.otherCFlags = parameters.otherCFlags
         self.otherCxxFlags = parameters.otherCxxFlags
         self.otherSwiftcFlags = parameters.otherSwiftcFlags

Tests/CommandsTests/PackageToolTests.swift

@@ -2049,6 +2049,53 @@ final class PackageToolTests: CommandsTestCase {
         }
     }
 
+    // Test logging of builds initiated by a command plugin
+    func testCommandPluginBuildLogs() throws {
+        // Only run the test if the environment in which we're running actually supports Swift concurrency (which the plugin APIs require).
+        try XCTSkipIf(!UserToolchain.default.supportsSwiftConcurrency(), "skipping because test environment doesn't support concurrency")
+
+        // Match patterns for expected messages
+
+        let isEmpty = StringPattern.equal("")
+
+        // result.logText printed by the plugin has a prefix
+        let containsLogtext = StringPattern.contains("command plugin: packageManager.build logtext: Building for debugging...")
+
+        // Echoed logs have no prefix
+        let containsLogecho = StringPattern.regex("^Building for debugging...\n")
+
+        // These tests involve building a target, so each test must run with a fresh copy of the fixture
+        // otherwise the logs may be different in subsequent tests.
+
+        // Check than nothing is echoed when echoLogs is false
+        try fixture(name: "Miscellaneous/Plugins/CommandPluginTestStub") { fixturePath in
+            let (stdout, stderr) = try SwiftPM.Package.execute(["print-diagnostics", "build"], packagePath: fixturePath)
+            XCTAssertMatch(stdout, isEmpty)
+            XCTAssertMatch(stderr, isEmpty)
+        }
+
+        // Check that logs are returned to the plugin when echoLogs is false
+        try fixture(name: "Miscellaneous/Plugins/CommandPluginTestStub") { fixturePath in
+            let (stdout, stderr) = try SwiftPM.Package.execute(["print-diagnostics", "build", "printlogs"], packagePath: fixturePath)
+            XCTAssertMatch(stdout, containsLogtext)
+            XCTAssertMatch(stderr, isEmpty)
+        }
+
+        // Check that logs echoed to the console (on stderr) when echoLogs is true
+        try fixture(name: "Miscellaneous/Plugins/CommandPluginTestStub") { fixturePath in
+            let (stdout, stderr) = try SwiftPM.Package.execute(["print-diagnostics", "build", "echologs"], packagePath: fixturePath)
+            XCTAssertMatch(stdout, isEmpty)
+            XCTAssertMatch(stderr, containsLogecho)
+        }
+
+        // Check that logs are returned to the plugin and echoed to the console (on stderr) when echoLogs is true
+        try fixture(name: "Miscellaneous/Plugins/CommandPluginTestStub") { fixturePath in
+            let (stdout, stderr) = try SwiftPM.Package.execute(["print-diagnostics", "build", "printlogs", "echologs"], packagePath: fixturePath)
+            XCTAssertMatch(stdout, containsLogtext)
+            XCTAssertMatch(stderr, containsLogecho)
+        }
+    }
+
     func testCommandPluginNetworkingPermissions(permissionsManifestFragment: String, permissionError: String, reason: String, remedy: [String]) throws {
         // Only run the test if the environment in which we're running actually supports Swift concurrency (which the plugin APIs require).
         try XCTSkipIf(!UserToolchain.default.supportsSwiftConcurrency(), "skipping because test environment doesn't support concurrency")