Log execution times for token parsing

Add logExecutionTime

Author: fwcd

Sources/LSPLogging/Logging.swift

@@ -62,6 +62,23 @@ public func orLog<R>(
   }
 }
 
+/// Logs the time that the given block takes to execute in milliseconds.
+public func logExecutionTime<R>(
+  _ prefix: String = #function,
+  level: LogLevel = .default,
+  logger: Logger = Logger.shared,
+  _ block: () throws -> R
+) rethrows -> R {
+  let start = Date()
+  let result = try block()
+  let deltaMs = -start.timeIntervalSinceNow * 1000
+  logger.log(
+    "\(prefix)\(prefix.isEmpty ? "" : " ")took \(String(format: "%.2f", deltaMs)) ms to execute",
+    level: level
+  )
+  return result
+}
+
 public protocol LogHandler: AnyObject {
   func handle(_ message: String, level: LogLevel)
 }

Sources/SourceKitLSP/Swift/SwiftLanguageServer.swift

@@ -184,34 +184,36 @@ public final class SwiftLanguageServer: ToolchainLanguageServer {
     response: SKDResponseDictionary,
     for snapshot: DocumentSnapshot
   ) -> DocumentTokens {
-    var docTokens = snapshot.tokens
+    logExecutionTime(level: .debug) {
+      var docTokens = snapshot.tokens
+
+      guard let offset: Int = response[keys.offset],
+            let length: Int = response[keys.length],
+            let start: Position = snapshot.positionOf(utf8Offset: offset),
+            let end: Position = snapshot.positionOf(utf8Offset: offset + length) else {
+        // This e.g. happens in the case of empty edits
+        log("did not update lexical/syntactic tokens, no range found", level: .debug)
+        return docTokens
+      }
 
-    guard let offset: Int = response[keys.offset],
-          let length: Int = response[keys.length],
-          let start: Position = snapshot.positionOf(utf8Offset: offset),
-          let end: Position = snapshot.positionOf(utf8Offset: offset + length) else {
-      // This e.g. happens in the case of empty edits
-      log("did not update lexical/syntactic tokens, no range found", level: .debug)
-      return docTokens
-    }
+      let range = start..<end
 
-    let range = start..<end
+      if let syntaxMap: SKDResponseArray = response[keys.syntaxmap] {
+        let tokenParser = SyntaxHighlightingTokenParser(sourcekitd: sourcekitd)
+        let tokens = tokenParser.parseTokens(syntaxMap, in: snapshot)
 
-    if let syntaxMap: SKDResponseArray = response[keys.syntaxmap] {
-      let tokenParser = SyntaxHighlightingTokenParser(sourcekitd: sourcekitd)
-      let tokens = tokenParser.parseTokens(syntaxMap, in: snapshot)
+        docTokens.replaceLexical(in: range, with: tokens)
+      }
 
-      docTokens.replaceLexical(in: range, with: tokens)
-    }
+      if let substructure: SKDResponseArray = response[keys.substructure] {
+        let tokenParser = SyntaxHighlightingTokenParser(sourcekitd: sourcekitd, useName: true)
+        let tokens = tokenParser.parseTokens(substructure, in: snapshot)
 
-    if let substructure: SKDResponseArray = response[keys.substructure] {
-      let tokenParser = SyntaxHighlightingTokenParser(sourcekitd: sourcekitd, useName: true)
-      let tokens = tokenParser.parseTokens(substructure, in: snapshot)
+        docTokens.syntactic = tokens
+      }
 
-      docTokens.syntactic = tokens
+      return docTokens
     }
-
-    return docTokens
   }
 
   /// Updates the semantic tokens for the given `snapshot`.
@@ -237,16 +239,18 @@ public final class SwiftLanguageServer: ToolchainLanguageServer {
     response: SKDResponseDictionary,
     for snapshot: DocumentSnapshot
   ) -> DocumentTokens {
-    var docTokens = snapshot.tokens
+    logExecutionTime(level: .debug) {
+      var docTokens = snapshot.tokens
 
-    if let skTokens: SKDResponseArray = response[keys.annotations] {
-      let tokenParser = SyntaxHighlightingTokenParser(sourcekitd: sourcekitd)
-      let tokens = tokenParser.parseTokens(skTokens, in: snapshot)
+      if let skTokens: SKDResponseArray = response[keys.annotations] {
+        let tokenParser = SyntaxHighlightingTokenParser(sourcekitd: sourcekitd)
+        let tokens = tokenParser.parseTokens(skTokens, in: snapshot)
 
-      docTokens.semantic = tokens
-    }
+        docTokens.semantic = tokens
+      }
 
-    return docTokens
+      return docTokens
+    }
   }
 
   /// Inform the client about changes to the syntax highlighting tokens.