Merge pull request #1090 from ahoppen/ahoppen/remove-logging-dependency-from-sourcekitd

Remove logging dependency from `SourceKitD`

Author: ahoppen

Sources/Diagnose/SourcekitdRequestCommand.swift

@@ -40,7 +40,7 @@ public struct SourceKitdRequestCommand: AsyncParsableCommand {
   public func run() async throws {
     let requestString = try String(contentsOf: URL(fileURLWithPath: sourcekitdRequestPath))
 
-    let sourcekitd = try SourceKitDImpl.getOrCreate(
+    let sourcekitd = try DynamicallyLoadedSourceKitD.getOrCreate(
       dylibPath: try! AbsolutePath(validating: sourcekitdPath)
     )
 

Sources/SourceKitD/CMakeLists.txt

@@ -6,7 +6,7 @@ add_library(SourceKitD STATIC
   SKDResponseArray.swift
   SKDResponseDictionary.swift
   SourceKitD.swift
-  SourceKitDImpl.swift
+  DynamicallyLoadedSourceKitD.swift
   SourceKitDRegistry.swift
   sourcekitd_functions.swift
   sourcekitd_uids.swift)

Sources/SourceKitD/SourceKitDImpl.swift renamed to Sources/SourceKitD/DynamicallyLoadedSourceKitD.swift

@@ -11,6 +11,7 @@
 //===----------------------------------------------------------------------===//
 
 import Foundation
+import LSPLogging
 import SKSupport
 
 import struct TSCBasic.AbsolutePath
@@ -20,7 +21,7 @@ import struct TSCBasic.AbsolutePath
 ///
 /// Users of this class should not call the api functions `initialize`, `shutdown`, or
 /// `set_notification_handler`, which are global state managed internally by this class.
-public final class SourceKitDImpl: SourceKitD {
+public final class DynamicallyLoadedSourceKitD: SourceKitD {
 
   /// The path to the sourcekitd dylib.
   public let path: AbsolutePath
@@ -48,7 +49,7 @@ public final class SourceKitDImpl: SourceKitD {
 
   public static func getOrCreate(dylibPath: AbsolutePath) throws -> SourceKitD {
     try SourceKitDRegistry.shared
-      .getOrAdd(dylibPath, create: { try SourceKitDImpl(dylib: dylibPath) })
+      .getOrAdd(dylibPath, create: { try DynamicallyLoadedSourceKitD(dylib: dylibPath) })
   }
 
   init(dylib path: AbsolutePath) throws {
@@ -96,6 +97,45 @@ public final class SourceKitDImpl: SourceKitD {
       _notificationHandlers.removeAll(where: { $0.value == nil || $0.value === handler })
     }
   }
+
+  public func log(request: SKDRequestDictionary) {
+    logger.info(
+      """
+      Sending sourcekitd request:
+      \(request.forLogging)
+      """
+    )
+  }
+
+  public func log(response: SKDResponse) {
+    logger.log(
+      level: (response.error == nil || response.error == .requestCancelled) ? .debug : .error,
+      """
+      Received sourcekitd response:
+      \(response.forLogging)
+      """
+    )
+  }
+
+  public func log(crashedRequest req: SKDRequestDictionary, fileContents: String?) {
+    let log = """
+      Request:
+      \(req.description)
+
+      File contents:
+      \(fileContents ?? "<nil>")
+      """
+    let chunks = splitLongMultilineMessage(message: log)
+    for (index, chunk) in chunks.enumerated() {
+      logger.fault(
+        """
+        sourcekitd crashed (\(index + 1)/\(chunks.count))
+        \(chunk)
+        """
+      )
+    }
+  }
+
 }
 
 struct WeakSKDNotificationHandler {

Sources/SourceKitD/SourceKitD.swift

@@ -13,7 +13,6 @@
 @_exported import Csourcekitd
 import Dispatch
 import Foundation
-import LSPLogging
 import SKSupport
 
 /// Access to sourcekitd API, taking care of initialization, shutdown, and notification handler
@@ -42,6 +41,24 @@ public protocol SourceKitD: AnyObject {
 
   /// Removes a previously registered notification handler.
   func removeNotificationHandler(_ handler: SKDNotificationHandler)
+
+  /// Log the given request.
+  ///
+  /// This log call is issued during normal operation. It is acceptable for the logger to truncate the log message
+  /// to achieve good performance.
+  func log(request: SKDRequestDictionary)
+
+  /// Log the given request and file contents, ensuring they do not get truncated.
+  ///
+  /// This log call is used when a request has crashed. In this case we want the log to contain the entire request to be
+  /// able to reproduce it.
+  func log(crashedRequest: SKDRequestDictionary, fileContents: String?)
+
+  /// Log the given response.
+  ///
+  /// This log call is issued during normal operation. It is acceptable for the logger to truncate the log message
+  /// to achieve good performance.
+  func log(response: SKDResponse)
 }
 
 public enum SKDError: Error, Equatable {
@@ -70,11 +87,7 @@ extension SourceKitD {
   ///   - fileContents: The contents of the file that the request operates on. If sourcekitd crashes, the file contents
   ///     will be logged.
   public func send(_ req: SKDRequestDictionary, fileContents: String?) async throws -> SKDResponseDictionary {
-    logRequest(req)
-
-    let signposter = logger.makeSignposter()
-    let signpostID = signposter.makeSignpostID()
-    let signposterState = signposter.beginInterval("sourcekitd-request", id: signpostID, "Start")
+    log(request: req)
 
     let sourcekitdResponse: SKDResponse = try await withCancellableCheckedThrowingContinuation { continuation in
       var handle: sourcekitd_api_request_handle_t? = nil
@@ -83,58 +96,24 @@ extension SourceKitD {
       }
       return handle
     } cancel: { handle in
-      api.cancel_request(handle)
+      if let handle {
+        api.cancel_request(handle)
+      }
     }
 
-    logResponse(sourcekitdResponse)
+    log(response: sourcekitdResponse)
 
     guard let dict = sourcekitdResponse.value else {
-      signposter.endInterval("sourcekitd-request", signposterState, "Error")
       if sourcekitdResponse.error == .connectionInterrupted {
-        let log = """
-          Request:
-          \(req.description)
-
-          File contents:
-          \(fileContents ?? "<nil>")
-          """
-        let chunks = splitLongMultilineMessage(message: log)
-        for (index, chunk) in chunks.enumerated() {
-          logger.fault(
-            """
-            sourcekitd crashed (\(index + 1)/\(chunks.count))
-            \(chunk)
-            """
-          )
-        }
+        log(crashedRequest: req, fileContents: fileContents)
       }
       throw sourcekitdResponse.error!
     }
 
-    signposter.endInterval("sourcekitd-request", signposterState, "Done")
     return dict
   }
 }
 
-private func logRequest(_ request: SKDRequestDictionary) {
-  logger.info(
-    """
-    Sending sourcekitd request:
-    \(request.forLogging)
-    """
-  )
-}
-
-private func logResponse(_ response: SKDResponse) {
-  logger.log(
-    level: (response.error == nil || response.error == .requestCancelled) ? .debug : .error,
-    """
-    Received sourcekitd response:
-    \(response.forLogging)
-    """
-  )
-}
-
 /// A sourcekitd notification handler in a class to allow it to be uniquely referenced.
 public protocol SKDNotificationHandler: AnyObject {
   func notification(_: SKDResponse) -> Void

Sources/SourceKitLSP/Swift/SwiftLanguageServer.swift

@@ -159,7 +159,7 @@ public actor SwiftLanguageServer: ToolchainLanguageServer {
     guard let sourcekitd = toolchain.sourcekitd else { return nil }
     self.sourceKitServer = sourceKitServer
     self.swiftFormat = toolchain.swiftFormat
-    self.sourcekitd = try SourceKitDImpl.getOrCreate(dylibPath: sourcekitd)
+    self.sourcekitd = try DynamicallyLoadedSourceKitD.getOrCreate(dylibPath: sourcekitd)
     self.capabilityRegistry = workspace.capabilityRegistry
     self.serverOptions = options
     self.documentManager = DocumentManager()

Tests/DiagnoseTests/DiagnoseTests.swift

@@ -204,7 +204,9 @@ private struct InProcessSourceKitRequestExecutor: SourceKitRequestExecutor {
   func run(request requestYaml: String) async throws -> SourceKitDRequestResult {
     logger.info("Sending request: \(requestYaml)")
 
-    let sourcekitd = try SourceKitDImpl.getOrCreate(dylibPath: try! AbsolutePath(validating: sourcekitd.path))
+    let sourcekitd = try DynamicallyLoadedSourceKitD.getOrCreate(
+      dylibPath: try! AbsolutePath(validating: sourcekitd.path)
+    )
     let response = try await sourcekitd.run(requestYaml: requestYaml)
 
     logger.info("Received response: \(response.description)")

Tests/SourceKitDTests/SourceKitDRegistryTests.swift

@@ -75,4 +75,8 @@ final class FakeSourceKitD: SourceKitD {
   static func getOrCreate(_ path: AbsolutePath, in registry: SourceKitDRegistry) -> SourceKitD {
     return registry.getOrAdd(path, create: { Self.init() })
   }
+
+  public func log(request: SKDRequestDictionary) {}
+  public func log(response: SKDResponse) {}
+  public func log(crashedRequest: SKDRequestDictionary, fileContents: String?) {}
 }

Tests/SourceKitDTests/SourceKitDTests.swift

@@ -28,7 +28,7 @@ import class TSCBasic.Process
 final class SourceKitDTests: XCTestCase {
   func testMultipleNotificationHandlers() async throws {
     let sourcekitdPath = await ToolchainRegistry.forTesting.default!.sourcekitd!
-    let sourcekitd = try SourceKitDImpl.getOrCreate(dylibPath: sourcekitdPath)
+    let sourcekitd = try DynamicallyLoadedSourceKitD.getOrCreate(dylibPath: sourcekitdPath)
     let keys = sourcekitd.keys
     let path = DocumentURI.for(.swift).pseudoPath
 
@@ -47,7 +47,7 @@ final class SourceKitDTests: XCTestCase {
         expectation1.fulfill()
       }
     }
-    // SourceKitDImpl weakly references handlers
+    // DynamicallyLoadedSourceKitD weakly references handlers
     defer {
       _fixLifetime(handler1)
     }
@@ -59,7 +59,7 @@ final class SourceKitDTests: XCTestCase {
         expectation2.fulfill()
       }
     }
-    // SourceKitDImpl weakly references handlers
+    // DynamicallyLoadedSourceKitD weakly references handlers
     defer {
       _fixLifetime(handler2)
     }