Logging refactoring #1 Subscription and Content Blocking

.swiftlint.yml

@@ -16,6 +16,8 @@ disabled_rules:
   - function_body_length
   - file_length
   - type_body_length
+  - static_over_final_class
+  - non_optional_string_data_conversion
 
 opt_in_rules:
   - file_header
@@ -31,13 +33,6 @@ custom_rules:
       - keyword
     message: "Classes should be `final` by default, use explicit `internal` or `public` for non-final classes."
     severity: error
-  enforce_os_log_wrapper:
-    included: ".*\\.swift"
-    name: "Use `import Common` for os_log instead of `import os.log`"
-    regex: "^(import (?:os\\.log|os|OSLog))$"
-    capture_group: 0
-    message: "os_log wrapper ensures log args are @autoclosures (computed when needed) and to be able to use String Interpolation."
-    severity: error
 
 analyzer_rules: # Rules run by `swiftlint analyze`
   - explicit_self

.swiftpm/xcode/xcshareddata/xcschemes/BrowserServicesKit-Package.xcscheme

@@ -441,6 +441,20 @@
                ReferencedContainer = "container:">
             </BuildableReference>
          </BuildActionEntry>
+         <BuildActionEntry
+            buildForTesting = "YES"
+            buildForRunning = "YES"
+            buildForProfiling = "YES"
+            buildForArchiving = "YES"
+            buildForAnalyzing = "YES">
+            <BuildableReference
+               BuildableIdentifier = "primary"
+               BlueprintIdentifier = "LoggingKit"
+               BuildableName = "LoggingKit"
+               BlueprintName = "LoggingKit"
+               ReferencedContainer = "container:">
+            </BuildableReference>
+         </BuildActionEntry>
       </BuildActionEntries>
    </BuildAction>
    <TestAction

Sources/BloomFilterObjC/BloomFilterObjC.mm

@@ -1,6 +1,5 @@
 //
 //  BloomFilterWrapper.m
-//  DuckDuckGo
 //
 //  Copyright © 2018 DuckDuckGo. All rights reserved.
 //

Sources/BloomFilterObjC/include/BloomFilterObjC.h

@@ -1,6 +1,5 @@
 //
 //  BloomFilterWrapper.h
-//  DuckDuckGo
 //
 //  Copyright © 2018 DuckDuckGo. All rights reserved.
 //

Sources/BrowserServicesKit/Autofill/AutofillUserScript.swift

@@ -19,6 +19,7 @@
 import Common
 import WebKit
 import UserScript
+import os.log
 
 var previousIncontextSignupPermanentlyDismissedAt: Double?
 var previousEmailSignedIn: Bool?
