From dd5716e831af94f5219d16200718b0910f5ccc4d Mon Sep 17 00:00:00 2001 From: Morgan Pretty Date: Mon, 20 May 2024 17:46:20 +1000 Subject: [PATCH] Initial work on 2.6.0 issues MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit • Fixed an issue where voice messages wouldn't stop playing when deleting a message or leaving a conversation • Fixed an issue where the notification extension was handling errors and finishing while within a database transaction • Fixed an issue where the ShareExtension may not have been able to send LinkPreviews • Fixed an issue where displaying or logging the paths weren't maintaining the correct order • Tweaked some of the logging behaviours --- Scripts/LintLocalizableStrings.swift | 8 +- .../Call Management/SessionCallManager.swift | 2 +- .../ConversationVC+Interaction.swift | 15 + .../Conversations/ConversationViewModel.swift | 11 + Session/Meta/AppDelegate.swift | 55 +-- Session/Meta/AppEnvironment.swift | 96 ----- Session/Meta/MainAppContext.swift | 21 -- Session/Meta/SessionApp.swift | 5 +- Session/Path/PathVC.swift | 6 +- Session/Settings/HelpViewModel.swift | 8 +- Session/Utilities/IP2Country.swift | 2 +- .../Migrations/_003_YDBToGRDBMigration.swift | 2 +- .../MessageSender+Convenience.swift | 2 +- .../LibSession/LibSessionSpec.swift | 6 + .../NotificationError.swift | 2 + .../NotificationServiceExtension.swift | 102 ++++-- .../ShareAppExtensionContext.swift | 9 - .../ShareNavController.swift | 33 +- SessionShareExtension/ThreadPickerVC.swift | 8 +- .../Migrations/_003_YDBToGRDBMigration.swift | 2 +- .../LibSession/LibSession+Networking.swift | 14 +- .../Migrations/_003_YDBToGRDBMigration.swift | 2 +- .../Database/Types/Migration.swift | 4 +- SessionUtilitiesKit/General/Logging.swift | 337 ++++++++++++++++-- SessionUtilitiesKit/JobRunner/JobRunner.swift | 2 +- .../LibSession/LibSession.swift | 41 ++- .../Utilities/TypeConversion+Utilities.swift | 6 +- 27 files changed, 521 insertions(+), 280 deletions(-) diff --git a/Scripts/LintLocalizableStrings.swift b/Scripts/LintLocalizableStrings.swift index 9860c275f..851fb78e7 100755 --- a/Scripts/LintLocalizableStrings.swift +++ b/Scripts/LintLocalizableStrings.swift @@ -38,7 +38,13 @@ extension ProjectState { .contains("print(", caseSensitive: false), .contains("NSLog(", caseSensitive: false), .contains("SNLog(", caseSensitive: false), - .contains("SNLogNotTests(", caseSensitive: false), + .contains("Log.setup(", caseSensitive: false), + .contains("Log.trace(", caseSensitive: false), + .contains("Log.debug(", caseSensitive: false), + .contains("Log.info(", caseSensitive: false), + .contains("Log.warn(", caseSensitive: false), + .contains("Log.error(", caseSensitive: false), + .contains("Log.critical(", caseSensitive: false), .contains("owsFailDebug(", caseSensitive: false), .contains("#imageLiteral(resourceName:", caseSensitive: false), .contains("UIImage(named:", caseSensitive: false), diff --git a/Session/Calls/Call Management/SessionCallManager.swift b/Session/Calls/Call Management/SessionCallManager.swift index 638d7e3fd..111769920 100644 --- a/Session/Calls/Call Management/SessionCallManager.swift +++ b/Session/Calls/Call Management/SessionCallManager.swift @@ -146,7 +146,7 @@ public final class SessionCallManager: NSObject, CallManagerProtocol { if Singleton.hasAppContext && Singleton.appContext.isInBackground { (UIApplication.shared.delegate as? AppDelegate)?.stopPollers() - DDLog.flushLog() + Log.flush() } } diff --git a/Session/Conversations/ConversationVC+Interaction.swift b/Session/Conversations/ConversationVC+Interaction.swift index 23e411979..d150e28da 100644 --- a/Session/Conversations/ConversationVC+Interaction.swift +++ b/Session/Conversations/ConversationVC+Interaction.swift @@ -2034,6 +2034,9 @@ extension ConversationVC: .filter(id: cellViewModel.id) .deleteAll(db) } + + // Stop it's audio if needed + self?.viewModel.stopAudioIfNeeded(for: cellViewModel) } // Regardless of success we should dismiss and callback @@ -2108,6 +2111,9 @@ extension ConversationVC: .filter(id: cellViewModel.id) .deleteAll(db) } + + // Stop it's audio if needed + self?.viewModel.stopAudioIfNeeded(for: cellViewModel) } } return @@ -2122,6 +2128,9 @@ extension ConversationVC: .filter(id: cellViewModel.id) .deleteAll(db) } + + // Stop it's audio if needed + viewModel.stopAudioIfNeeded(for: cellViewModel) return } @@ -2190,6 +2199,9 @@ extension ConversationVC: using: dependencies ) } + + // Stop it's audio if needed + viewModel.stopAudioIfNeeded(for: cellViewModel) return } @@ -2215,6 +2227,9 @@ extension ConversationVC: ) } self?.showInputAccessoryView() + + // Stop it's audio if needed + self?.viewModel.stopAudioIfNeeded(for: cellViewModel) }) actionSheet.addAction(UIAlertAction( diff --git a/Session/Conversations/ConversationViewModel.swift b/Session/Conversations/ConversationViewModel.swift index 8cd170b70..b91b9a744 100644 --- a/Session/Conversations/ConversationViewModel.swift +++ b/Session/Conversations/ConversationViewModel.swift @@ -200,6 +200,11 @@ public class ConversationViewModel: OWSAudioPlayerDelegate { } } + deinit { + // Stop any audio playing when leaving the screen + audioPlayer.wrappedValue?.stop() + } + // MARK: - Thread Data private var _threadData: Atomic @@ -1016,6 +1021,12 @@ public class ConversationViewModel: OWSAudioPlayerDelegate { updatedPlaybackInfo?.updateCallback(updatedPlaybackInfo, nil) } + public func stopAudioIfNeeded(for viewModel: MessageViewModel) { + guard viewModel.id == currentPlayingInteraction.wrappedValue else { return } + + audioPlayer.wrappedValue?.stop() + } + public func stopAudio() { audioPlayer.wrappedValue?.stop() diff --git a/Session/Meta/AppDelegate.swift b/Session/Meta/AppDelegate.swift index eba309ed1..bc8fcebd2 100644 --- a/Session/Meta/AppDelegate.swift +++ b/Session/Meta/AppDelegate.swift @@ -29,6 +29,7 @@ class AppDelegate: UIResponder, UIApplicationDelegate, UNUserNotificationCenterD // MARK: - Lifecycle func application(_ application: UIApplication, didFinishLaunchingWithOptions launchOptions: [UIApplication.LaunchOptionsKey: Any]?) -> Bool { + Log.info("[AppDelegate] didFinishLaunchingWithOptions called.") startTime = CACurrentMediaTime() // These should be the first things we do (the startup process can fail without them) @@ -50,11 +51,16 @@ class AppDelegate: UIResponder, UIApplicationDelegate, UNUserNotificationCenterD AppSetup.setupEnvironment( appSpecificBlock: { - // Create AppEnvironment - AppEnvironment.shared.setup() + Log.setup(with: Logger(primaryPrefix: "Session")) + Log.info("[AppDelegate] Setting up environment.") + + // Setup LibSession LibSession.addLogger() LibSession.createNetworkIfNeeded() + // Create AppEnvironment + AppEnvironment.shared.setup() + // Note: Intentionally dispatching sync as we want to wait for these to complete before // continuing DispatchQueue.main.sync { @@ -124,12 +130,14 @@ class AppDelegate: UIResponder, UIApplicationDelegate, UNUserNotificationCenterD object: nil ) - Logger.info("application: didFinishLaunchingWithOptions completed.") - + Log.info("[AppDelegate] didFinishLaunchingWithOptions completed.") return true } func applicationWillEnterForeground(_ application: UIApplication) { + Log.enterForeground() + Log.info("[AppDelegate] applicationWillEnterForeground.") + /// **Note:** We _shouldn't_ need to call this here but for some reason the OS doesn't seems to /// be calling the `userNotificationCenter(_:,didReceive:withCompletionHandler:)` /// method when the device is locked while the app is in the foreground (or if the user returns to the @@ -146,7 +154,7 @@ class AppDelegate: UIResponder, UIApplicationDelegate, UNUserNotificationCenterD // If we've already completed migrations at least once this launch then check // to see if any "delayed" migrations now need to run if Storage.shared.hasCompletedMigrations { - SNLog("Checking for pending migrations") + Log.info("Checking for pending migrations") let initialLaunchFailed: Bool = self.initialLaunchFailed Singleton.appReadiness.invalidate() @@ -189,9 +197,9 @@ class AppDelegate: UIResponder, UIApplicationDelegate, UNUserNotificationCenterD } func applicationDidEnterBackground(_ application: UIApplication) { - if !hasInitialRootViewController { SNLog("Entered background before startup was completed") } - - DDLog.flushLog() + if !hasInitialRootViewController { Log.info("Entered background before startup was completed") } + Log.info("[AppDelegate] applicationDidEnterBackground.") + Log.flush() // NOTE: Fix an edge case where user taps on the callkit notification // but answers the call on another device @@ -210,16 +218,18 @@ class AppDelegate: UIResponder, UIApplicationDelegate, UNUserNotificationCenterD } func applicationDidReceiveMemoryWarning(_ application: UIApplication) { - Logger.info("applicationDidReceiveMemoryWarning") + Log.info("applicationDidReceiveMemoryWarning") } func applicationWillTerminate(_ application: UIApplication) { - DDLog.flushLog() + Log.info("[AppDelegate] applicationWillTerminate.") + Log.flush() stopPollers() } func applicationDidBecomeActive(_ application: UIApplication) { + Log.info("[AppDelegate] applicationDidBecomeActive.") guard !SNUtilitiesKit.isRunningTests else { return } UserDefaults.sharedLokiProject?[.isMainAppActive] = true @@ -247,11 +257,12 @@ class AppDelegate: UIResponder, UIApplicationDelegate, UNUserNotificationCenterD } func applicationWillResignActive(_ application: UIApplication) { + Log.info("[AppDelegate] applicationWillResignActive.") clearAllNotificationsAndRestoreBadgeCount() UserDefaults.sharedLokiProject?[.isMainAppActive] = false - DDLog.flushLog() + Log.flush() } // MARK: - Orientation @@ -288,7 +299,7 @@ class AppDelegate: UIResponder, UIApplicationDelegate, UNUserNotificationCenterD LibSession.closeNetworkConnections() } - SNLog("Background poll failed due to manual timeout") + Log.info("Background poll failed due to manual timeout") completionHandler(.failed) } @@ -324,7 +335,7 @@ class AppDelegate: UIResponder, UIApplicationDelegate, UNUserNotificationCenterD // MARK: - App Readiness private func completePostMigrationSetup(calledFrom lifecycleMethod: LifecycleMethod, needsConfigSync: Bool) { - SNLog("Migrations completed, performing setup and ensuring rootViewController") + Log.info("Migrations completed, performing setup and ensuring rootViewController") Configuration.performMainSetup() JobRunner.setExecutor(SyncPushTokensJob.self, for: .syncPushTokens) @@ -339,7 +350,7 @@ class AppDelegate: UIResponder, UIApplicationDelegate, UNUserNotificationCenterD // the user is in an invalid state (and should have already been shown a modal) guard success else { return } - SNLog("RootViewController ready for state: \(Onboarding.State.current), readying remaining processes") + Log.info("RootViewController ready for state: \(Onboarding.State.current), readying remaining processes") self?.initialLaunchFailed = false /// Trigger any launch-specific jobs and start the JobRunner with `JobRunner.appDidFinishLaunching()` some @@ -395,7 +406,7 @@ class AppDelegate: UIResponder, UIApplicationDelegate, UNUserNotificationCenterD // Add a log to track the proper startup time of the app so we know whether we need to // improve it in the future from user logs let endTime: CFTimeInterval = CACurrentMediaTime() - SNLog("\(lifecycleMethod.timingName) completed in \((self?.startTime).map { ceil((endTime - $0) * 1000) } ?? -1)ms") + Log.info("\(lifecycleMethod.timingName) completed in \((self?.startTime).map { ceil((endTime - $0) * 1000) } ?? -1)ms") } // May as well run these on the background thread @@ -468,11 +479,11 @@ class AppDelegate: UIResponder, UIApplicationDelegate, UNUserNotificationCenterD } alert.addAction(UIAlertAction(title: "APP_STARTUP_EXIT".localized(), style: .default) { _ in - DDLog.flushLog() + Log.flush() exit(0) }) - SNLog("Showing startup alert due to error: \(error.name)") + Log.info("Showing startup alert due to error: \(error.name)") self.window?.rootViewController?.present(alert, animated: animated, completion: presentationCompletion) } @@ -503,7 +514,7 @@ class AppDelegate: UIResponder, UIApplicationDelegate, UNUserNotificationCenterD UNUserNotificationCenter.current().add(notificationRequest, withCompletionHandler: nil) UIApplication.shared.applicationIconBadgeNumber = 1 - DDLog.flushLog() + Log.flush() exit(0) } @@ -649,14 +660,14 @@ class AppDelegate: UIResponder, UIApplicationDelegate, UNUserNotificationCenterD func application(_ application: UIApplication, didRegisterForRemoteNotificationsWithDeviceToken deviceToken: Data) { PushRegistrationManager.shared.didReceiveVanillaPushToken(deviceToken) - Logger.info("Registering for push notifications with token: \(deviceToken).") + Log.info("Registering for push notifications.") } func application(_ application: UIApplication, didFailToRegisterForRemoteNotificationsWithError error: Error) { - Logger.error("Failed to register push token with error: \(error).") + Log.error("Failed to register push token with error: \(error).") #if DEBUG - Logger.warn("We're in debug mode. Faking success for remote registration with a fake push identifier.") + Log.warn("We're in debug mode. Faking success for remote registration with a fake push identifier.") PushRegistrationManager.shared.didReceiveVanillaPushToken(Data(count: 32)) #else PushRegistrationManager.shared.didFailToReceiveVanillaPushToken(error: error) @@ -700,7 +711,7 @@ class AppDelegate: UIResponder, UIApplicationDelegate, UNUserNotificationCenterD /// This decision should be based on whether the information in the notification is otherwise visible to the user. func userNotificationCenter(_ center: UNUserNotificationCenter, willPresent notification: UNNotification, withCompletionHandler completionHandler: @escaping (UNNotificationPresentationOptions) -> Void) { if notification.request.content.userInfo["remote"] != nil { - Logger.info("[Loki] Ignoring remote notifications while the app is in the foreground.") + Log.info("Ignoring remote notifications while the app is in the foreground.") return } diff --git a/Session/Meta/AppEnvironment.swift b/Session/Meta/AppEnvironment.swift index c021c5a54..a302dfd03 100644 --- a/Session/Meta/AppEnvironment.swift +++ b/Session/Meta/AppEnvironment.swift @@ -10,18 +10,6 @@ import SessionMessagingKit public class AppEnvironment { - enum ExtensionType { - case share - case notification - - var name: String { - switch self { - case .share: return "ShareExtension" - case .notification: return "NotificationExtension" - } - } - } - private static var _shared: AppEnvironment = AppEnvironment() public class var shared: AppEnvironment { @@ -39,7 +27,6 @@ public class AppEnvironment { public var callManager: SessionCallManager public var notificationPresenter: NotificationPresenter public var pushRegistrationManager: PushRegistrationManager - public var fileLogger: DDFileLogger // Stored properties cannot be marked as `@available`, only classes and functions. // Instead, store a private `Any` and wrap it with a public `@available` getter @@ -54,7 +41,6 @@ public class AppEnvironment { self.notificationPresenter = NotificationPresenter() self.pushRegistrationManager = PushRegistrationManager() self._userNotificationActionHandler = UserNotificationActionHandler() - self.fileLogger = DDFileLogger() SwiftSingletons.register(self) } @@ -67,87 +53,5 @@ public class AppEnvironment { SessionEnvironment.shared?.notificationsManager.mutate { $0 = notificationPresenter } - setupLogFiles() - } - - private func setupLogFiles() { - fileLogger.rollingFrequency = kDayInterval // Refresh everyday - fileLogger.logFileManager.maximumNumberOfLogFiles = 3 // Save 3 days' log files - DDLog.add(fileLogger) - - // The extensions write their logs to the app shared directory but the main app writes - // to a local directory (so they can be exported via XCode) - the below code reads any - // logs from the shared directly and attempts to add them to the main app logs to make - // debugging user issues in extensions easier - DispatchQueue.global(qos: .utility).async { [fileLogger] in - guard let currentLogFileInfo: DDLogFileInfo = fileLogger.currentLogFileInfo else { - return SNLog("Unable to retrieve current log file.") - } - - DDLog.loggingQueue.async { - let extensionInfo: [(dir: String, type: ExtensionType)] = [ - ("\(OWSFileSystem.appSharedDataDirectoryPath())/Logs/NotificationExtension", .notification), - ("\(OWSFileSystem.appSharedDataDirectoryPath())/Logs/ShareExtension", .share) - ] - let extensionLogs: [(path: String, type: ExtensionType)] = extensionInfo.flatMap { dir, type -> [(path: String, type: ExtensionType)] in - guard let files: [String] = try? FileManager.default.contentsOfDirectory(atPath: dir) else { return [] } - - return files.map { ("\(dir)/\($0)", type) } - } - - do { - guard let fileHandle: FileHandle = FileHandle(forWritingAtPath: currentLogFileInfo.filePath) else { - throw StorageError.objectNotFound - } - - // Ensure we close the file handle - defer { fileHandle.closeFile() } - - // Move to the end of the file to insert the logs - if #available(iOS 13.4, *) { try fileHandle.seekToEnd() } - else { fileHandle.seekToEndOfFile() } - - try extensionLogs - .grouped(by: \.type) - .forEach { type, value in - guard !value.isEmpty else { return } // Ignore if there are no logs - guard - let typeNameStartData: Data = "🧩 \(type.name) -- Start\n".data(using: .utf8), - let typeNameEndData: Data = "🧩 \(type.name) -- End\n".data(using: .utf8) - else { throw StorageError.invalidData } - - var hasWrittenStartLog: Bool = false - - // Write the logs - try value.forEach { path, _ in - let logData: Data = try Data(contentsOf: URL(fileURLWithPath: path)) - - guard !logData.isEmpty else { return } // Ignore empty files - - // Write the type start separator if needed - if !hasWrittenStartLog { - if #available(iOS 13.4, *) { try fileHandle.write(contentsOf: typeNameStartData) } - else { fileHandle.write(typeNameStartData) } - hasWrittenStartLog = true - } - - // Write the log data to the log file - if #available(iOS 13.4, *) { try fileHandle.write(contentsOf: logData) } - else { fileHandle.write(logData) } - - // Extension logs have been writen to the app logs, remove them now - try? FileManager.default.removeItem(atPath: path) - } - - // Write the type end separator if needed - if hasWrittenStartLog { - if #available(iOS 13.4, *) { try fileHandle.write(contentsOf: typeNameEndData) } - else { fileHandle.write(typeNameEndData) } - } - } - } - catch { SNLog("Unable to write extension logs to current log file") } - } - } } } diff --git a/Session/Meta/MainAppContext.swift b/Session/Meta/MainAppContext.swift index 3739db2d1..40bb5d42c 100644 --- a/Session/Meta/MainAppContext.swift +++ b/Session/Meta/MainAppContext.swift @@ -62,12 +62,6 @@ final class MainAppContext: AppContext { name: UIApplication.didBecomeActiveNotification, object: nil ) - NotificationCenter.default.addObserver( - self, - selector: #selector(applicationWillTerminate(notification:)), - name: UIApplication.willTerminateNotification, - object: nil - ) } deinit { @@ -93,9 +87,6 @@ final class MainAppContext: AppContext { self.reportedApplicationState = .background - OWSLogger.info("") - DDLog.flushLog() - NotificationCenter.default.post( name: .sessionDidEnterBackground, object: nil @@ -107,9 +98,6 @@ final class MainAppContext: AppContext { self.reportedApplicationState = .inactive - OWSLogger.info("") - DDLog.flushLog() - NotificationCenter.default.post( name: .sessionWillResignActive, object: nil @@ -121,20 +109,11 @@ final class MainAppContext: AppContext { self.reportedApplicationState = .active - OWSLogger.info("") - NotificationCenter.default.post( name: .sessionDidBecomeActive, object: nil ) } - - @objc private func applicationWillTerminate(notification: NSNotification) { - AssertIsOnMainThread() - - OWSLogger.info("") - DDLog.flushLog() - } // MARK: - AppContext Functions diff --git a/Session/Meta/SessionApp.swift b/Session/Meta/SessionApp.swift index cbc6a97f3..eb464e26b 100644 --- a/Session/Meta/SessionApp.swift +++ b/Session/Meta/SessionApp.swift @@ -112,10 +112,7 @@ public struct SessionApp { // MARK: - Functions public static func resetAppData(onReset: (() -> ())? = nil) { - // This _should_ be wiped out below. - Logger.error("") - DDLog.flushLog() - + Log.flush() LibSession.clearMemoryState() Storage.resetAllStorage() ProfileManager.resetProfileStorage() diff --git a/Session/Path/PathVC.swift b/Session/Path/PathVC.swift index bf52308cc..54d8d8bc9 100644 --- a/Session/Path/PathVC.swift +++ b/Session/Path/PathVC.swift @@ -14,7 +14,7 @@ final class PathVC: BaseVC { private var pathUpdateId: UUID? private var cacheUpdateId: UUID? - private var lastPath: Set = [] + private var lastPath: [LibSession.Snode] = [] // MARK: - Components @@ -136,8 +136,8 @@ final class PathVC: BaseVC { // MARK: - Updating - private func update(paths: [Set], force: Bool) { - guard let pathToDisplay: Set = paths.first else { + private func update(paths: [[LibSession.Snode]], force: Bool) { + guard let pathToDisplay: [LibSession.Snode] = paths.first else { pathStackView.arrangedSubviews.forEach { $0.removeFromSuperview() } spinner.startAnimating() diff --git a/Session/Settings/HelpViewModel.swift b/Session/Settings/HelpViewModel.swift index 0e24701d4..887625f1d 100644 --- a/Session/Settings/HelpViewModel.swift +++ b/Session/Settings/HelpViewModel.swift @@ -179,13 +179,11 @@ class HelpViewModel: SessionTableViewModel, NavigatableStateHolder, ObservableTa animated: Bool = true, onShareComplete: (() -> ())? = nil ) { - OWSLogger.info("[Version] \(SessionApp.versionInfo)") - DDLog.flushLog() - - let logFilePaths: [String] = AppEnvironment.shared.fileLogger.logFileManager.sortedLogFilePaths + Log.info("[Version] \(SessionApp.versionInfo)") + Log.flush() guard - let latestLogFilePath: String = logFilePaths.first, + let latestLogFilePath: String = Log.logFilePath(), Singleton.hasAppContext, let viewController: UIViewController = Singleton.appContext.frontmostViewController else { return } diff --git a/Session/Utilities/IP2Country.swift b/Session/Utilities/IP2Country.swift index 3fbb94bb0..986e28a28 100644 --- a/Session/Utilities/IP2Country.swift +++ b/Session/Utilities/IP2Country.swift @@ -56,7 +56,7 @@ public enum IP2Country { } } - private static func populateCacheIfNeeded(paths: [Set]) { + private static func populateCacheIfNeeded(paths: [[LibSession.Snode]]) { guard !paths.isEmpty else { return } countryNamesCache.mutate { cache in diff --git a/SessionMessagingKit/Database/Migrations/_003_YDBToGRDBMigration.swift b/SessionMessagingKit/Database/Migrations/_003_YDBToGRDBMigration.swift index 5caba2821..1d22c7637 100644 --- a/SessionMessagingKit/Database/Migrations/_003_YDBToGRDBMigration.swift +++ b/SessionMessagingKit/Database/Migrations/_003_YDBToGRDBMigration.swift @@ -19,7 +19,7 @@ enum _003_YDBToGRDBMigration: Migration { Identity.userExists(db) else { return Storage.update(progress: 1, for: self, in: target) } - SNLogNotTests("[Migration Error] Attempted to perform legacy migation") + Log.info("[Migration Error] Attempted to perform legacy migation", silenceForTests: true) throw StorageError.migrationNoLongerSupported } } diff --git a/SessionMessagingKit/Sending & Receiving/MessageSender+Convenience.swift b/SessionMessagingKit/Sending & Receiving/MessageSender+Convenience.swift index 8b1a35e0e..d31b4b88a 100644 --- a/SessionMessagingKit/Sending & Receiving/MessageSender+Convenience.swift +++ b/SessionMessagingKit/Sending & Receiving/MessageSender+Convenience.swift @@ -142,7 +142,7 @@ extension MessageSender { return dependencies.storage .readPublisher { db -> (attachments: [Attachment], openGroup: OpenGroup?) in let attachmentStateInfo: [Attachment.StateInfo] = (try? Attachment - .stateInfo(interactionId: interactionId, state: .uploading) + .stateInfo(interactionId: interactionId) .fetchAll(db)) .defaulting(to: []) diff --git a/SessionMessagingKitTests/LibSession/LibSessionSpec.swift b/SessionMessagingKitTests/LibSession/LibSessionSpec.swift index ebb82399b..b461d37bc 100644 --- a/SessionMessagingKitTests/LibSession/LibSessionSpec.swift +++ b/SessionMessagingKitTests/LibSession/LibSessionSpec.swift @@ -214,6 +214,12 @@ class LibSessionSpec: QuickSpec { expect(LibSession.communityUrlFor(server: "SeRVer", roomToken: "RoOM", publicKey: "f8fec9b701000000ffffffff0400008000000000000000000000000000000000")) .to(equal("SeRVer/RoOM?public_key=f8fec9b701000000ffffffff0400008000000000000000000000000000000000")) } + + // MARK: ---- returns null when given a null value + it("returns null when given a null value") { + expect(LibSession.communityUrlFor(server: nil, roomToken: "RoOM", publicKey: "f8fec9b701000000ffffffff0400008000000000000000000000000000000000")) + .to(beNil()) + } } } } diff --git a/SessionNotificationServiceExtension/NotificationError.swift b/SessionNotificationServiceExtension/NotificationError.swift index 0ef6e2e8c..abf243ecf 100644 --- a/SessionNotificationServiceExtension/NotificationError.swift +++ b/SessionNotificationServiceExtension/NotificationError.swift @@ -9,12 +9,14 @@ enum NotificationError: Error, CustomStringConvertible { case processing(PushNotificationAPI.ProcessResult) case messageProcessing case messageHandling(MessageReceiverError) + case other(Error) public var description: String { switch self { case .processing(let result): return "Failed to process notification (\(result)) (NotificationError.processing)." case .messageProcessing: return "Failed to process message (NotificationError.messageProcessing)." case .messageHandling(let error): return "Failed to handle message (\(error)) (NotificationError.messageHandling)." + case .other(let error): return "Unknown error occurred: \(error) (NotificationError.other)." } } } diff --git a/SessionNotificationServiceExtension/NotificationServiceExtension.swift b/SessionNotificationServiceExtension/NotificationServiceExtension.swift index 538cd5191..0555165f1 100644 --- a/SessionNotificationServiceExtension/NotificationServiceExtension.swift +++ b/SessionNotificationServiceExtension/NotificationServiceExtension.swift @@ -16,17 +16,18 @@ public final class NotificationServiceExtension: UNNotificationServiceExtension private var contentHandler: ((UNNotificationContent) -> Void)? private var request: UNNotificationRequest? private var openGroupPollCancellable: AnyCancellable? - private var fileLogger: DDFileLogger? + private var hasCompleted: Atomic = Atomic(false) - public static let isFromRemoteKey = "remote" - public static let threadIdKey = "Signal.AppNotificationsUserInfoKey.threadId" - public static let threadVariantRaw = "Signal.AppNotificationsUserInfoKey.threadVariantRaw" - public static let threadNotificationCounter = "Session.AppNotificationsUserInfoKey.threadNotificationCounter" + public static let isFromRemoteKey = "remote" // stringlint:disable + public static let threadIdKey = "Signal.AppNotificationsUserInfoKey.threadId" // stringlint:disable + public static let threadVariantRaw = "Signal.AppNotificationsUserInfoKey.threadVariantRaw" // stringlint:disable + public static let threadNotificationCounter = "Session.AppNotificationsUserInfoKey.threadNotificationCounter" // stringlint:disable private static let callPreOfferLargeNotificationSupressionDuration: TimeInterval = 30 // MARK: Did receive a remote push notification request override public func didReceive(_ request: UNNotificationRequest, withContentHandler contentHandler: @escaping (UNNotificationContent) -> Void) { + Log.info("didReceive called.") self.contentHandler = contentHandler self.request = request @@ -83,7 +84,7 @@ public final class NotificationServiceExtension: UNNotificationServiceExtension // Just log if the notification was too long (a ~2k message should be able to fit so // these will most commonly be call or config messages) case .successTooLong: - return SNLog("[NotificationServiceExtension] Received too long notification for namespace: \(metadata.namespace).", forceNSLog: true) + return Log.info("Received too long notification for namespace: \(metadata.namespace).") case .legacyForceSilent, .failureNoContent: return } @@ -95,8 +96,7 @@ public final class NotificationServiceExtension: UNNotificationServiceExtension Storage.shared.write { db in do { guard let processedMessage: ProcessedMessage = try Message.processRawReceivedMessageAsNotification(db, data: data, metadata: metadata) else { - self.handleFailure(for: notificationContent, error: .messageProcessing) - return + throw NotificationError.messageProcessing } switch processedMessage { @@ -194,12 +194,29 @@ public final class NotificationServiceExtension: UNNotificationServiceExtension } } catch { - if let error = error as? MessageReceiverError, error.isRetryable { + // If an error occurred we want to rollback the transaction (by throwing) and then handle + // the error outside of the database + let handleError = { switch error { - case .invalidGroupPublicKey, .noGroupKeyPair, .outdatedMessage: self.completeSilenty() - default: self.handleFailure(for: notificationContent, error: .messageHandling(error)) + case MessageReceiverError.invalidGroupPublicKey, MessageReceiverError.noGroupKeyPair, + MessageReceiverError.outdatedMessage: + self.completeSilenty() + + case NotificationError.messageProcessing: + self.handleFailure(for: notificationContent, error: .messageProcessing) + + case let msgError as MessageReceiverError: + self.handleFailure(for: notificationContent, error: .messageHandling(msgError)) + + default: self.handleFailure(for: notificationContent, error: .other(error)) } } + + db.afterNextTransactionNested( + onCommit: { _ in handleError() }, + onRollback: { _ in handleError() } + ) + throw error } } } @@ -215,7 +232,7 @@ public final class NotificationServiceExtension: UNNotificationServiceExtension // to process new messages. guard !didPerformSetup else { return } - SNLog("[NotificationServiceExtension] Performing setup", forceNSLog: true) + Log.info("Performing setup.") didPerformSetup = true _ = AppVersion.sharedInstance() @@ -224,26 +241,26 @@ public final class NotificationServiceExtension: UNNotificationServiceExtension AppSetup.setupEnvironment( retrySetupIfDatabaseInvalid: true, - appSpecificBlock: { [weak self] in + appSpecificBlock: { + Log.setup(with: Logger( + primaryPrefix: "NotificationServiceExtension", // stringlint:disable + customDirectory: "\(OWSFileSystem.appSharedDataDirectoryPath())/Logs/NotificationExtension", // stringlint:disable + forceNSLog: true + )) + SessionEnvironment.shared?.notificationsManager.mutate { $0 = NSENotificationPresenter() } - // Add the file logger - let logFileManager: DDLogFileManagerDefault = DDLogFileManagerDefault( - logsDirectory: "\(OWSFileSystem.appSharedDataDirectoryPath())/Logs/NotificationExtension" // stringlint:disable - ) - let fileLogger: DDFileLogger = DDFileLogger(logFileManager: logFileManager) - fileLogger.rollingFrequency = kDayInterval // Refresh everyday - fileLogger.logFileManager.maximumNumberOfLogFiles = 3 // Save 3 days' log files - DDLog.add(fileLogger) - self?.fileLogger = fileLogger + // Setup LibSession + LibSession.addLogger() + LibSession.createNetworkIfNeeded() }, migrationsCompletion: { [weak self] result, needsConfigSync in switch result { // Only 'NSLog' works in the extension - viewable via Console.app case .failure(let error): - SNLog("[NotificationServiceExtension] Failed to complete migrations: \(error)", forceNSLog: true) + Log.error("Failed to complete migrations: \(error).") self?.completeSilenty() case .success: @@ -253,7 +270,7 @@ public final class NotificationServiceExtension: UNNotificationServiceExtension // so it is possible that could change in the future. If it does, do nothing // and don't disturb the user. Messages will be processed when they open the app. guard Storage.shared[.isReadyForAppExtensions] else { - SNLog("[NotificationServiceExtension] Not ready for extensions", forceNSLog: true) + Log.error("Not ready for extensions.") self?.completeSilenty() return } @@ -289,7 +306,7 @@ public final class NotificationServiceExtension: UNNotificationServiceExtension // App isn't ready until storage is ready AND all version migrations are complete. guard Storage.shared.isValid && migrationsCompleted else { - SNLog("[NotificationServiceExtension] Storage invalid", forceNSLog: true) + Log.error("Storage invalid.") self.completeSilenty() return } @@ -305,14 +322,23 @@ public final class NotificationServiceExtension: UNNotificationServiceExtension override public func serviceExtensionTimeWillExpire() { // Called just before the extension will be terminated by the system. // Use this as an opportunity to deliver your "best attempt" at modified content, otherwise the original push payload will be used. - SNLog("[NotificationServiceExtension] Execution time expired", forceNSLog: true) + Log.warn("Execution time expired.") openGroupPollCancellable?.cancel() completeSilenty() } private func completeSilenty() { - SNLog("[NotificationServiceExtension] Complete silently", forceNSLog: true) - DDLog.flushLog() + // Ensure we on'y run this once + guard + hasCompleted.mutate({ hasCompleted in + let wasCompleted: Bool = hasCompleted + hasCompleted = true + return wasCompleted + }) == false + else { return } + + Log.info("Complete silently.") + Log.flush() let silentContent: UNMutableNotificationContent = UNMutableNotificationContent() silentContent.badge = Storage.shared .read { db in try Interaction.fetchUnreadCount(db) } @@ -329,18 +355,18 @@ public final class NotificationServiceExtension: UNNotificationServiceExtension guard let caller: String = callMessage.sender, let timestamp = callMessage.sentTimestamp else { return } let payload: JSON = [ - "uuid": callMessage.uuid, - "caller": caller, - "timestamp": timestamp + "uuid": callMessage.uuid, // stringlint:disable + "caller": caller, // stringlint:disable + "timestamp": timestamp // stringlint:disable ] CXProvider.reportNewIncomingVoIPPushPayload(payload) { error in if let error = error { self.handleFailureForVoIP(db, for: callMessage) - SNLog("[NotificationServiceExtension] Failed to notify main app of call message: \(error)", forceNSLog: true) + Log.error("Failed to notify main app of call message: \(error).") } else { - SNLog("[NotificationServiceExtension] Successfully notified main app of call message.", forceNSLog: true) + Log.info("Successfully notified main app of call message.") UserDefaults.sharedLokiProject?[.lastCallPreOffer] = Date() self.completeSilenty() } @@ -373,18 +399,18 @@ public final class NotificationServiceExtension: UNNotificationServiceExtension UNUserNotificationCenter.current().add(request) { error in if let error = error { - SNLog("[NotificationServiceExtension] Failed to add notification request due to error: \(error)", forceNSLog: true) + Log.error("Failed to add notification request due to error: \(error).") } semaphore.signal() } semaphore.wait() - SNLog("[NotificationServiceExtension] Add remote notification request", forceNSLog: true) - DDLog.flushLog() + Log.info("Add remote notification request.") + Log.flush() } private func handleFailure(for content: UNMutableNotificationContent, error: NotificationError) { - SNLog("[NotificationServiceExtension] Show generic failure message due to error: \(error)", forceNSLog: true) - DDLog.flushLog() + Log.error("Show generic failure message due to error: \(error).") + Log.flush() Storage.suspendDatabaseAccess() LibSession.closeNetworkConnections() diff --git a/SessionShareExtension/ShareAppExtensionContext.swift b/SessionShareExtension/ShareAppExtensionContext.swift index 9ec316568..ddd3e546d 100644 --- a/SessionShareExtension/ShareAppExtensionContext.swift +++ b/SessionShareExtension/ShareAppExtensionContext.swift @@ -74,7 +74,6 @@ final class ShareAppExtensionContext: AppContext { @objc private func extensionHostDidBecomeActive(notification: NSNotification) { AssertIsOnMainThread() - OWSLogger.info("") self.reportedApplicationState = .active @@ -89,9 +88,6 @@ final class ShareAppExtensionContext: AppContext { self.reportedApplicationState = .inactive - OWSLogger.info("") - DDLog.flushLog() - NotificationCenter.default.post( name: .sessionWillResignActive, object: nil @@ -100,9 +96,6 @@ final class ShareAppExtensionContext: AppContext { @objc private func extensionHostDidEnterBackground(notification: NSNotification) { AssertIsOnMainThread() - - OWSLogger.info("") - DDLog.flushLog() self.reportedApplicationState = .background @@ -114,8 +107,6 @@ final class ShareAppExtensionContext: AppContext { @objc private func extensionHostWillEnterForeground(notification: NSNotification) { AssertIsOnMainThread() - - OWSLogger.info("") self.reportedApplicationState = .inactive diff --git a/SessionShareExtension/ShareNavController.swift b/SessionShareExtension/ShareNavController.swift index 063d0467f..d47a2fcda 100644 --- a/SessionShareExtension/ShareNavController.swift +++ b/SessionShareExtension/ShareNavController.swift @@ -36,8 +36,6 @@ final class ShareNavController: UINavigationController, ShareViewDelegate { if !Singleton.hasAppContext { Singleton.setup(appContext: ShareAppExtensionContext(rootViewController: self)) } - - Logger.info("") _ = AppVersion.sharedInstance() @@ -53,24 +51,23 @@ final class ShareNavController: UINavigationController, ShareViewDelegate { } AppSetup.setupEnvironment( - appSpecificBlock: { [weak self] in + appSpecificBlock: { + Log.setup(with: Logger( + primaryPrefix: "SessionShareExtension", // stringlint:disable + customDirectory: "\(OWSFileSystem.appSharedDataDirectoryPath())/Logs/ShareExtension" // stringlint:disable + )) + SessionEnvironment.shared?.notificationsManager.mutate { $0 = NoopNotificationsManager() } - // Add the file logger - let logFileManager: DDLogFileManagerDefault = DDLogFileManagerDefault( - logsDirectory: "\(OWSFileSystem.appSharedDataDirectoryPath())/Logs/ShareExtension" // stringlint:disable - ) - let fileLogger: DDFileLogger = DDFileLogger(logFileManager: logFileManager) - fileLogger.rollingFrequency = kDayInterval // Refresh everyday - fileLogger.logFileManager.maximumNumberOfLogFiles = 3 // Save 3 days' log files - DDLog.add(fileLogger) - self?.fileLogger = fileLogger + // Setup LibSession + LibSession.addLogger() + LibSession.createNetworkIfNeeded() }, migrationsCompletion: { [weak self] result, needsConfigSync in switch result { - case .failure: SNLog("[SessionShareExtension] Failed to complete migrations") + case .failure: Log.error("Failed to complete migrations") case .success: DispatchQueue.main.async { // Need to manually trigger these since we don't have a "mainWindow" here @@ -112,8 +109,6 @@ final class ShareNavController: UINavigationController, ShareViewDelegate { func versionMigrationsDidComplete(needsConfigSync: Bool) { AssertIsOnMainThread() - Logger.debug("") - // If we need a config sync then trigger it now if needsConfigSync { Storage.shared.write { db in @@ -143,8 +138,6 @@ final class ShareNavController: UINavigationController, ShareViewDelegate { SignalUtilitiesKit.Configuration.performMainSetup() - Logger.debug("") - // Note that this does much more than set a flag; // it will also run all deferred blocks. Singleton.appReadiness.setAppReady() @@ -174,9 +167,7 @@ final class ShareNavController: UINavigationController, ShareViewDelegate { @objc public func applicationDidEnterBackground() { AssertIsOnMainThread() - DDLog.flushLog() - - Logger.info("") + Log.flush() if Storage.shared[.isScreenLockEnabled] { self.dismiss(animated: false) { [weak self] in @@ -188,7 +179,7 @@ final class ShareNavController: UINavigationController, ShareViewDelegate { deinit { NotificationCenter.default.removeObserver(self) - DDLog.flushLog() + Log.flush() // Share extensions reside in a process that may be reused between usages. // That isn't safe; the codebase is full of statics (e.g. singletons) which diff --git a/SessionShareExtension/ThreadPickerVC.swift b/SessionShareExtension/ThreadPickerVC.swift index f798d5eab..e6f98d65c 100644 --- a/SessionShareExtension/ThreadPickerVC.swift +++ b/SessionShareExtension/ThreadPickerVC.swift @@ -97,6 +97,12 @@ final class ThreadPickerVC: UIViewController, UITableViewDataSource, UITableView super.viewWillDisappear(animated) stopObservingChanges() + + // When the thread picker disappears it means the user has left the screen (this will be called + // whether the user has sent the message or cancelled sending) + Log.flush() + Storage.suspendDatabaseAccess() + LibSession.closeNetworkConnections() } @objc func applicationDidBecomeActive(_ notification: Notification) { @@ -308,7 +314,7 @@ final class ThreadPickerVC: UIViewController, UITableViewDataSource, UITableView .receive(on: DispatchQueue.main) .sinkUntilComplete( receiveCompletion: { [weak self] result in - DDLog.flushLog() + Log.flush() Storage.suspendDatabaseAccess() LibSession.closeNetworkConnections() activityIndicator.dismiss { } diff --git a/SessionSnodeKit/Database/Migrations/_003_YDBToGRDBMigration.swift b/SessionSnodeKit/Database/Migrations/_003_YDBToGRDBMigration.swift index 1ef646a25..31d8e179e 100644 --- a/SessionSnodeKit/Database/Migrations/_003_YDBToGRDBMigration.swift +++ b/SessionSnodeKit/Database/Migrations/_003_YDBToGRDBMigration.swift @@ -19,7 +19,7 @@ enum _003_YDBToGRDBMigration: Migration { Identity.userExists(db) else { return Storage.update(progress: 1, for: self, in: target) } - SNLogNotTests("[Migration Error] Attempted to perform legacy migation") + Log.info("[Migration Error] Attempted to perform legacy migation", silenceForTests: true) throw StorageError.migrationNoLongerSupported } } diff --git a/SessionSnodeKit/LibSession/LibSession+Networking.swift b/SessionSnodeKit/LibSession/LibSession+Networking.swift index 684f6c399..fdae14419 100644 --- a/SessionSnodeKit/LibSession/LibSession+Networking.swift +++ b/SessionSnodeKit/LibSession/LibSession+Networking.swift @@ -12,9 +12,9 @@ import SessionUtilitiesKit public extension LibSession { private static var networkCache: Atomic?> = Atomic(nil) private static var snodeCachePath: String { "\(OWSFileSystem.appSharedDataDirectoryPath())/snodeCache" } - private static var lastPaths: Atomic<[Set]> = Atomic([]) + private static var lastPaths: Atomic<[[Snode]]> = Atomic([]) private static var lastNetworkStatus: Atomic = Atomic(.unknown) - private static var pathsChangedCallbacks: Atomic<[UUID: ([Set], UUID) -> ()]> = Atomic([:]) + private static var pathsChangedCallbacks: Atomic<[UUID: ([[Snode]], UUID) -> ()]> = Atomic([:]) private static var networkStatusCallbacks: Atomic<[UUID: (NetworkStatus) -> ()]> = Atomic([:]) static var hasPaths: Bool { !lastPaths.wrappedValue.isEmpty } @@ -63,12 +63,12 @@ public extension LibSession { networkStatusCallbacks.mutate { $0.removeValue(forKey: callbackId) } } - static func onPathsChanged(skipInitialCallbackIfEmpty: Bool = false, callback: @escaping ([Set], UUID) -> ()) -> UUID { + static func onPathsChanged(skipInitialCallbackIfEmpty: Bool = false, callback: @escaping ([[Snode]], UUID) -> ()) -> UUID { let callbackId: UUID = UUID() pathsChangedCallbacks.mutate { $0[callbackId] = callback } // Trigger the callback immediately with the most recent status - let lastPaths: [Set] = self.lastPaths.wrappedValue + let lastPaths: [[Snode]] = self.lastPaths.wrappedValue if !lastPaths.isEmpty || !skipInitialCallbackIfEmpty { callback(lastPaths, callbackId) } @@ -347,7 +347,7 @@ public extension LibSession { } private static func updatePaths(cPathsPtr: UnsafeMutablePointer?, pathsLen: Int) { - var paths: [Set] = [] + var paths: [[Snode]] = [] if let cPathsPtr: UnsafeMutablePointer = cPathsPtr { var cPaths: [onion_request_path] = [] @@ -358,9 +358,9 @@ public extension LibSession { // Copy the nodes over as the memory will be freed after the callback is run paths = cPaths.map { cPath in - var nodes: Set = [] + var nodes: [Snode] = [] (0.. ((_ db: Database) throws -> ()) { return { (db: Database) in - SNLogNotTests("[Migration Info] Starting \(targetIdentifier.key(with: self))") + Log.info("[Migration Info] Starting \(targetIdentifier.key(with: self))", silenceForTests: true) storage?.willStartMigration(db, self) storage?.internalCurrentlyRunningMigration.mutate { $0 = (targetIdentifier, self) } defer { storage?.internalCurrentlyRunningMigration.mutate { $0 = nil } } try migrate(db) - SNLogNotTests("[Migration Info] Completed \(targetIdentifier.key(with: self))") + Log.info("[Migration Info] Completed \(targetIdentifier.key(with: self))", silenceForTests: true) } } } diff --git a/SessionUtilitiesKit/General/Logging.swift b/SessionUtilitiesKit/General/Logging.swift index 7e11e6e01..dfe86a970 100644 --- a/SessionUtilitiesKit/General/Logging.swift +++ b/SessionUtilitiesKit/General/Logging.swift @@ -5,6 +5,319 @@ import Foundation import SignalCoreKit +// MARK: - Log + +public enum Log { + fileprivate typealias LogInfo = (level: Log.Level, message: String, withPrefixes: Bool, silenceForTests: Bool) + + public enum Level { + case trace + case debug + case info + case warn + case error + case critical + case off + } + + private static var logger: Atomic = Atomic(nil) + private static var pendingStartupLogs: Atomic<[LogInfo]> = Atomic([]) + + public static func setup(with logger: Logger) { + logger.retrievePendingStartupLogs = { + pendingStartupLogs.mutate { pendingStartupLogs in + let logs: [LogInfo] = pendingStartupLogs + pendingStartupLogs = [] + return logs + } + } + Log.logger.mutate { $0 = logger } + } + + public static func enterForeground() { + guard logger.wrappedValue != nil else { return } + + OWSLogger.info("") + OWSLogger.info("") + } + + public static func logFilePath() -> String? { + guard + let logger: Logger = logger.wrappedValue + else { return nil } + + return logger.fileLogger.logFileManager.sortedLogFilePaths.first + } + + public static func flush() { + DDLog.flushLog() + } + + // MARK: - Log Functions + + public static func trace( + _ message: String, + withPrefixes: Bool = true, + silenceForTests: Bool = false + ) { + custom(.trace, message, withPrefixes: withPrefixes, silenceForTests: silenceForTests) + } + + public static func debug( + _ message: String, + withPrefixes: Bool = true, + silenceForTests: Bool = false + ) { + custom(.debug, message, withPrefixes: withPrefixes, silenceForTests: silenceForTests) + } + + public static func info( + _ message: String, + withPrefixes: Bool = true, + silenceForTests: Bool = false + ) { + custom(.info, message, withPrefixes: withPrefixes, silenceForTests: silenceForTests) + } + + public static func warn( + _ message: String, + withPrefixes: Bool = true, + silenceForTests: Bool = false + ) { + custom(.warn, message, withPrefixes: withPrefixes, silenceForTests: silenceForTests) + } + + public static func error( + _ message: String, + withPrefixes: Bool = true, + silenceForTests: Bool = false + ) { + custom(.error, message, withPrefixes: withPrefixes, silenceForTests: silenceForTests) + } + + public static func critical( + _ message: String, + withPrefixes: Bool = true, + silenceForTests: Bool = false + ) { + custom(.critical, message, withPrefixes: withPrefixes, silenceForTests: silenceForTests) + } + + public static func custom( + _ level: Log.Level, + _ message: String, + withPrefixes: Bool, + silenceForTests: Bool + ) { + guard + let logger: Logger = logger.wrappedValue, + logger.startupCompleted.wrappedValue + else { return pendingStartupLogs.mutate { $0.append((level, message, withPrefixes, silenceForTests)) } } + + logger.log(level, message, withPrefixes: withPrefixes, silenceForTests: silenceForTests) + } +} + +// MARK: - Logger + +public class Logger { + private let isRunningTests: Bool = (ProcessInfo.processInfo.environment["XCTestConfigurationFilePath"] == nil) + private let primaryPrefix: String + private let forceNSLog: Bool + fileprivate let fileLogger: DDFileLogger + fileprivate let startupCompleted: Atomic = Atomic(false) + fileprivate var retrievePendingStartupLogs: (() -> [Log.LogInfo])? + + public init( + primaryPrefix: String, + customDirectory: String? = nil, + forceNSLog: Bool = false + ) { + self.primaryPrefix = primaryPrefix + self.forceNSLog = forceNSLog + + switch customDirectory { + case .none: self.fileLogger = DDFileLogger() + case .some(let customDirectory): + let logFileManager: DDLogFileManagerDefault = DDLogFileManagerDefault(logsDirectory: customDirectory) + self.fileLogger = DDFileLogger(logFileManager: logFileManager) + } + + self.fileLogger.rollingFrequency = kDayInterval // Refresh everyday + self.fileLogger.logFileManager.maximumNumberOfLogFiles = 3 // Save 3 days' log files + DDLog.add(self.fileLogger) + + // Now that we are setup we should load the extension logs which will then + // complete the startup process when completed + self.loadExtensionLogs() + } + + // MARK: - Functions + + private func loadExtensionLogs() { + // The extensions write their logs to the app shared directory but the main app writes + // to a local directory (so they can be exported via XCode) - the below code reads any + // logs from the shared directly and attempts to add them to the main app logs to make + // debugging user issues in extensions easier + DispatchQueue.global(qos: .utility).async { [weak self] in + guard let currentLogFileInfo: DDLogFileInfo = self?.fileLogger.currentLogFileInfo else { + self?.completeStartup(error: "Unable to retrieve current log file.") + return + } + + DDLog.loggingQueue.async { + let extensionInfo: [(dir: String, type: ExtensionType)] = [ + ("\(OWSFileSystem.appSharedDataDirectoryPath())/Logs/NotificationExtension", .notification), + ("\(OWSFileSystem.appSharedDataDirectoryPath())/Logs/ShareExtension", .share) + ] + let extensionLogs: [(path: String, type: ExtensionType)] = extensionInfo.flatMap { dir, type -> [(path: String, type: ExtensionType)] in + guard let files: [String] = try? FileManager.default.contentsOfDirectory(atPath: dir) else { return [] } + + return files.map { ("\(dir)/\($0)", type) } + } + + do { + guard let fileHandle: FileHandle = FileHandle(forWritingAtPath: currentLogFileInfo.filePath) else { + throw StorageError.objectNotFound + } + + // Ensure we close the file handle + defer { fileHandle.closeFile() } + + // Move to the end of the file to insert the logs + if #available(iOS 13.4, *) { try fileHandle.seekToEnd() } + else { fileHandle.seekToEndOfFile() } + + try extensionLogs + .grouped(by: \.type) + .forEach { type, value in + guard !value.isEmpty else { return } // Ignore if there are no logs + guard + let typeNameStartData: Data = "🧩 \(type.name) -- Start\n".data(using: .utf8), + let typeNameEndData: Data = "🧩 \(type.name) -- End\n".data(using: .utf8) + else { throw StorageError.invalidData } + + var hasWrittenStartLog: Bool = false + + // Write the logs + try value.forEach { path, _ in + let logData: Data = try Data(contentsOf: URL(fileURLWithPath: path)) + + guard !logData.isEmpty else { return } // Ignore empty files + + // Write the type start separator if needed + if !hasWrittenStartLog { + if #available(iOS 13.4, *) { try fileHandle.write(contentsOf: typeNameStartData) } + else { fileHandle.write(typeNameStartData) } + hasWrittenStartLog = true + } + + // Write the log data to the log file + if #available(iOS 13.4, *) { try fileHandle.write(contentsOf: logData) } + else { fileHandle.write(logData) } + + // Extension logs have been writen to the app logs, remove them now + try? FileManager.default.removeItem(atPath: path) + } + + // Write the type end separator if needed + if hasWrittenStartLog { + if #available(iOS 13.4, *) { try fileHandle.write(contentsOf: typeNameEndData) } + else { fileHandle.write(typeNameEndData) } + } + } + } + catch { + self?.completeStartup(error: "Unable to write extension logs to current log file") + return + } + + self?.completeStartup() + } + } + } + + private func completeStartup(error: String? = nil) { + let pendingLogs: [Log.LogInfo] = startupCompleted.mutate { startupCompleted in + startupCompleted = true + return (retrievePendingStartupLogs?() ?? []) + } + + // After creating a new logger we want to log two empty lines to make it easier to read + OWSLogger.info("") + OWSLogger.info("") + + // Add any logs that were pending during the startup process + pendingLogs.forEach { level, message, withPrefixes, silenceForTests in + log(level, message, withPrefixes: withPrefixes, silenceForTests: silenceForTests) + } + } + + fileprivate func log( + _ level: Log.Level, + _ message: String, + withPrefixes: Bool, + silenceForTests: Bool + ) { + guard !silenceForTests || !isRunningTests else { return } + + // Sort out the prefixes + let logPrefix: String = { + guard withPrefixes else { return "" } + + let prefixes: String = [ + primaryPrefix, + (Thread.isMainThread ? "Main" : nil), + (DispatchQueue.isDBWriteQueue ? "DBWrite" : nil) + ] + .compactMap { $0 } + .joined(separator: ", ") + + return "[\(prefixes)] " + }() + + // Clean up the message if needed (replace double periods with single, trim whitespace) + let logMessage: String = logPrefix + .appending(message) + .replacingOccurrences(of: "...", with: "|||") + .replacingOccurrences(of: "..", with: ".") + .replacingOccurrences(of: "|||", with: "...") + .trimmingCharacters(in: .whitespacesAndNewlines) + + switch level { + case .off: return + case .trace: OWSLogger.verbose(logMessage) + case .debug: OWSLogger.debug(logMessage) + case .info: OWSLogger.info(logMessage) + case .warn: OWSLogger.warn(logMessage) + case .error, .critical: OWSLogger.error(logMessage) + + } + + #if DEBUG + print(logMessage) + #endif + + if forceNSLog { + NSLog(message) + } + } +} + +// MARK: - Convenience + +private enum ExtensionType { + case share + case notification + + var name: String { + switch self { + case .share: return "ShareExtension" + case .notification: return "NotificationExtension" + } + } +} + private extension DispatchQueue { static var isDBWriteQueue: Bool { /// The `dispatch_queue_get_label` function is used to get the label for a given DispatchQueue, in Swift this @@ -22,27 +335,7 @@ private extension DispatchQueue { } } +// FIXME: Remove this once everything has been updated to use the new `Log.x()` methods public func SNLog(_ message: String, forceNSLog: Bool = false) { - let logPrefixes: String = [ - "Session", - (Thread.isMainThread ? "Main" : nil), - (DispatchQueue.isDBWriteQueue ? "DBWrite" : nil) - ] - .compactMap { $0 } - .joined(separator: ", ") - - #if DEBUG - print("[\(logPrefixes)] \(message)") - #endif - OWSLogger.info("[\(logPrefixes)] \(message)") - - if forceNSLog { - NSLog(message) - } -} - -public func SNLogNotTests(_ message: String) { - guard ProcessInfo.processInfo.environment["XCTestConfigurationFilePath"] == nil else { return } - - SNLog(message) + Log.info(message) } diff --git a/SessionUtilitiesKit/JobRunner/JobRunner.swift b/SessionUtilitiesKit/JobRunner/JobRunner.swift index 2adb7abe6..de04c1da0 100644 --- a/SessionUtilitiesKit/JobRunner/JobRunner.swift +++ b/SessionUtilitiesKit/JobRunner/JobRunner.swift @@ -1300,7 +1300,7 @@ public final class JobQueue: Hashable { // Run the first job in the pendingJobsQueue if !wasAlreadyRunning { - SNLogNotTests("[JobRunner] Starting \(queueContext) with (\(jobCount) job\(jobCount != 1 ? "s" : ""))") + Log.info("[JobRunner] Starting \(queueContext) with (\(jobCount) job\(jobCount != 1 ? "s" : ""))", silenceForTests: true) } runNextJob(using: dependencies) } diff --git a/SessionUtilitiesKit/LibSession/LibSession.swift b/SessionUtilitiesKit/LibSession/LibSession.swift index b692d8957..49d868355 100644 --- a/SessionUtilitiesKit/LibSession/LibSession.swift +++ b/SessionUtilitiesKit/LibSession/LibSession.swift @@ -25,28 +25,21 @@ extension LibSession { /// Then set any explicit category log levels we have logLevels.forEach { cat, level in - session_logger_set_level(cat.rawValue.cArray, level) + guard let cCat: [CChar] = cat.rawValue.cString(using: .utf8) else { return } + + session_logger_set_level(cCat, level) } /// Finally register the actual logger callback session_add_logger_full({ msgPtr, msgLen, _, _, lvl in guard let msg: String = String(pointer: msgPtr, length: msgLen, encoding: .utf8) else { return } - let trimmedLog: String = msg.trimmingCharacters(in: .whitespacesAndNewlines) - switch lvl { - case LOG_LEVEL_TRACE: OWSLogger.verbose(trimmedLog) - case LOG_LEVEL_DEBUG: OWSLogger.debug(trimmedLog) - case LOG_LEVEL_INFO: OWSLogger.info(trimmedLog) - case LOG_LEVEL_WARN: OWSLogger.warn(trimmedLog) - case LOG_LEVEL_ERROR: OWSLogger.error(trimmedLog) - case LOG_LEVEL_CRITICAL: OWSLogger.error(trimmedLog) - case LOG_LEVEL_OFF: break - default: break - } - - #if DEBUG - print(trimmedLog) - #endif + Log.custom( + Log.Level(lvl), + msg.trimmingCharacters(in: .whitespacesAndNewlines), + withPrefixes: false, + silenceForTests: false + ) }) } @@ -66,3 +59,19 @@ extension LibSession { } } } + +// MARK: - Convenience + +fileprivate extension Log.Level { + init(_ level: LOG_LEVEL) { + switch level { + case LOG_LEVEL_TRACE: self = .trace + case LOG_LEVEL_DEBUG: self = .debug + case LOG_LEVEL_INFO: self = .info + case LOG_LEVEL_WARN: self = .warn + case LOG_LEVEL_ERROR: self = .error + case LOG_LEVEL_CRITICAL: self = .critical + default: self = .off + } + } +} diff --git a/SessionUtilitiesKit/LibSession/Utilities/TypeConversion+Utilities.swift b/SessionUtilitiesKit/LibSession/Utilities/TypeConversion+Utilities.swift index 576aaf9f8..f3a5baab8 100644 --- a/SessionUtilitiesKit/LibSession/Utilities/TypeConversion+Utilities.swift +++ b/SessionUtilitiesKit/LibSession/Utilities/TypeConversion+Utilities.swift @@ -5,9 +5,7 @@ import SessionUtil // MARK: - String -public extension String { - var cArray: [CChar] { [UInt8](self.utf8).map { CChar(bitPattern: $0) } } - +public extension String { /// Initialize with an optional pointer and a specific length init?(pointer: UnsafeRawPointer?, length: Int, encoding: String.Encoding = .utf8) { guard @@ -89,8 +87,6 @@ public extension Optional { // MARK: - Data public extension Data { - var cArray: [UInt8] { [UInt8](self) } - init(libSessionVal: T, count: Int) { let result: Data = Swift.withUnsafePointer(to: libSessionVal) { Data(bytes: $0, count: count)