From 79795bf4d9ffdb359ecbeb429bb33b2883d9ecdb Mon Sep 17 00:00:00 2001
From: David Goldman <dallasftball@gmail.com>
Date: Thu, 8 Oct 2020 18:20:56 -0400
Subject: [PATCH] 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
---
 Sources/SKCore/BuildSystemManager.swift       |  1 +
 Sources/SKCore/LanguageServer.swift           | 24 ++++++++++++-------
 Sources/SourceKitD/SourceKitD.swift           | 10 ++++++--
 .../IndexStoreDB+MainFilesProvider.swift      |  2 +-
 4 files changed, 26 insertions(+), 11 deletions(-)

diff --git a/Sources/SKCore/BuildSystemManager.swift b/Sources/SKCore/BuildSystemManager.swift
index d82dcc93..52e5a54b 100644
--- a/Sources/SKCore/BuildSystemManager.swift
+++ b/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
diff --git a/Sources/SKCore/LanguageServer.swift b/Sources/SKCore/LanguageServer.swift
index 6f87c24b..0e00113a 100644
--- a/Sources/SKCore/LanguageServer.swift
+++ b/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 {
diff --git a/Sources/SourceKitD/SourceKitD.swift b/Sources/SourceKitD/SourceKitD.swift
index d7665d85..f0e35907 100644
--- a/Sources/SourceKitD/SourceKitD.swift
+++ b/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 }
diff --git a/Sources/SourceKitLSP/IndexStoreDB+MainFilesProvider.swift b/Sources/SourceKitLSP/IndexStoreDB+MainFilesProvider.swift
index df9dc101..d67149d3 100644
--- a/Sources/SourceKitLSP/IndexStoreDB+MainFilesProvider.swift
+++ b/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
   }
 }