From bca3a5f495130560a343bfeb4143919f0e77559d Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?David=20R=C3=B6nnqvist?= Date: Fri, 18 Oct 2024 19:19:48 +0200 Subject: [PATCH 1/9] Fix data race in `LogHandle.LogStorage` (used in tests to verify log output) --- Sources/SwiftDocC/Utility/LogHandle.swift | 7 +++++-- 1 file changed, 5 insertions(+), 2 deletions(-) diff --git a/Sources/SwiftDocC/Utility/LogHandle.swift b/Sources/SwiftDocC/Utility/LogHandle.swift index 40925f88ea..2cf48bca59 100644 --- a/Sources/SwiftDocC/Utility/LogHandle.swift +++ b/Sources/SwiftDocC/Utility/LogHandle.swift @@ -34,7 +34,10 @@ public enum LogHandle: TextOutputStream { /// A by-reference string storage. public class LogStorage { - var text = "" + var _text = Synchronized("") + var text: String { + _text.sync { $0 } + } } /// Writes the given string to the log handle. @@ -51,7 +54,7 @@ public enum LogHandle: TextOutputStream { case .file(let fileHandle): fileHandle.write(Data(string.utf8)) case .memory(let storage): - storage.text.append(string) + storage._text.sync { $0.append(string) } } } } From b40cd27a2acdd4980c6e983bda15588107d00c35 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?David=20R=C3=B6nnqvist?= Date: Fri, 18 Oct 2024 19:20:44 +0200 Subject: [PATCH 2/9] Fix start/stop data race in DirectoryMonitor rdar://137751315 --- .../SwiftDocC/Utility/Synchronization.swift | 8 ++--- .../Utility/DirectoryMonitor.swift | 34 +++++++++++-------- 2 files changed, 24 insertions(+), 18 deletions(-) diff --git a/Sources/SwiftDocC/Utility/Synchronization.swift b/Sources/SwiftDocC/Utility/Synchronization.swift index d4e4e2ad01..182ee89dc5 100644 --- a/Sources/SwiftDocC/Utility/Synchronization.swift +++ b/Sources/SwiftDocC/Utility/Synchronization.swift @@ -97,16 +97,16 @@ public class Synchronized { /// lock.sync { myVar = 1 } /// let result = lock.sync { return index["key"] } /// ``` -typealias Lock = Synchronized +package typealias Lock = Synchronized -public extension Lock { +extension Lock { /// Creates a new lock. - convenience init() { + package convenience init() { self.init(()) } @discardableResult - func sync(_ block: () throws -> Result) rethrows -> Result { + package func sync(_ block: () throws -> Result) rethrows -> Result { #if os(macOS) || os(iOS) os_unfair_lock_lock(lock) defer { os_unfair_lock_unlock(lock) } diff --git a/Sources/SwiftDocCUtilities/Utility/DirectoryMonitor.swift b/Sources/SwiftDocCUtilities/Utility/DirectoryMonitor.swift index 5c9e623ced..056eb473b9 100644 --- a/Sources/SwiftDocCUtilities/Utility/DirectoryMonitor.swift +++ b/Sources/SwiftDocCUtilities/Utility/DirectoryMonitor.swift @@ -207,18 +207,22 @@ class DirectoryMonitor { ) } + private var startStopLock = Lock() + /// Start monitoring the root directory and its contents. func start() throws { - let watchedFiles = try watchedURLChecksum() - lastChecksum = watchedFiles.checksum - - do { - watchedDirectories = try allDirectories(in: root) - .map { return try watchedDirectory(at: $0.directory, files: $0.files, on: monitorQueue) } - } catch Error.openFileHandleFailed(_, let errorCode) where errorCode == Error.tooManyOpenFilesErrorCode { - // In case we've reached the file descriptor limit throw a detailed user error - // with recovery instructions. - throw Error.reachedOpenFileLimit(watchedFiles.count) + try startStopLock.sync { + let watchedFiles = try watchedURLChecksum() + lastChecksum = watchedFiles.checksum + + do { + watchedDirectories = try allDirectories(in: root) + .map { return try watchedDirectory(at: $0.directory, files: $0.files, on: monitorQueue) } + } catch Error.openFileHandleFailed(_, let errorCode) where errorCode == Error.tooManyOpenFilesErrorCode { + // In case we've reached the file descriptor limit throw a detailed user error + // with recovery instructions. + throw Error.reachedOpenFileLimit(watchedFiles.count) + } } } @@ -229,12 +233,14 @@ class DirectoryMonitor { /// Stop monitoring. func stop() { - for directory in watchedDirectories { - for source in directory.sources { - source.cancel() + startStopLock.sync { + for directory in watchedDirectories { + for source in directory.sources { + source.cancel() + } } + watchedDirectories = [] } - watchedDirectories = [] } deinit { From 5c40155b6b58d5d2b5fa56e0c5b0c6834a3c3d4d Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?David=20R=C3=B6nnqvist?= Date: Fri, 18 Oct 2024 19:38:18 +0200 Subject: [PATCH 3/9] Fix possible data race to `PreviewAction.logHandle` --- .../Action/Actions/PreviewAction.swift | 50 +++++++++++-------- 1 file changed, 29 insertions(+), 21 deletions(-) diff --git a/Sources/SwiftDocCUtilities/Action/Actions/PreviewAction.swift b/Sources/SwiftDocCUtilities/Action/Actions/PreviewAction.swift index d9f09af2f2..fcce28c306 100644 --- a/Sources/SwiftDocCUtilities/Action/Actions/PreviewAction.swift +++ b/Sources/SwiftDocCUtilities/Action/Actions/PreviewAction.swift @@ -38,8 +38,6 @@ public final class PreviewAction: AsyncAction { static var allowConcurrentPreviews = false private let printHTMLTemplatePath: Bool - - var logHandle = LogHandle.standardOutput let port: Int @@ -89,17 +87,17 @@ public final class PreviewAction: AsyncAction { /// /// - Parameter logHandle: The file handle that the convert and preview actions will print debug messages to. public func perform(logHandle: inout LogHandle) async throws -> ActionResult { - self.logHandle = logHandle + self.logHandle.sync { $0 = logHandle } if let rootURL = convertAction.rootURL { - print("Input: \(rootURL.path)", to: &self.logHandle) + print("Input: \(rootURL.path)") } // TODO: This never did output human readable string; rdar://74324255 // print("Input: \(convertAction.documentationCoverageOptions)", to: &self.logHandle) // In case a developer is using a custom template log its path. if printHTMLTemplatePath, let htmlTemplateDirectory = convertAction.htmlTemplateDirectory { - print("Template: \(htmlTemplateDirectory.path)", to: &self.logHandle) + print("Template: \(htmlTemplateDirectory.path)") } let previewResult = try await preview() @@ -124,15 +122,16 @@ public final class PreviewAction: AsyncAction { let previewResult: ActionResult // Preview the output and monitor the source bundle for changes. do { - print(String(repeating: "=", count: 40), to: &logHandle) + print(String(repeating: "=", count: 40)) if let previewURL = URL(string: "http://localhost:\(port)") { - print("Starting Local Preview Server", to: &logHandle) + print("Starting Local Preview Server") printPreviewAddresses(base: previewURL) - print(String(repeating: "=", count: 40), to: &logHandle) + print(String(repeating: "=", count: 40)) } let to: PreviewServer.Bind = bindServerToSocketPath.map { .socket(path: $0) } ?? .localhost(port: port) - servers[serverIdentifier] = try PreviewServer(contentURL: convertAction.targetDirectory, bindTo: to, logHandle: &logHandle) + var logHandleCopy = logHandle.sync { $0 } + servers[serverIdentifier] = try PreviewServer(contentURL: convertAction.targetDirectory, bindTo: to, logHandle: &logHandleCopy) // When the user stops docc - stop the preview server first before exiting. trapSignals() @@ -159,7 +158,8 @@ public final class PreviewAction: AsyncAction { func convert() async throws -> ActionResult { convertAction = try createConvertAction() - let (result, context) = try await convertAction.perform(logHandle: &logHandle) + var logHandleCopy = logHandle.sync { $0 } + let (result, context) = try await convertAction.perform(logHandle: &logHandleCopy) previewPaths = try context.previewPaths() return result @@ -168,15 +168,23 @@ public final class PreviewAction: AsyncAction { private func printPreviewAddresses(base: URL) { // If the preview paths are empty, just print the base. let firstPath = previewPaths.first ?? "" - print("\t Address: \(base.appendingPathComponent(firstPath).absoluteString)", to: &logHandle) + print("\t Address: \(base.appendingPathComponent(firstPath).absoluteString)") let spacing = String(repeating: " ", count: "Address:".count) for previewPath in previewPaths.dropFirst() { - print("\t \(spacing) \(base.appendingPathComponent(previewPath).absoluteString)", to: &logHandle) + print("\t \(spacing) \(base.appendingPathComponent(previewPath).absoluteString)") + } + } + + private var logHandle: Synchronized = .init(.none) + + fileprivate func print(_ string: String, terminator: String = "\n") { + logHandle.sync { logHandle in + Swift.print(string, terminator: terminator, to: &logHandle) } } - var monitoredConvertTask: Task? + fileprivate var monitoredConvertTask: Task? } // Monitoring a source folder: Asynchronous output reading and file system events are supported only on macOS. @@ -192,7 +200,7 @@ extension PreviewAction { } monitor = try DirectoryMonitor(root: rootURL) { _, _ in - print("Source bundle was modified, converting... ", terminator: "", to: &self.logHandle) + self.print("Source bundle was modified, converting... ", terminator: "") self.monitoredConvertTask?.cancel() self.monitoredConvertTask = Task { defer { @@ -201,8 +209,8 @@ extension PreviewAction { try monitor.restart() } catch { // The file watching system API has thrown, stop watching. - print("Watching for changes has failed. To continue preview with watching restart docc.", to: &self.logHandle) - print(error.localizedDescription, to: &self.logHandle) + self.print("Watching for changes has failed. To continue preview with watching restart docc.") + self.print(error.localizedDescription) } } @@ -211,19 +219,19 @@ extension PreviewAction { if result.didEncounterError { throw ErrorsEncountered() } - print("Done.", to: &self.logHandle) + self.print("Done.") } catch DocumentationContext.ContextError.registrationDisabled { // The context cancelled loading the bundles and threw to yield execution early. - print("\nConversion cancelled...", to: &self.logHandle) + self.print("\nConversion cancelled...") } catch is CancellationError { - print("\nConversion cancelled...", to: &self.logHandle) + self.print("\nConversion cancelled...") } catch { - print("\n\(error.localizedDescription)\nCompilation failed", to: &self.logHandle) + self.print("\n\(error.localizedDescription)\nCompilation failed") } } } try monitor.start() - print("Monitoring \(rootURL.path) for changes...", to: &self.logHandle) + self.print("Monitoring \(rootURL.path) for changes...") } } #endif // !os(Linux) && !os(Android) From 8e4538ff7d4c1ff542e9c6cc29e3e4c0ba005f7f Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?David=20R=C3=B6nnqvist?= Date: Mon, 21 Oct 2024 16:40:42 +0200 Subject: [PATCH 4/9] Fix possible data race in loading symbol graphs for different platforms --- .../Infrastructure/Symbol Graph/SymbolGraphLoader.swift | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/Sources/SwiftDocC/Infrastructure/Symbol Graph/SymbolGraphLoader.swift b/Sources/SwiftDocC/Infrastructure/Symbol Graph/SymbolGraphLoader.swift index a2f23813df..a7a142e483 100644 --- a/Sources/SwiftDocC/Infrastructure/Symbol Graph/SymbolGraphLoader.swift +++ b/Sources/SwiftDocC/Infrastructure/Symbol Graph/SymbolGraphLoader.swift @@ -61,7 +61,7 @@ struct SymbolGraphLoader { let loadGraphAtURL: (URL) -> Void = { [dataLoader, bundle] symbolGraphURL in // Bail out in case a symbol graph has already errored - guard loadError == nil else { return } + guard loadingLock.sync({ loadError == nil }) else { return } do { // Load and decode a single symbol graph file From 7b49e9431123642da32d1ce3c8bcb34809169556 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?David=20R=C3=B6nnqvist?= Date: Mon, 21 Oct 2024 16:41:20 +0200 Subject: [PATCH 5/9] Remove unnecessary restart of the directory monitor --- .../Action/Actions/PreviewAction.swift | 11 ----------- 1 file changed, 11 deletions(-) diff --git a/Sources/SwiftDocCUtilities/Action/Actions/PreviewAction.swift b/Sources/SwiftDocCUtilities/Action/Actions/PreviewAction.swift index fcce28c306..39a946b68b 100644 --- a/Sources/SwiftDocCUtilities/Action/Actions/PreviewAction.swift +++ b/Sources/SwiftDocCUtilities/Action/Actions/PreviewAction.swift @@ -203,17 +203,6 @@ extension PreviewAction { self.print("Source bundle was modified, converting... ", terminator: "") self.monitoredConvertTask?.cancel() self.monitoredConvertTask = Task { - defer { - // Reload the directory contents and start to monitor for changes. - do { - try monitor.restart() - } catch { - // The file watching system API has thrown, stop watching. - self.print("Watching for changes has failed. To continue preview with watching restart docc.") - self.print(error.localizedDescription) - } - } - do { let result = try await self.convert() if result.didEncounterError { From db519043ae8fc13f1b8f4936f5fdc07733b9d203 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?David=20R=C3=B6nnqvist?= Date: Wed, 23 Oct 2024 15:18:48 +0200 Subject: [PATCH 6/9] Use shorter temporary unix domain socket path in tests --- .../PreviewActionIntegrationTests.swift | 39 ++++++++++++++++++- 1 file changed, 37 insertions(+), 2 deletions(-) diff --git a/Tests/SwiftDocCUtilitiesTests/PreviewActionIntegrationTests.swift b/Tests/SwiftDocCUtilitiesTests/PreviewActionIntegrationTests.swift index 98017e3c74..76bbff4e92 100644 --- a/Tests/SwiftDocCUtilitiesTests/PreviewActionIntegrationTests.swift +++ b/Tests/SwiftDocCUtilitiesTests/PreviewActionIntegrationTests.swift @@ -235,8 +235,7 @@ class PreviewActionIntegrationTests: XCTestCase { try? preview.stop() } - let socketURL = try createTemporaryDirectory().appendingPathComponent("sock") - preview.bindServerToSocketPath = socketURL.path + preview.bindServerToSocketPath = try createTemporaryTestSocketPath() let logStorage = LogHandle.LogStorage() // Start watching the source and get the initial (successful) state. @@ -330,6 +329,42 @@ class PreviewActionIntegrationTests: XCTestCase { // MARK: - + private func createTemporaryTestSocketPath() throws -> String { + // The unix domain socket paths have a character limit that we need to stay under. + + func isShortEnoughUnixDomainSocket(_ url: URL) -> Bool { + url.path.utf8.count <= 103 + } + + // Prefer a temporary socket URL that's relative to the unit test bundle location if possible + let bundleRelativeSocketURL = try createTemporaryDirectory().appendingPathComponent("s", isDirectory: false) + if isShortEnoughUnixDomainSocket(bundleRelativeSocketURL) { + return bundleRelativeSocketURL.path + } + + // If that URL was to long, try a temporary socket URL in the user's shared temporary directory. + // The added "doc" and UUID components should be sufficient to avoid collisions with other tests or other processes. + + let tempDir = URL(fileURLWithPath: Foundation.NSTemporaryDirectory()) + .appendingPathComponent("docc", isDirectory: true) + .appendingPathComponent(UUID().uuidString, isDirectory: true) + + let socketURL = tempDir.appendingPathComponent("s", isDirectory: false) + + // If we couldn't create short enough socket path, skip the tests rather than fail them to avoid flakiness in the CI. + // The current implementation _should_ result in a path that's around 92 characters long, so the 11 character headroom + // should cover some amount of hypothetical changes to the `NSTemporaryDirectory` length and the `UUID().uuidString` length. + try XCTSkipIf(!isShortEnoughUnixDomainSocket(socketURL), + "Temporary socket path \(socketURL.path.singleQuoted) is too long (\(socketURL.path.utf8.count) character) to start a preview server.") + + try FileManager.default.createDirectory(at: tempDir, withIntermediateDirectories: true) + addTeardownBlock { + try? FileManager.default.removeItem(at: tempDir) + } + + return socketURL.path + } + override static func setUp() { super.setUp() PreviewAction.allowConcurrentPreviews = true From f6595aa3bdce0ecacb9466a16773b0b64f85350a Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?David=20R=C3=B6nnqvist?= Date: Wed, 23 Oct 2024 15:18:04 +0200 Subject: [PATCH 7/9] Add extra test assertion if we ever need to debug more flakiness in this test --- .../PreviewActionIntegrationTests.swift | 10 ++++++++++ 1 file changed, 10 insertions(+) diff --git a/Tests/SwiftDocCUtilitiesTests/PreviewActionIntegrationTests.swift b/Tests/SwiftDocCUtilitiesTests/PreviewActionIntegrationTests.swift index 76bbff4e92..3b6c575bac 100644 --- a/Tests/SwiftDocCUtilitiesTests/PreviewActionIntegrationTests.swift +++ b/Tests/SwiftDocCUtilitiesTests/PreviewActionIntegrationTests.swift @@ -287,6 +287,16 @@ class PreviewActionIntegrationTests: XCTestCase { // This should only take 1.5 seconds (1 second for the directory monitor debounce and 0.5 seconds for the expectation poll interval) await fulfillment(of: [expectation], timeout: 20.0) + // This assertion is always true if the expectation was fulfilled. However, in the past this expectation has sometimes (but very rarely) failed. + // If that happens we want to print the full preview action log to help investigate what went wrong. + XCTAssert(logStorage.text.contains("Conversion cancelled..."), + """ + PreviewAction log output doesn't contain 'Conversion cancelled...'. + Full log output from the preview action that ran in this test (to investigate the issue): + -------------------------------------------------- + \(logStorage.text) + -------------------------------------------------- + """) } #endif From 5b4f6a7c14bd5bd7a35c04b2445ff16b14bfe7eb Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?David=20R=C3=B6nnqvist?= Date: Wed, 23 Oct 2024 15:19:29 +0200 Subject: [PATCH 8/9] Reenable `testCancelsConversion` --- .../SwiftDocCUtilitiesTests/PreviewActionIntegrationTests.swift | 1 - 1 file changed, 1 deletion(-) diff --git a/Tests/SwiftDocCUtilitiesTests/PreviewActionIntegrationTests.swift b/Tests/SwiftDocCUtilitiesTests/PreviewActionIntegrationTests.swift index 3b6c575bac..2725e6b7e4 100644 --- a/Tests/SwiftDocCUtilitiesTests/PreviewActionIntegrationTests.swift +++ b/Tests/SwiftDocCUtilitiesTests/PreviewActionIntegrationTests.swift @@ -194,7 +194,6 @@ class PreviewActionIntegrationTests: XCTestCase { func testCancelsConversion() async throws { #if os(macOS) - throw XCTSkip("To be reenabled again by #1059") let (sourceURL, outputURL, templateURL) = try createPreviewSetup(source: createMinimalDocsBundle()) defer { try? FileManager.default.removeItem(at: sourceURL) From 756cb7e122a00310a63a5343740f523268c255cb Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?David=20R=C3=B6nnqvist?= Date: Wed, 23 Oct 2024 15:23:23 +0200 Subject: [PATCH 9/9] Add back reimplementation of `testWatchRecoversAfterConversionErrors` --- .../PreviewActionIntegrationTests.swift | 124 ++++++++++++++++++ 1 file changed, 124 insertions(+) diff --git a/Tests/SwiftDocCUtilitiesTests/PreviewActionIntegrationTests.swift b/Tests/SwiftDocCUtilitiesTests/PreviewActionIntegrationTests.swift index 2725e6b7e4..9e25ec6ed3 100644 --- a/Tests/SwiftDocCUtilitiesTests/PreviewActionIntegrationTests.swift +++ b/Tests/SwiftDocCUtilitiesTests/PreviewActionIntegrationTests.swift @@ -63,6 +63,130 @@ class PreviewActionIntegrationTests: XCTestCase { return (sourceURL: sourceURL, outputURL: outputURL, templateURL: templateURL) } + func testWatchRecoversAfterConversionErrors() async throws { + #if os(macOS) + let (sourceURL, outputURL, templateURL) = try createPreviewSetup(source: createMinimalDocsBundle()) + defer { + try? FileManager.default.removeItem(at: sourceURL) + try? FileManager.default.removeItem(at: outputURL) + try? FileManager.default.removeItem(at: templateURL) + } + + // A FileHandle to read action's output. + let pipeURL = try createTemporaryDirectory().appendingPathComponent("pipe") + try Data().write(to: pipeURL) + let fileHandle = try FileHandle(forUpdating: pipeURL) + defer { fileHandle.closeFile() } + + let convertActionTempDirectory = try createTemporaryDirectory() + let createConvertAction = { + try ConvertAction( + documentationBundleURL: sourceURL, + outOfProcessResolver: nil, + analyze: false, + targetDirectory: outputURL, + htmlTemplateDirectory: templateURL, + emitDigest: false, + currentPlatforms: nil, + fileManager: FileManager.default, + temporaryDirectory: convertActionTempDirectory) + } + + let preview = try PreviewAction( + port: 8080, // We ignore this value when we set the `bindServerToSocketPath` property below. + createConvertAction: createConvertAction + ) + defer { + try? preview.stop() + } + + preview.bindServerToSocketPath = try createTemporaryTestSocketPath() + + let logStorage = LogHandle.LogStorage() + + // The technology output file URL + let convertedOverviewURL = outputURL + .appendingPathComponent("data") + .appendingPathComponent("tutorials") + .appendingPathComponent("Overview.json") + + // Start watching the source and get the initial (successful) state. + do { + let didStartServerExpectation = asyncLogExpectation(log: logStorage, description: "Did start the preview server", expectedText: "=======") + + // Start the preview and keep it running for the asserts that follow inside this test. + Task { + var logHandle = LogHandle.memory(logStorage) + let result = try await preview.perform(logHandle: &logHandle) + + guard !result.problems.containsErrors else { + throw ErrorsEncountered() + } + } + + // This should only take 1.5 seconds (1 second for the directory monitor debounce and 0.5 seconds for the expectation poll interval) + await fulfillment(of: [didStartServerExpectation], timeout: 20.0) + + // Check the log output to confirm that expected informational text is printed + let logOutput = logStorage.text + + let expectedLogIntroductoryOutput = """ + Input: \(sourceURL.path) + Template: \(templateURL.path) + """ + XCTAssertTrue(logOutput.hasPrefix(expectedLogIntroductoryOutput), """ + Missing expected input and template information in log/print output + """) + + if let previewInfoStart = logOutput.range(of: "=====\n")?.upperBound, + let previewInfoEnd = logOutput[previewInfoStart...].range(of: "\n=====")?.lowerBound { + XCTAssertEqual(logOutput[previewInfoStart..