From c142b601ffd031e070ccf6c91eb08a57f8d45e00 Mon Sep 17 00:00:00 2001 From: Alex Hoppen Date: Mon, 1 Sep 2025 16:02:49 +0200 Subject: [PATCH] Add a timeout for `workspace/buildTargets` and `buildTarget/sources` requests This allows us to provide functionality based on fallback settings for unresponsive BSP servers. Fixes #2252 --- Documentation/Configuration File.md | 1 + .../BuildServerManager.swift | 141 +++++++++++++----- .../BuildServerManagerDelegate.swift | 2 +- Sources/SKOptions/SourceKitLSPOptions.swift | 24 ++- .../SemanticIndex/SemanticIndexManager.swift | 9 +- Sources/SourceKitLSP/Workspace.swift | 4 +- Sources/SwiftExtensions/AsyncUtils.swift | 20 ++- Sources/SwiftExtensions/Cache.swift | 9 ++ .../BuildSystemManagerTests.swift | 2 +- .../ExternalBuildServerTests.swift | 89 +++++++++++ config.schema.json | 5 + 11 files changed, 248 insertions(+), 58 deletions(-) diff --git a/Documentation/Configuration File.md b/Documentation/Configuration File.md index 27e31a060..6ca95bac6 100644 --- a/Documentation/Configuration File.md +++ b/Documentation/Configuration File.md @@ -59,3 +59,4 @@ The structure of the file is currently not guaranteed to be stable. Options may - `workDoneProgressDebounceDuration: number`: When a task is started that should be displayed to the client as a work done progress, how many milliseconds to wait before actually starting the work done progress. This prevents flickering of the work done progress in the client for short-lived index tasks which end within this duration. - `sourcekitdRequestTimeout: number`: The maximum duration that a sourcekitd request should be allowed to execute before being declared as timed out. In general, editors should cancel requests that they are no longer interested in, but in case editors don't cancel requests, this ensures that a long-running non-cancelled request is not blocking sourcekitd and thus most semantic functionality. In particular, VS Code does not cancel the semantic tokens request, which can cause a long-running AST build that blocks sourcekitd. - `semanticServiceRestartTimeout: number`: If a request to sourcekitd or clangd exceeds this timeout, we assume that the semantic service provider is hanging for some reason and won't recover. To restore semantic functionality, we terminate and restart it. +- `buildServerWorkspaceRequestsTimeout: number`: Duration how long to wait for responses to `workspace/buildTargets` or `buildTarget/sources` request by the build server before defaulting to an empty response. diff --git a/Sources/BuildServerIntegration/BuildServerManager.swift b/Sources/BuildServerIntegration/BuildServerManager.swift index b71285afc..a9763a54d 100644 --- a/Sources/BuildServerIntegration/BuildServerManager.swift +++ b/Sources/BuildServerIntegration/BuildServerManager.swift @@ -482,8 +482,7 @@ package actor BuildServerManager: QueueBasedMessageHandler { self.filesDependenciesUpdatedDebouncer = Debouncer( debounceDuration: .milliseconds(500), combineResults: { $0.union($1) }, - makeCall: { - [weak self] (filesWithUpdatedDependencies) in + makeCall: { [weak self] (filesWithUpdatedDependencies) in guard let self, let delegate = await self.delegate else { logger.fault("Not calling filesDependenciesUpdated because no delegate exists in SwiftPMBuildServer") return @@ -502,8 +501,7 @@ package actor BuildServerManager: QueueBasedMessageHandler { self.filesBuildSettingsChangedDebouncer = Debouncer( debounceDuration: .milliseconds(20), combineResults: { $0.union($1) }, - makeCall: { - [weak self] (filesWithChangedBuildSettings) in + makeCall: { [weak self] (filesWithChangedBuildSettings) in guard let self, let delegate = await self.delegate else { logger.fault("Not calling fileBuildSettingsChanged because no delegate exists in SwiftPMBuildServer") return @@ -670,31 +668,76 @@ package actor BuildServerManager: QueueBasedMessageHandler { } private func didChangeBuildTarget(notification: OnBuildTargetDidChangeNotification) async { - let updatedTargets: Set? = + let changedTargets: Set? = if let changes = notification.changes { Set(changes.map(\.target)) } else { nil } - self.cachedAdjustedSourceKitOptions.clear(isolation: self) { cacheKey in - guard let updatedTargets else { - // All targets might have changed - return true + await self.buildTargetsDidChange(.didChangeBuildTargets(changedTargets: changedTargets)) + } + + private enum BuildTargetsChange { + case didChangeBuildTargets(changedTargets: Set?) + case buildTargetsReceivedResultAfterTimeout( + request: WorkspaceBuildTargetsRequest, + newResult: [BuildTargetIdentifier: BuildTargetInfo] + ) + case sourceFilesReceivedResultAfterTimeout( + request: BuildTargetSourcesRequest, + newResult: BuildTargetSourcesResponse + ) + } + + /// Update the cached state in `BuildServerManager` because new data was received from the BSP server. + /// + /// This handles a few seemingly unrelated reasons to ensure that we think about which caches to invalidate in the + /// other scenarios as well, when making changes in here. + private func buildTargetsDidChange(_ stateChange: BuildTargetsChange) async { + let changedTargets: Set? + + switch stateChange { + case .didChangeBuildTargets(let changedTargetsValue): + changedTargets = changedTargetsValue + self.cachedAdjustedSourceKitOptions.clear(isolation: self) { cacheKey in + guard let changedTargets else { + // All targets might have changed + return true + } + return changedTargets.contains(cacheKey.target) } - return updatedTargets.contains(cacheKey.target) - } - self.cachedBuildTargets.clearAll(isolation: self) - self.cachedTargetSources.clear(isolation: self) { cacheKey in - guard let updatedTargets else { - // All targets might have changed - return true + self.cachedBuildTargets.clearAll(isolation: self) + self.cachedTargetSources.clear(isolation: self) { cacheKey in + guard let changedTargets else { + // All targets might have changed + return true + } + return !changedTargets.intersection(cacheKey.targets).isEmpty } - return !updatedTargets.intersection(cacheKey.targets).isEmpty - } + case .buildTargetsReceivedResultAfterTimeout(let request, let newResult): + changedTargets = nil + + // Caches not invalidated: + // - cachedAdjustedSourceKitOptions: We would not have requested SourceKit options for targets that we didn't + // know about. Even if we did, the build server now telling us about the target should not change the options of + // the file within the target + // - cachedTargetSources: Similar to cachedAdjustedSourceKitOptions, we would not have requested sources for + // targets that we didn't know about and if we did, they wouldn't be affected + self.cachedBuildTargets.set(request, to: newResult) + case .sourceFilesReceivedResultAfterTimeout(let request, let newResult): + changedTargets = Set(request.targets) + + // Caches not invalidated: + // - cachedAdjustedSourceKitOptions: Same as for buildTargetsReceivedResultAfterTimeout. + // - cachedBuildTargets: Getting a result for the source files in a target doesn't change anything about the + // target's existence. + self.cachedTargetSources.set(request, to: newResult) + } + // Clear caches that capture global state and are affected by all changes self.cachedSourceFilesAndDirectories.clearAll(isolation: self) self.scheduleRecomputeCopyFileMap() - await delegate?.buildTargetsChanged(notification.changes) + await delegate?.buildTargetsChanged(changedTargets) await filesBuildSettingsChangedDebouncer.scheduleCall(Set(watchedFiles.keys)) } @@ -896,6 +939,7 @@ package actor BuildServerManager: QueueBasedMessageHandler { previousUpdateTask?.cancel() await orLog("Re-computing copy file map") { let sourceFilesAndDirectories = try await self.sourceFilesAndDirectories() + try Task.checkCancellation() var copiedFileMap: [DocumentURI: DocumentURI] = [:] for (file, fileInfo) in sourceFilesAndDirectories.files { for copyDestination in fileInfo.copyDestinations { @@ -1022,7 +1066,7 @@ package actor BuildServerManager: QueueBasedMessageHandler { if fallbackAfterTimeout { try await withTimeout(options.buildSettingsTimeoutOrDefault) { return try await self.buildSettingsFromBuildServer(for: document, in: target, language: language) - } resultReceivedAfterTimeout: { + } resultReceivedAfterTimeout: { _ in await self.filesBuildSettingsChangedDebouncer.scheduleCall([document]) } } else { @@ -1080,7 +1124,7 @@ package actor BuildServerManager: QueueBasedMessageHandler { } else { try await withTimeout(options.buildSettingsTimeoutOrDefault) { await self.canonicalTarget(for: mainFile) - } resultReceivedAfterTimeout: { + } resultReceivedAfterTimeout: { _ in await self.filesBuildSettingsChangedDebouncer.scheduleCall([document]) } } @@ -1234,28 +1278,39 @@ package actor BuildServerManager: QueueBasedMessageHandler { let request = WorkspaceBuildTargetsRequest() let result = try await cachedBuildTargets.get(request, isolation: self) { request in - let buildTargets = try await buildServerAdapter.send(request).targets - let (depths, dependents) = await self.targetDepthsAndDependents(for: buildTargets) - var result: [BuildTargetIdentifier: BuildTargetInfo] = [:] - result.reserveCapacity(buildTargets.count) - for buildTarget in buildTargets { - guard result[buildTarget.id] == nil else { - logger.error("Found two targets with the same ID \(buildTarget.id)") - continue - } - let depth: Int - if let d = depths[buildTarget.id] { - depth = d - } else { - logger.fault("Did not compute depth for target \(buildTarget.id)") - depth = 0 + let result = try await withTimeout(self.options.buildServerWorkspaceRequestsTimeoutOrDefault) { + let buildTargets = try await buildServerAdapter.send(request).targets + let (depths, dependents) = await self.targetDepthsAndDependents(for: buildTargets) + var result: [BuildTargetIdentifier: BuildTargetInfo] = [:] + result.reserveCapacity(buildTargets.count) + for buildTarget in buildTargets { + guard result[buildTarget.id] == nil else { + logger.error("Found two targets with the same ID \(buildTarget.id)") + continue + } + let depth: Int + if let d = depths[buildTarget.id] { + depth = d + } else { + logger.fault("Did not compute depth for target \(buildTarget.id)") + depth = 0 + } + result[buildTarget.id] = BuildTargetInfo( + target: buildTarget, + depth: depth, + dependents: dependents[buildTarget.id] ?? [] + ) } - result[buildTarget.id] = BuildTargetInfo( - target: buildTarget, - depth: depth, - dependents: dependents[buildTarget.id] ?? [] + return result + } resultReceivedAfterTimeout: { newResult in + await self.buildTargetsDidChange( + .buildTargetsReceivedResultAfterTimeout(request: request, newResult: newResult) ) } + guard let result else { + logger.error("Failed to get targets of workspace within timeout") + return [:] + } return result } return result @@ -1288,7 +1343,11 @@ package actor BuildServerManager: QueueBasedMessageHandler { } let response = try await cachedTargetSources.get(request, isolation: self) { request in - try await buildServerAdapter.send(request) + try await withTimeout(self.options.buildServerWorkspaceRequestsTimeoutOrDefault) { + return try await buildServerAdapter.send(request) + } resultReceivedAfterTimeout: { newResult in + await self.buildTargetsDidChange(.sourceFilesReceivedResultAfterTimeout(request: request, newResult: newResult)) + } ?? BuildTargetSourcesResponse(items: []) } return response.items } diff --git a/Sources/BuildServerIntegration/BuildServerManagerDelegate.swift b/Sources/BuildServerIntegration/BuildServerManagerDelegate.swift index d03c8e44c..92137f7cf 100644 --- a/Sources/BuildServerIntegration/BuildServerManagerDelegate.swift +++ b/Sources/BuildServerIntegration/BuildServerManagerDelegate.swift @@ -29,7 +29,7 @@ package protocol BuildServerManagerDelegate: AnyObject, Sendable { /// Notify the delegate that some information about the given build targets has changed and that it should recompute /// any information based on top of it. - func buildTargetsChanged(_ changes: [BuildTargetEvent]?) async + func buildTargetsChanged(_ changedTargets: Set?) async } /// Methods with which the `BuildServerManager` can send messages to the client (aka. editor). diff --git a/Sources/SKOptions/SourceKitLSPOptions.swift b/Sources/SKOptions/SourceKitLSPOptions.swift index dbf07658a..49ac7deb6 100644 --- a/Sources/SKOptions/SourceKitLSPOptions.swift +++ b/Sources/SKOptions/SourceKitLSPOptions.swift @@ -433,6 +433,22 @@ public struct SourceKitLSPOptions: Sendable, Codable, Equatable { return .seconds(300) } + /// Duration how long to wait for responses to `workspace/buildTargets` or `buildTarget/sources` request by the build + /// server before defaulting to an empty response. + public var buildServerWorkspaceRequestsTimeout: Double? = nil + + public var buildServerWorkspaceRequestsTimeoutOrDefault: Duration { + if let buildServerWorkspaceRequestsTimeout { + return .seconds(buildServerWorkspaceRequestsTimeout) + } + // The default value needs to strike a balance: If the build server is slow to respond, we don't want to constantly + // run into this timeout, which causes somewhat expensive computations because we trigger the `buildTargetsChanged` + // chain. + // At the same time, we do want to provide functionality based on fallback settings after some time. + // 15s seems like it should strike a balance here but there is no data backing this value up. + return .seconds(15) + } + public init( swiftPM: SwiftPMOptions? = .init(), fallbackBuildSystem: FallbackBuildSystemOptions? = .init(), @@ -451,7 +467,8 @@ public struct SourceKitLSPOptions: Sendable, Codable, Equatable { swiftPublishDiagnosticsDebounceDuration: Double? = nil, workDoneProgressDebounceDuration: Double? = nil, sourcekitdRequestTimeout: Double? = nil, - semanticServiceRestartTimeout: Double? = nil + semanticServiceRestartTimeout: Double? = nil, + buildServerWorkspaceRequestsTimeout: Double? = nil ) { self.swiftPM = swiftPM self.fallbackBuildSystem = fallbackBuildSystem @@ -471,6 +488,7 @@ public struct SourceKitLSPOptions: Sendable, Codable, Equatable { self.workDoneProgressDebounceDuration = workDoneProgressDebounceDuration self.sourcekitdRequestTimeout = sourcekitdRequestTimeout self.semanticServiceRestartTimeout = semanticServiceRestartTimeout + self.buildServerWorkspaceRequestsTimeout = buildServerWorkspaceRequestsTimeout } public init?(fromLSPAny lspAny: LSPAny?) throws { @@ -531,7 +549,9 @@ public struct SourceKitLSPOptions: Sendable, Codable, Equatable { workDoneProgressDebounceDuration: override?.workDoneProgressDebounceDuration ?? base.workDoneProgressDebounceDuration, sourcekitdRequestTimeout: override?.sourcekitdRequestTimeout ?? base.sourcekitdRequestTimeout, - semanticServiceRestartTimeout: override?.semanticServiceRestartTimeout ?? base.semanticServiceRestartTimeout + semanticServiceRestartTimeout: override?.semanticServiceRestartTimeout ?? base.semanticServiceRestartTimeout, + buildServerWorkspaceRequestsTimeout: override?.buildServerWorkspaceRequestsTimeout + ?? base.buildServerWorkspaceRequestsTimeout ) } diff --git a/Sources/SemanticIndex/SemanticIndexManager.swift b/Sources/SemanticIndex/SemanticIndexManager.swift index 4c1a179d9..c7bd7c71b 100644 --- a/Sources/SemanticIndex/SemanticIndexManager.swift +++ b/Sources/SemanticIndex/SemanticIndexManager.swift @@ -416,14 +416,7 @@ package final actor SemanticIndexManager { } } - package func buildTargetsChanged(_ changes: [BuildTargetEvent]?) async { - let targets: Set? = - if let changes = changes?.map(\.target) { - Set(changes) - } else { - nil - } - + package func buildTargetsChanged(_ targets: Set?) async { if let targets { var targetsAndDependencies = targets targetsAndDependencies.formUnion(await buildServerManager.targets(dependingOn: targets)) diff --git a/Sources/SourceKitLSP/Workspace.swift b/Sources/SourceKitLSP/Workspace.swift index 0b0e1bf08..165ea4e29 100644 --- a/Sources/SourceKitLSP/Workspace.swift +++ b/Sources/SourceKitLSP/Workspace.swift @@ -468,9 +468,9 @@ package final class Workspace: Sendable, BuildServerManagerDelegate { } } - package func buildTargetsChanged(_ changes: [BuildTargetEvent]?) async { + package func buildTargetsChanged(_ changedTargets: Set?) async { await sourceKitLSPServer?.fileHandlingCapabilityChanged() - await semanticIndexManager?.buildTargetsChanged(changes) + await semanticIndexManager?.buildTargetsChanged(changedTargets) await orLog("Scheduling syntactic test re-indexing") { let testFiles = try await buildServerManager.testFiles() await syntacticTestIndex.listOfTestFilesDidChange(testFiles) diff --git a/Sources/SwiftExtensions/AsyncUtils.swift b/Sources/SwiftExtensions/AsyncUtils.swift index 8a9f57640..bda889aef 100644 --- a/Sources/SwiftExtensions/AsyncUtils.swift +++ b/Sources/SwiftExtensions/AsyncUtils.swift @@ -270,8 +270,8 @@ package func withTimeout( /// `body` should be cancelled after `timeout`. package func withTimeout( _ timeout: Duration, - body: @escaping @Sendable () async throws -> T?, - resultReceivedAfterTimeout: @escaping @Sendable () async -> Void + body: @escaping @Sendable () async throws -> T, + resultReceivedAfterTimeout: @escaping @Sendable (_ result: T) async -> Void ) async throws -> T? { let didHitTimeout = AtomicBool(initialValue: false) @@ -286,7 +286,7 @@ package func withTimeout( do { let result = try await body() if didHitTimeout.value { - await resultReceivedAfterTimeout() + await resultReceivedAfterTimeout(result) } continuation.yield(result) } catch { @@ -306,3 +306,17 @@ package func withTimeout( preconditionFailure("Continuation never finishes") } } + +/// Same as `withTimeout` above but allows `body` to return an optional value. +package func withTimeout( + _ timeout: Duration, + body: @escaping @Sendable () async throws -> T?, + resultReceivedAfterTimeout: @escaping @Sendable (_ result: T?) async -> Void +) async throws -> T? { + let result: T?? = try await withTimeout(timeout, body: body, resultReceivedAfterTimeout: resultReceivedAfterTimeout) + switch result { + case .none: return nil + case .some(.none): return nil + case .some(.some(let value)): return value + } +} diff --git a/Sources/SwiftExtensions/Cache.swift b/Sources/SwiftExtensions/Cache.swift index debb7a026..5b93bf2f0 100644 --- a/Sources/SwiftExtensions/Cache.swift +++ b/Sources/SwiftExtensions/Cache.swift @@ -33,6 +33,15 @@ package class Cache { return try await task.value } + /// Force the value for a specific key to a value. + /// + /// This should only be used if a value for this key is received by means that aren't covered through the `compute` + /// function in `get`. An example of this is receiving the results of a BSP request after a timeout, in which case we + /// would have cached the timeout result through `get` but now we have an updated value. + package func set(_ key: Key, to value: Result) { + storage[key] = Task { value } + } + /// Get the value cached for `key`. If no value exists for `key`, try deriving the result from an existing cache entry /// that satisfies `canReuseKey` by applying `transform` to that result. package func getDerived( diff --git a/Tests/BuildServerIntegrationTests/BuildSystemManagerTests.swift b/Tests/BuildServerIntegrationTests/BuildSystemManagerTests.swift index 3d0b39ed5..222a6d594 100644 --- a/Tests/BuildServerIntegrationTests/BuildSystemManagerTests.swift +++ b/Tests/BuildServerIntegrationTests/BuildSystemManagerTests.swift @@ -428,7 +428,7 @@ private actor BSMDelegate: BuildServerManagerDelegate { func filesDependenciesUpdated(_ changedFiles: Set) {} - func buildTargetsChanged(_ changes: [BuildTargetEvent]?) async {} + func buildTargetsChanged(_ changedTargets: Set?) async {} var clientSupportsWorkDoneProgress: Bool { false } diff --git a/Tests/BuildServerIntegrationTests/ExternalBuildServerTests.swift b/Tests/BuildServerIntegrationTests/ExternalBuildServerTests.swift index c12fef2a8..f7db89d4e 100644 --- a/Tests/BuildServerIntegrationTests/ExternalBuildServerTests.swift +++ b/Tests/BuildServerIntegrationTests/ExternalBuildServerTests.swift @@ -680,4 +680,93 @@ final class ExternalBuildServerTests: XCTestCase { let message = try await project.testClient.nextNotification(ofType: ShowMessageNotification.self) assertContains(message.message, "Initialization failed with bad error") } + + func testBuildServerTakesLongToReply() async throws { + actor BuildServer: CustomBuildServer { + let inProgressRequestsTracker = CustomBuildServerInProgressRequestTracker() + let projectRoot: URL + let unlockBuildServerResponses = MultiEntrySemaphore(name: "Build server starts responding") + var didReceiveTargetSourcesRequest = false + var didReceiveBuildTargetsRequest = false + + init(projectRoot: URL, connectionToSourceKitLSP: any Connection) { + self.projectRoot = projectRoot + } + + func workspaceBuildTargetsRequest( + _ request: WorkspaceBuildTargetsRequest + ) async throws -> WorkspaceBuildTargetsResponse { + // We should cache the result of the request once we receive it and not re-request information after the build + // server request timeout has fired + XCTAssert(!didReceiveBuildTargetsRequest) + didReceiveBuildTargetsRequest = true + + await unlockBuildServerResponses.waitOrXCTFail() + + return WorkspaceBuildTargetsResponse(targets: [ + BuildTarget( + id: .dummy, + capabilities: BuildTargetCapabilities(), + languageIds: [], + dependencies: [] + ) + ]) + } + + func buildTargetSourcesRequest(_ request: BuildTargetSourcesRequest) async throws -> BuildTargetSourcesResponse { + // We should cache the result of the request once we receive it and not re-request information after the build + // server request timeout has fired + XCTAssert(!didReceiveTargetSourcesRequest) + didReceiveTargetSourcesRequest = true + + await unlockBuildServerResponses.waitOrXCTFail() + return dummyTargetSourcesResponse(files: [DocumentURI(projectRoot.appendingPathComponent("Test.swift"))]) + } + + func textDocumentSourceKitOptionsRequest( + _ request: TextDocumentSourceKitOptionsRequest + ) async throws -> TextDocumentSourceKitOptionsResponse? { + var arguments = [request.textDocument.uri.pseudoPath, "-DFOO"] + if let defaultSDKPath { + arguments += ["-sdk", defaultSDKPath] + } + return TextDocumentSourceKitOptionsResponse(compilerArguments: arguments) + } + } + + var options = try await SourceKitLSPOptions.testDefault() + options.buildServerWorkspaceRequestsTimeout = 0.1 /* seconds */ + + let project = try await CustomBuildServerTestProject( + files: [ + "Test.swift": """ + #if FOO + func foo() {} + #endif + + func test() { + 1️⃣foo() + } + """ + ], + buildServer: BuildServer.self, + options: options + ) + + // Check that we can open a document using fallback settings even if the build server is unresponsive. + let (uri, positions) = try project.openDocument("Test.swift") + let definitionWithoutBuildServer = try await project.testClient.send( + DefinitionRequest(textDocument: TextDocumentIdentifier(uri), position: positions["1️⃣"]) + ) + XCTAssertEqual(definitionWithoutBuildServer?.locations, nil) + try project.buildServer().unlockBuildServerResponses.signal() + + // Once the build server starts being responsive, we should be able to get actual results. + try await repeatUntilExpectedResult { + let definitionsWithBuildServer = try await project.testClient.send( + DefinitionRequest(textDocument: TextDocumentIdentifier(uri), position: positions["1️⃣"]) + ) + return definitionsWithBuildServer?.locations?.count == 1 + } + } } diff --git a/config.schema.json b/config.schema.json index d22dfee11..b286aa0c2 100644 --- a/config.schema.json +++ b/config.schema.json @@ -22,6 +22,11 @@ ], "type" : "string" }, + "buildServerWorkspaceRequestsTimeout" : { + "description" : "Duration how long to wait for responses to `workspace/buildTargets` or `buildTarget/sources` request by the build server before defaulting to an empty response.", + "markdownDescription" : "Duration how long to wait for responses to `workspace/buildTargets` or `buildTarget/sources` request by the build server before defaulting to an empty response.", + "type" : "number" + }, "buildSettingsTimeout" : { "description" : "Number of milliseconds to wait for build settings from the build server before using fallback build settings.", "markdownDescription" : "Number of milliseconds to wait for build settings from the build server before using fallback build settings.",