@@ -115,11 +116,10 @@ public class AutofillUserScript: NSObject, UserScript, UserScriptMessageEncrypti
 
     public func messageHandlerFor(_ messageName: String) -> MessageHandler? {
         guard let message = MessageName(rawValue: messageName) else {
-            os_log("Failed to parse Autofill User Script message: '%{public}s'", log: .userScripts, type: .debug, messageName)
+            Logger.autofill.error("Failed to parse Autofill User Script message: '\(messageName, privacy: .public)'")
             return nil
         }
-
-        os_log("AutofillUserScript: received '%{public}s'", log: .userScripts, type: .debug, messageName)
+        Logger.autofill.debug("AutofillUserScript: received '\(messageName, privacy: .public)'")
 
         switch message {
         case .emailHandlerStoreToken: return emailStoreToken

Sources/BrowserServicesKit/Autofill/Logger+Autofill.swift

@@ -0,0 +1,24 @@
+//
+//  Logger+Autofill.swift
+//
+//  Copyright © 2024 DuckDuckGo. All rights reserved.
+//
+//  Licensed under the Apache License, Version 2.0 (the "License");
+//  you may not use this file except in compliance with the License.
+//  You may obtain a copy of the License at
+//
+//  http://www.apache.org/licenses/LICENSE-2.0
+//
+//  Unless required by applicable law or agreed to in writing, software
+//  distributed under the License is distributed on an "AS IS" BASIS,
+//  WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+//  See the License for the specific language governing permissions and
+//  limitations under the License.
+//
+
+import Foundation
+import os.log
+
+public extension Logger {
+    static var autofill: Logger = { Logger(subsystem: Bundle.main.bundleIdentifier ?? "DuckDuckGo", category: "Autofill") }()
+}

Sources/BrowserServicesKit/ContentBlocking/ContentBlockerRulesManager.swift

@@ -21,6 +21,7 @@ import WebKit
 import TrackerRadarKit
 import Combine
 import Common
+import os.log
 
 public protocol CompiledRuleListsSource {
 
@@ -124,10 +125,6 @@ public class ContentBlockerRulesManager: CompiledRuleListsSource {
     public var onCriticalError: (() -> Void)?
 
     private let errorReporting: EventMapping<ContentBlockerDebugEvents>?
-    private let getLog: () -> OSLog
-    private var log: OSLog {
-        getLog()
-    }
 
     // Public only for tests
     public var sourceManagers = [String: ContentBlockerRulesSourceManager]()
@@ -143,14 +140,12 @@ public class ContentBlockerRulesManager: CompiledRuleListsSource {
                 exceptionsSource: ContentBlockerRulesExceptionsSource,
                 lastCompiledRulesStore: LastCompiledRulesStore? = nil,
                 cache: ContentBlockerRulesCaching? = nil,
-                errorReporting: EventMapping<ContentBlockerDebugEvents>? = nil,
-                log: @escaping @autoclosure () -> OSLog = .disabled) {
+                errorReporting: EventMapping<ContentBlockerDebugEvents>? = nil) {
         self.rulesSource = rulesSource
         self.exceptionsSource = exceptionsSource
         self.lastCompiledRulesStore = lastCompiledRulesStore
         self.cache = cache
         self.errorReporting = errorReporting
-        self.getLog = log
 
         workQueue.async {
             _ = self.updateCompilationState(token: "")
@@ -201,7 +196,7 @@ public class ContentBlockerRulesManager: CompiledRuleListsSource {
     @discardableResult
     public func scheduleCompilation() -> CompletionToken {
         let token = UUID().uuidString
-        os_log("Scheduling compilation with %{public}s", log: log, type: .default, token)
+        Logger.contentBlocking.log("Scheduling compilation with \(token, privacy: .public)")
         workQueue.async {
             let shouldStartCompilation = self.updateCompilationState(token: token)
             if shouldStartCompilation {
@@ -213,7 +208,7 @@ public class ContentBlockerRulesManager: CompiledRuleListsSource {
 
     /// Returns true if the compilation should be executed immediately
     private func updateCompilationState(token: CompletionToken) -> Bool {
-        os_log("Requesting compilation...", log: log, type: .default)
+        Logger.contentBlocking.log("Requesting compilation...")
         lock.lock()
         guard case .idle = state else {
             if case .recompiling(let tokens) = state {
@@ -237,16 +232,16 @@ public class ContentBlockerRulesManager: CompiledRuleListsSource {
      Returns true if rules were found, false otherwise.
      */
     private func lookupCompiledRules() -> Bool {
-        os_log("Lookup compiled rules", log: log, type: .debug)
+        Logger.contentBlocking.debug("Lookup compiled rules")
         prepareSourceManagers()
         let initialCompilationTask = LookupRulesTask(sourceManagers: Array(sourceManagers.values))
         let mutex = DispatchSemaphore(value: 0)
 
-        Task { [log] in
+        Task {
             do {
                 try await initialCompilationTask.lookupCachedRulesLists()
             } catch {
-                os_log("❌ Lookup failed: %{public}s", log: log, type: .debug, error.localizedDescription)
+                Logger.contentBlocking.debug("❌ Lookup failed: \(error.localizedDescription, privacy: .public)")
             }
             mutex.signal()
         }
@@ -255,7 +250,7 @@ public class ContentBlockerRulesManager: CompiledRuleListsSource {
 
         if let result = initialCompilationTask.result {
             let rules = result.map(Rules.init(compilationResult:))
-            os_log("🟩 Found %{public}d rules", log: log, type: .debug, rules.count)
+            Logger.contentBlocking.debug("🟩 Found \(rules.count, privacy: .public) rules")
             applyRules(rules)
             return true
         }
@@ -267,7 +262,7 @@ public class ContentBlockerRulesManager: CompiledRuleListsSource {
      Returns true if rules were found, false otherwise.
      */
     private func fetchLastCompiledRules(with lastCompiledRules: [LastCompiledRules]) {
-        os_log("Fetch last compiled rules: %{public}d", log: log, type: .debug, lastCompiledRules.count)
+        Logger.contentBlocking.debug("Fetch last compiled rules: \(lastCompiledRules.count, privacy: .public)")
 
         let initialCompilationTask = LastCompiledRulesLookupTask(sourceRules: rulesSource.contentBlockerRulesLists,
                                                                  lastCompiledRules: lastCompiledRules)
@@ -299,19 +294,17 @@ public class ContentBlockerRulesManager: CompiledRuleListsSource {
                 manager.rulesList = rulesList
                 sourceManager = manager
             } else {
-                let log = self.log
                 sourceManager = ContentBlockerRulesSourceManager(rulesList: rulesList,
                                                                  exceptionsSource: self.exceptionsSource,
                                                                  errorReporting: self.errorReporting,
-                                                                 onCriticalError: self.onCriticalError,
-                                                                 log: log)
+                                                                 onCriticalError: self.onCriticalError)
                 self.sourceManagers[rulesList.name] = sourceManager
             }
         }
     }
 
     private func startCompilationProcess() {
-        os_log("Starting compilataion process", log: log, type: .debug)
+        Logger.contentBlocking.debug("Starting compilataion process")
         prepareSourceManagers()
 
         // Prepare compilation tasks based on the sources
@@ -368,7 +361,7 @@ public class ContentBlockerRulesManager: CompiledRuleListsSource {
 
         let newRules: [Rules] = currentTasks.compactMap { task in
             guard let result = task.result else {
-                os_log("Failed to complete task %{public}s ", log: self.log, type: .error, task.rulesList.name)
+                Logger.contentBlocking.debug("Failed to complete task \(task.rulesList.name, privacy: .public)")
                 return nil
             }
             let rules = Rules(compilationResult: result)

Sources/BrowserServicesKit/ContentBlocking/UserScripts/contentblockerrules.js

@@ -1,6 +1,5 @@
 //
 //  contentblockerrules.js
-//  DuckDuckGo
 //
 //  Copyright © 2020 DuckDuckGo. All rights reserved.
 //

Sources/BrowserServicesKit/ContentBlocking/UserScripts/surrogates.js

@@ -1,6 +1,5 @@
 //
 //  surrogates.js
-//  DuckDuckGo
 //
 //  Copyright © 2017 DuckDuckGo. All rights reserved.
 //

Sources/BrowserServicesKit/ContentScopeScript/UserContentController.swift

@@ -21,6 +21,7 @@ import Common
 import UserScript
 import WebKit
 import QuartzCore
+import os.log
 
 public protocol UserContentControllerDelegate: AnyObject {
     @MainActor
@@ -80,14 +81,15 @@ final public class UserContentController: WKUserContentController {
             self.removeAllUserScripts()
 
             if let contentBlockingAssets = newValue {
-                os_log(.debug, log: .contentBlocking, "\(self): 📚 installing \(contentBlockingAssets)")
+                Logger.contentBlocking.debug("📚 installing \(contentBlockingAssets.debugDescription)")
                 self.installGlobalContentRuleLists(contentBlockingAssets.globalRuleLists)
-                os_log(.debug, log: .userScripts, "\(self): 📜 installing user scripts")
+                Logger.contentBlocking.debug("📜 installing user scripts")
                 self.installUserScripts(contentBlockingAssets.wkUserScripts, handlers: contentBlockingAssets.userScripts.userScripts)
-                os_log(.debug, log: .contentBlocking, "\(self): ✅ installing content blocking assets done")
+                Logger.contentBlocking.debug("✅ installing content blocking assets done")
             }
         }
     }
+
     @MainActor
     private func installContentBlockingAssets(_ contentBlockingAssets: ContentBlockingAssets) {
         // don‘t install ContentBlockingAssets (especially Message Handlers retaining `self`) after cleanUpBeforeClosing was called
@@ -124,7 +126,7 @@ final public class UserContentController: WKUserContentController {
         installUserScripts([], handlers: earlyAccessHandlers)
 
         assetsPublisherCancellable = assetsPublisher.sink { [weak self, selfDescr=self.debugDescription] content in
-            os_log(.debug, log: .contentBlocking, "\(selfDescr): 📚 received content blocking assets")
+            Logger.contentBlocking.debug("\(selfDescr): 📚 received content blocking assets")
             Task.detached { [weak self] in
                 let contentBlockingAssets = await ContentBlockingAssets(content: content)
                 await self?.installContentBlockingAssets(contentBlockingAssets)
@@ -147,12 +149,12 @@ final public class UserContentController: WKUserContentController {
     private func installGlobalContentRuleLists(_ globalContentRuleLists: [String: WKContentRuleList]) {
         assert(contentRuleLists.isEmpty, "installGlobalContentRuleLists should be called after removing all Content Rule Lists")
         guard self.privacyConfigurationManager.privacyConfig.isEnabled(featureKey: .contentBlocking) else {
-            os_log(.debug, log: .contentBlocking, "\(self): ❗️ content blocking disabled, removing all content rule lists")
+            Logger.contentBlocking.debug("\(self): ❗️ content blocking disabled, removing all content rule lists")
             removeAllContentRuleLists()
             return
         }
 
-        os_log(.debug, log: .contentBlocking, "\(self): ❇️ installing global rule lists: \(globalContentRuleLists))")
+        Logger.contentBlocking.debug("\(self): ❇️ installing global rule lists: \(globalContentRuleLists))")
         contentRuleLists = globalContentRuleLists.reduce(into: [:]) {
             $0[.global($1.key)] = $1.value
         }
@@ -166,12 +168,12 @@ final public class UserContentController: WKUserContentController {
                 // when enabling from a $contentBlockingAssets subscription, the ruleList gets
                 // to contentRuleLists before contentBlockingAssets value is set
                 ?? contentRuleLists[.global(identifier)] else {
-            os_log(.debug, log: .contentBlocking, "\(self): ❗️ can‘t enable rule list `\(identifier)` as it‘s not available")
+            Logger.contentBlocking.debug("\(self): ❗️ can‘t enable rule list `\(identifier)` as it‘s not available")
             throw ContentRulesNotFoundError()
         }
         guard contentRuleLists[.global(identifier)] == nil else { return /* already enabled */ }
 
-        os_log(.debug, log: .contentBlocking, "\(self): 🟩 enabling rule list `\(identifier)`")
+        Logger.contentBlocking.debug("\(self): 🟩 enabling rule list `\(identifier)`")
         contentRuleLists[.global(identifier)] = ruleList
         add(ruleList)
     }
@@ -180,11 +182,11 @@ final public class UserContentController: WKUserContentController {
     @MainActor
     public func disableGlobalContentRuleList(withIdentifier identifier: String) throws {
         guard let ruleList = contentRuleLists[.global(identifier)] else {
-            os_log(.debug, log: .contentBlocking, "\(self): ❗️ can‘t disable rule list `\(identifier)` as it‘s not enabled")
+            Logger.contentBlocking.debug("\(self): ❗️ can‘t disable rule list `\(identifier)` as it‘s not enabled")
             throw ContentRulesNotEnabledError()
         }
 
-        os_log(.debug, log: .contentBlocking, "\(self): 🔻 disabling rule list `\(identifier)`")
+        Logger.contentBlocking.debug("\(self): 🔻 disabling rule list `\(identifier)`")
         contentRuleLists[.global(identifier)] = nil
         remove(ruleList)
     }
@@ -194,7 +196,7 @@ final public class UserContentController: WKUserContentController {
         // replace if already installed
         removeLocalContentRuleList(withIdentifier: identifier)
 
-        os_log(.debug, log: .contentBlocking, "\(self): 🔸 installing local rule list `\(identifier)`")
+        Logger.contentBlocking.debug("\(self): 🔸 installing local rule list `\(identifier)`")
         contentRuleLists[.local(identifier)] = ruleList
         add(ruleList)
     }
@@ -203,13 +205,13 @@ final public class UserContentController: WKUserContentController {
     public func removeLocalContentRuleList(withIdentifier identifier: String) {
         guard let ruleList = contentRuleLists.removeValue(forKey: .local(identifier)) else { return }
 
-        os_log(.debug, log: .contentBlocking, "\(self): 🔻 removing local rule list `\(identifier)`")
+        Logger.contentBlocking.debug("\(self): 🔻 removing local rule list `\(identifier)`")
         remove(ruleList)
     }
 
     @MainActor
     public override func removeAllContentRuleLists() {
-        os_log(.debug, log: .contentBlocking, "\(self): 🧹 removing all content rule lists")
+        Logger.contentBlocking.debug("\(self): 🧹 removing all content rule lists")
         contentRuleLists.removeAll(keepingCapacity: true)
         super.removeAllContentRuleLists()
     }
@@ -222,7 +224,7 @@ final public class UserContentController: WKUserContentController {
 
     @MainActor
     public func cleanUpBeforeClosing() {
-        os_log(.debug, log: .contentBlocking, "\(self): 💀 cleanUpBeforeClosing")
+        Logger.contentBlocking.debug("\(self): 💀 cleanUpBeforeClosing")
 
         self.removeAllUserScripts()
 
@@ -275,7 +277,7 @@ public extension UserContentController {
     @MainActor
     var awaitContentBlockingAssetsInstalled: () async -> Void {
         guard !contentBlockingAssetsInstalled else { return {} }
-        os_log(.debug, log: .contentBlocking, "\(self): 🛑 will wait for content blocking assets installed")
+        Logger.contentBlocking.debug("\(self): 🛑 will wait for content blocking assets installed")
         let startTime = CACurrentMediaTime()
         return { [weak self, selfDescr=self.description] in
             // merge $contentBlockingAssets with Task cancellation completion event publisher
@@ -297,15 +299,15 @@ public extension UserContentController {
                     }
                     cancellable = throwingPublisher.sink /* completion: */ { _ in
                         withExtendedLifetime(cancellable) {
-                            os_log(.debug, log: .contentBlocking, "\(selfDescr): ❌ wait cancelled after \(elapsedTime)")
+                            Logger.contentBlocking.debug("\(selfDescr): ❌ wait cancelled after \(elapsedTime)")
 
                             c.resume(with: .failure(CancellationError()))
                             cancellable.cancel()
                         }
                     } receiveValue: { assets in
                         guard assets != nil else { return }
                         withExtendedLifetime(cancellable) {
-                            os_log(.debug, log: .contentBlocking, "\(selfDescr): 🏁 content blocking assets installed (\(elapsedTime))")
+                            Logger.contentBlocking.debug("\(selfDescr): 🏁 content blocking assets installed (\(elapsedTime))")
 
                             c.resume(with: .success( () ))
                             cancellable.cancel()