Wrap request and notification ID for the purpose of logging scopes

OSLog only allows the creation of 4000 logger objects, which means that logging will crash on the 4000th request to sourcekit-lsp (which would create the 4000th os_log object because it is the 4000th distinct category in which we are logging).

To circumvent this problem, only use the last two digits of the request and notification ID for the logging scope and wrap around afterwards. This should still allow us to tell apart log messages from concurrently handled requests/notifications while only using 200 os_log objects, which means we stay well clear of the 4000 limit.

rdar://119221355

Author: ahoppen

Sources/LSPLogging/LoggingScope.swift

@@ -22,36 +22,20 @@ public final class LoggingScope {
   }
 }
 
-/// Append `subscope` to the current scope name, if any exists, otherwise return
-/// `subscope`.
-private func newLoggingScopeName(_ subscope: String) -> String {
-  if let existingScope = LoggingScope._scope {
-    return "\(existingScope).\(subscope)"
-  } else {
-    return subscope
-  }
-}
-
-/// Create a new logging scope, which will be used as the category in any log
-/// messages created from the operation.
-///
-/// The name of the new scope will be any existing scope with the new scope
-/// appended using a `.`.
-///
-/// For example if we are currently logging scope `handleRequest` and we start a
-/// new scope `sourcekitd`, then the new scope has the name `handleRequest.sourcekitd`.
+/// Create a new logging scope, which will be used as the category in any log messages created from the operation.
 ///
-/// Because `.` is used to separate scopes and sub-scopes, `subscope` should not
-/// contain any `.`.
+/// This overrides the current logging scope.
 ///
 /// - Note: Since this stores the logging scope in a task-local value, it only
 ///   works when run inside a task. Outside a task, this is a no-op.
+/// - Warning: Be very careful with the dynamic creation of logging scopes. The logging scope is used as the os_log
+///   category, os_log only supports 4000 different loggers and thus at most 4000 different scopes must be used.
 public func withLoggingScope<Result>(
-  _ subscope: String,
+  _ scope: String,
   _ operation: () throws -> Result
 ) rethrows -> Result {
   return try LoggingScope.$_scope.withValue(
-    newLoggingScopeName(subscope),
+    scope,
     operation: operation
   )
 }
@@ -60,11 +44,11 @@ public func withLoggingScope<Result>(
 ///
 /// - SeeAlso: ``withLoggingScope(_:_:)-6qtga``
 public func withLoggingScope<Result>(
-  _ subscope: String,
+  _ scope: String,
   _ operation: () async throws -> Result
 ) async rethrows -> Result {
   return try await LoggingScope.$_scope.withValue(
-    newLoggingScopeName(subscope),
+    scope,
     operation: operation
   )
 }

Sources/SourceKitLSP/SourceKitServer.swift

@@ -736,7 +736,10 @@ extension SourceKitServer: MessageHandler {
     messageHandlingQueue.async(metadata: TaskMetadata(params)) {
       signposter.emitEvent("Start handling", id: signpostID)
 
-      await withLoggingScope("notification-\(notificationID)") {
+      // Only use the last two digits of the notification ID for the logging scope to avoid creating too many scopes.
+      // See comment in `withLoggingScope`.
+      // The last 2 digits should be sufficient to differentiate between multiple concurrently running notifications.
+      await withLoggingScope("notification-\(notificationID % 100)") {
         await self.handleImpl(params, from: clientID)
         signposter.endInterval("Notification", state, "Done")
       }
@@ -783,7 +786,10 @@ extension SourceKitServer: MessageHandler {
 
     let task = messageHandlingQueue.async(metadata: TaskMetadata(params)) {
       signposter.emitEvent("Start handling", id: signpostID)
-      await withLoggingScope("request-\(id)") {
+      // Only use the last two digits of the request ID for the logging scope to avoid creating too many scopes.
+      // See comment in `withLoggingScope`.
+      // The last 2 digits should be sufficient to differentiate between multiple concurrently running requests.
+      await withLoggingScope("request-\(id.numericValue % 100)") {
         await self.handleImpl(params, id: id, from: clientID, reply: reply)
         signposter.endInterval("Request", state, "Done")
       }
@@ -2331,3 +2337,16 @@ extension WorkspaceSymbolItem {
     )
   }
 }
+
+fileprivate extension RequestID {
+  /// Returns a numeric value for this request ID.
+  ///
+  /// For request IDs that are numbers, this is straightforward. For string-based request IDs, this uses a hash to
+  /// convert the string into a number.
+  var numericValue: Int {
+    switch self {
+    case .number(let number): return number
+    case .string(let string): return Int(string) ?? string.hashValue
+    }
+  }
+}