Log messages from the build server and clangd

Log messages sent to clangd and the build server in a similar way that we log requests to sourcekitd.

Fixes #886
rdar://116705677

Author: ahoppen

Sources/LSPTestSupport/TestJSONRPCConnection.swift

@@ -26,12 +26,14 @@ public final class TestJSONRPCConnection {
 
   public init() {
     clientConnection = JSONRPCConnection(
+      name: "client",
       protocol: testMessageRegistry,
       inFD: serverToClient.fileHandleForReading,
       outFD: clientToServer.fileHandleForWriting
     )
 
     serverConnection = JSONRPCConnection(
+      name: "server",
       protocol: testMessageRegistry,
       inFD: clientToServer.fileHandleForReading,
       outFD: serverToClient.fileHandleForWriting

Sources/LanguageServerProtocolJSONRPC/CMakeLists.txt

@@ -1,6 +1,7 @@
 add_library(LanguageServerProtocolJSONRPC STATIC
   DisableSigpipe.swift
   JSONRPCConnection.swift
+  LoggableMessageTypes.swift
   MessageCoding.swift
   MessageSplitting.swift)
 set_target_properties(LanguageServerProtocolJSONRPC PROPERTIES

Sources/LanguageServerProtocolJSONRPC/JSONRPCConnection.swift

@@ -24,6 +24,9 @@ import struct CDispatch.dispatch_fd_t
 /// For example, inside a language server, the `JSONRPCConnection` takes the language service implemenation as its `receiveHandler` and itself provides the client connection for sending notifications and callbacks.
 public final class JSONRPCConnection {
 
+  /// A name of the endpoint for this connection, used for logging, e.g. `clangd`.
+  let name: String
+
   var receiveHandler: MessageHandler? = nil
 
   /// The queue on which we read the data
@@ -66,11 +69,13 @@ public final class JSONRPCConnection {
   var closeHandler: (() async -> Void)? = nil
 
   public init(
+    name: String,
     protocol messageRegistry: MessageRegistry,
     inFD: FileHandle,
     outFD: FileHandle,
     syncRequests: Bool = false
   ) {
+    self.name = name
     #if os(Linux) || os(Android)
     // We receive a `SIGPIPE` if we write to a pipe that points to a crashed process. This in particular happens if the target of a `JSONRPCConnection` has crashed and we try to send it a message.
     // On Darwin, `DispatchIO` ignores `SIGPIPE` for the pipes handled by it, but that features is not available on Linux.
@@ -410,22 +415,36 @@ public final class JSONRPCConnection {
     _nextRequestID += 1
     return .number(_nextRequestID)
   }
-
 }
 
 extension JSONRPCConnection: Connection {
   // MARK: Connection interface
 
   public func send<Notification>(_ notification: Notification) where Notification: NotificationType {
-    guard readyToSend() else { return }
+    guard readyToSend() else {
+      logger.error(
+        """
+        Not sending notification to \(self.name, privacy: .public) because connection is not ready to send
+        \(notification.forLogging)
+        """
+      )
+      return
+    }
+    logger.info(
+      """
+      Sending notification to \(self.name, privacy: .public)
+      \(notification.forLogging)
+      """
+    )
     send { encoder in
       return try encoder.encode(JSONRPCMessage.notification(notification))
     }
   }
 
-  public func send<Request>(_ request: Request, reply: @escaping (LSPResult<Request.Response>) -> Void) -> RequestID
-  where Request: RequestType {
-
+  public func send<Request: RequestType>(
+    _ request: Request,
+    reply: @escaping (LSPResult<Request.Response>) -> Void
+  ) -> RequestID {
     let id: RequestID = self.queue.sync {
       let id = nextRequestID()
 
@@ -439,12 +458,36 @@ extension JSONRPCConnection: Connection {
         responseType: Request.Response.self,
         queue: queue,
         replyHandler: { anyResult in
-          reply(anyResult.map { $0 as! Request.Response })
+          let result = anyResult.map { $0 as! Request.Response }
+          switch result {
+          case .success(let response):
+            logger.info(
+              """
+              Received reply for request \(id, privacy: .public) from \(self.name, privacy: .public)
+              \(response.forLogging)
+              """
+            )
+          case .failure(let error):
+            logger.error(
+              """
+              Received error for request \(id, privacy: .public) from \(self.name, privacy: .public)
+              \(error.forLogging)
+              """
+            )
+          }
+          reply(result)
         }
       )
       return id
     }
 
+    logger.info(
+      """
+      Sending request to \(self.name, privacy: .public) (id: \(id, privacy: .public)):
+      \(request.forLogging)
+      """
+    )
+
     send { encoder in
       return try encoder.encode(JSONRPCMessage.request(request, id: id))
     }

Sources/SKSupport/LoggableMessageTypes.swift renamed to Sources/LanguageServerProtocolJSONRPC/LoggableMessageTypes.swift

@@ -31,19 +31,6 @@ fileprivate extension Encodable {
   }
 }
 
-// MARK: - DocumentURI
-
-extension DocumentURI {
-  public var redactedDescription: String {
-    return "<DocumentURI length=\(description.count) hash=\(description.hashForLogging)>"
-  }
-}
-#if swift(<5.10)
-extension DocumentURI: CustomLogStringConvertible {}
-#else
-extension DocumentURI: @retroactive CustomLogStringConvertible {}
-#endif
-
 // MARK: - RequestType
 
 fileprivate struct AnyRequestType: CustomLogStringConvertible {

Sources/SKCore/BuildServerBuildSystem.swift

@@ -191,6 +191,12 @@ public actor BuildServerBuildSystem: MessageHandler {
   ///
   /// We need to notify the delegate about any updated build settings.
   public nonisolated func handle(_ params: some NotificationType, from clientID: ObjectIdentifier) {
+    logger.info(
+      """
+      Received notification from build server:
+      \(params.forLogging)
+      """
+    )
     bspMessageHandlingQueue.async {
       if let params = params as? BuildTargetsChangedNotification {
         await self.handleBuildTargetsChanged(params)
@@ -209,6 +215,12 @@ public actor BuildServerBuildSystem: MessageHandler {
     from clientID: ObjectIdentifier,
     reply: @escaping (LSPResult<R.Response>) -> Void
   ) {
+    logger.info(
+      """
+      Received request from build server:
+      \(params.forLogging)
+      """
+    )
     reply(.failure(ResponseError.methodNotFound(R.method)))
   }
 
@@ -339,6 +351,7 @@ private func makeJSONRPCBuildServer(
   let serverToClient = Pipe()
 
   let connection = JSONRPCConnection(
+    name: "build server",
     protocol: BuildServerProtocol.bspRegistry,
     inFD: serverToClient.fileHandleForReading,
     outFD: clientToServer.fileHandleForWriting

Sources/SKSupport/CMakeLists.txt

@@ -6,9 +6,9 @@ add_library(SKSupport STATIC
   ByteString.swift
   Connection+Send.swift
   dlopen.swift
+  DocumentURI+CustomLogStringConvertible.swift
   FileSystem.swift
   LineTable.swift
-  LoggableMessageTypes.swift
   Random.swift
   Result.swift
   ThreadSafeBox.swift

Sources/SKSupport/DocumentURI+CustomLogStringConvertible.swift

@@ -0,0 +1,28 @@
+//===----------------------------------------------------------------------===//
+//
+// This source file is part of the Swift.org open source project
+//
+// Copyright (c) 2014 - 2023 Apple Inc. and the Swift project authors
+// Licensed under Apache License v2.0 with Runtime Library Exception
+//
+// See https://swift.org/LICENSE.txt for license information
+// See https://swift.org/CONTRIBUTORS.txt for the list of Swift project authors
+//
+//===----------------------------------------------------------------------===//
+
+import Foundation
+import LSPLogging
+import LanguageServerProtocol
+
+// MARK: - DocumentURI
+
+extension DocumentURI {
+  public var redactedDescription: String {
+    return "<DocumentURI length=\(description.count) hash=\(description.hashForLogging)>"
+  }
+}
+#if swift(<5.10)
+extension DocumentURI: CustomLogStringConvertible {}
+#else
+extension DocumentURI: @retroactive CustomLogStringConvertible {}
+#endif

Sources/SourceKitLSP/Clang/ClangLanguageServer.swift

@@ -200,6 +200,7 @@ actor ClangLanguageServerShim: ToolchainLanguageServer, MessageHandler {
     let clangdToUs: Pipe = Pipe()
 
     let connectionToClangd = JSONRPCConnection(
+      name: "clangd",
       protocol: MessageRegistry.lspProtocol,
       inFD: clangdToUs.fileHandleForReading,
       outFD: usToClangd.fileHandleForWriting
@@ -302,6 +303,12 @@ actor ClangLanguageServerShim: ToolchainLanguageServer, MessageHandler {
   ///
   /// We should either handle it ourselves or forward it to the editor.
   nonisolated func handle(_ params: some NotificationType, from clientID: ObjectIdentifier) {
+    logger.info(
+      """
+      Received notification from clangd:
+      \(params.forLogging)
+      """
+    )
     clangdMessageHandlingQueue.async {
       switch params {
       case let publishDiags as PublishDiagnosticsNotification:
@@ -324,6 +331,12 @@ actor ClangLanguageServerShim: ToolchainLanguageServer, MessageHandler {
     from clientID: ObjectIdentifier,
     reply: @escaping (LSPResult<R.Response>) -> Void
   ) {
+    logger.info(
+      """
+      Received request from clangd:
+      \(params.forLogging)
+      """
+    )
     clangdMessageHandlingQueue.async {
       guard let sourceKitServer = await self.sourceKitServer else {
         // `SourceKitServer` has been destructed. We are tearing down the language

Sources/sourcekit-lsp/SourceKitLSP.swift

@@ -221,6 +221,7 @@ struct SourceKitLSP: ParsableCommand {
     let realStdoutHandle = FileHandle(fileDescriptor: realStdout, closeOnDealloc: false)
 
     let clientConnection = JSONRPCConnection(
+      name: "client",
       protocol: MessageRegistry.lspProtocol,
       inFD: FileHandle.standardInput,
       outFD: realStdoutHandle,

Tests/LanguageServerProtocolJSONRPCTests/ConnectionTests.swift

@@ -252,6 +252,7 @@ class ConnectionTests: XCTestCase {
       expectation.assertForOverFulfill = true
 
       let conn = JSONRPCConnection(
+        name: "test",
         protocol: MessageRegistry(requests: [], notifications: []),
         inFD: to.fileHandleForReading,
         outFD: from.fileHandleForWriting