Decrease verbosity of info-level logging (#331)

- Don't log entire LSP notifications/requests for the `info` level, instead log of the form:
  - `Notification<method>` e.g. Notification<textDocument/publishDiagnostics>
  - `Request<method(id)>` e.g. Request<textDocument/hover(6)>
  - `Response<method(id)` e.g. Response<textDocument/hover(6)>

- Only log sourcekitd requests/responses at the debug level

Author: DavidGoldman

Sources/SKCore/BuildSystemManager.swift

@@ -388,6 +388,7 @@ extension BuildSystemManager: BuildSystemDelegate {
 
 extension BuildSystemManager: MainFilesDelegate {
 
+  // FIXME: Consider debouncing/limiting this, seems to trigger often during a build.
   public func mainFilesChanged() {
     queue.async {
       let origWatched = self.watchedFiles

Sources/SKCore/LanguageServer.swift

@@ -81,19 +81,28 @@ open class LanguageServerEndpoint {
   }
 
   open func _logRequest<R>(_ request: Request<R>) {
-    logAsync { _ in
-      "\(type(of: self)): \(request)"
+    logAsync { currentLevel in
+      guard currentLevel >= LogLevel.debug else {
+        return "\(type(of: self)): Request<\(R.method)(\(request.id))>"
+      }
+      return "\(type(of: self)): \(request)"
     }
   }
   open func _logNotification<N>(_ notification: Notification<N>) {
-    logAsync { _ in
-      "\(type(of: self)): \(notification)"
+    logAsync { currentLevel in
+      guard currentLevel >= LogLevel.debug else {
+        return "\(type(of: self)): Notification<\(N.method)>"
+      }
+      return "\(type(of: self)): \(notification)"
     }
   }
   open func _logResponse<Response>(_ result: LSPResult<Response>, id: RequestID, method: String) {
-    logAsync { _ in
-      """
-      \(type(of: self)): Response<\(method)>(
+    logAsync { currentLevel in
+      guard currentLevel >= LogLevel.debug else {
+        return "\(type(of: self)): Response<\(method)(\(id))>"
+      }
+      return """
+      \(type(of: self)): Response<\(method)(\(id))>(
         \(result)
       )
       """
@@ -158,7 +167,6 @@ extension LanguageServerEndpoint: MessageHandler {
     queue.async {
 
       let notification = Notification(params, clientID: clientID)
-
       self._logNotification(notification)
 
       guard let handler = self.notificationHandlers[ObjectIdentifier(N.self)] as? ((Notification<N>) -> Void) else {

Sources/SourceKitD/SourceKitD.swift

@@ -69,7 +69,7 @@ extension SourceKitD {
 
   /// Send the given request and synchronously receive a reply dictionary (or error).
   public func sendSync(_ req: SKDRequestDictionary) throws -> SKDResponseDictionary {
-    logAsync { _ in req.description }
+    logRequest(req)
 
     let resp = SKDResponse(api.send_request_sync(req.dict), sourcekitd: self)
 
@@ -88,7 +88,7 @@ extension SourceKitD {
     _ queue: DispatchQueue,
     reply: @escaping (Result<SKDResponseDictionary, SKDError>) -> Void
   ) -> sourcekitd_request_handle_t? {
-    logAsync { _ in req.description }
+    logRequest(req)
 
     var handle: sourcekitd_request_handle_t? = nil
 
@@ -115,6 +115,12 @@ extension SourceKitD {
   }
 }
 
+private func logRequest(_ request: SKDRequestDictionary) {
+  // FIXME: Ideally we could log the request key here at the info level but the dictionary is
+  // readonly.
+  logAsync(level: .debug) { _ in request.description }
+}
+
 private func logResponse(_ response: SKDResponse) {
   if let value = response.value {
     logAsync(level: .debug) { _ in value.description }

Sources/SourceKitLSP/IndexStoreDB+MainFilesProvider.swift

@@ -24,7 +24,7 @@ extension IndexStoreDB: MainFilesProvider {
     } else {
       mainFiles = []
     }
-    log("mainFilesContainingFile(\(uri.pseudoPath)) -> \(mainFiles)")
+    log("mainFilesContainingFile(\(uri.pseudoPath)) -> \(mainFiles)", level: .debug)
     return mainFiles
   }
 }