Fixed a couple of onboarding bugs and tweaks some logs

Session/Calls/Views & Modals/IncomingCallBanner.swift

@@ -114,7 +114,7 @@ final class IncomingCallBanner: UIView, UIGestureRecognizerDelegate {
             publicKey: call.sessionId,
             threadVariant: .contact,
             customImageData: nil,
-            profile: Storage.shared.read { db in Profile.fetchOrCreate(db, id: call.sessionId) },
+            profile: Storage.shared.read { [sessionId = call.sessionId] db in Profile.fetchOrCreate(db, id: sessionId) },
             additionalProfile: nil
         )
         displayNameLabel.text = call.contactName

Session/Meta/AppDelegate.swift

@@ -324,7 +324,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, readying remaining processes")
+            SNLog("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

Session/Onboarding/LinkDeviceVC.swift

@@ -130,10 +130,6 @@ final class LinkDeviceVC: BaseVC, UIPageViewControllerDataSource, UIPageViewCont
 
     // MARK: - Interaction
 
-    @objc private func close() {
-        dismiss(animated: true, completion: nil)
-    }
-
     func controller(_ controller: QRCodeScanningViewController, didDetectQRCodeWith string: String, onError: (() -> ())?) {
         let seed = Data(hex: string)
         continueWithSeed(seed, onError: onError)

Session/Onboarding/Onboarding.swift

@@ -121,7 +121,7 @@ enum Onboarding {
             .eraseToAnyPublisher()
     }
 
-    enum State {
+    enum State: CustomStringConvertible {
         case newUser
         case missingName
         case completed
@@ -138,14 +138,22 @@ enum Onboarding {
             // Otherwise we have enough for a full user and can start the app
             return .completed
         }
+
+        var description: String {
+            switch self {
+                case .newUser: return "New User"            // stringlint:disable
+                case .missingName: return "Missing Name"    // stringlint:disable
+                case .completed: return "Completed"         // stringlint:disable
+            }
+        }
     }
 
     enum Flow {
         case register, recover, link
 
         /// If the user returns to an earlier screen during Onboarding we might need to clear out a partially created
         /// account (eg. returning from the PN setting screen to the seed entry screen when linking a device)
-        func unregister() {
+        func unregister(using dependencies: Dependencies = Dependencies()) {
             // Clear the in-memory state from SessionUtil
             SessionUtil.clearMemoryState()
 
@@ -165,6 +173,9 @@ enum Onboarding {
             profileNameRetrievalIdentifier.mutate { $0 = nil }
             profileNameRetrievalPublisher.mutate { $0 = nil }
 
+            // Clear the cached 'encodedPublicKey' if needed
+            dependencies.caches.mutate(cache: .general) { $0.encodedPublicKey = nil }
+
             UserDefaults.standard[.hasSyncedInitialConfiguration] = false
         }
 

Session/Onboarding/SeedVC.swift

@@ -8,6 +8,8 @@ import SignalUtilitiesKit
 final class SeedVC: BaseVC {
     public static func mnemonic() throws -> String {
         let dbIsValid: Bool = Storage.shared.isValid
+        let dbHasRead: Bool = Storage.shared.hasSuccessfullyRead
+        let dbHasWritten: Bool = Storage.shared.hasSuccessfullyWritten
         let dbIsSuspendedUnsafe: Bool = Storage.shared.isSuspendedUnsafe
 
         if let hexEncodedSeed: String = Identity.fetchHexEncodedSeed() {
@@ -19,6 +21,8 @@ final class SeedVC: BaseVC {
             let hasStoredEdKeyPair: Bool = (Identity.fetchUserEd25519KeyPair() != nil)
             let dbStates: [String] = [
                 "dbIsValid: \(dbIsValid)",                      // stringlint:disable
+                "dbHasRead: \(dbHasRead)",                      // stringlint:disable
+                "dbHasWritten: \(dbHasWritten)",                // stringlint:disable
                 "dbIsSuspendedUnsafe: \(dbIsSuspendedUnsafe)",  // stringlint:disable
                 "storedSeed: false",                            // stringlint:disable
                 "userPublicKey: \(hasStoredPublicKey)",         // stringlint:disable

SessionMessagingKit/SessionUtil/Config Handling/SessionUtil+Shared.swift

@@ -77,7 +77,7 @@ internal extension SessionUtil {
                 }
         }
         catch {
-            SNLog("[libSession] Failed to update/dump updated \(variant) config data due to error: \(error)")
+            SNLog("[SessionUtil] Failed to update/dump updated \(variant) config data due to error: \(error)")
             throw error
         }
 
@@ -368,7 +368,7 @@ internal extension SessionUtil {
         loopCounter += 1
 
         guard loopCounter < maxLoopCount else {
-            SNLog("[libSession] Got stuck in infinite loop processing '\(variant.configMessageKind.description)' data")
+            SNLog("[SessionUtil] Got stuck in infinite loop processing '\(variant.configMessageKind.description)' data")
             throw SessionUtilError.processingLoopLimitReached
         }
     }

SessionMessagingKit/SessionUtil/SessionUtil.swift

@@ -45,7 +45,7 @@ public enum SessionUtil {
     // MARK: - Variables
 
     internal static func syncDedupeId(_ publicKey: String) -> String {
-        return "EnqueueConfigurationSyncJob-\(publicKey)"
+        return "EnqueueConfigurationSyncJob-\(publicKey)"   // stringlint:disable
     }
 
     /// Returns `true` if there is a config which needs to be pushed, but returns `false` if the configs are all up to date or haven't been
@@ -63,7 +63,7 @@ public enum SessionUtil {
     public static var libSessionVersion: String { String(cString: LIBSESSION_UTIL_VERSION_STR) }
 
     internal static func lastError(_ conf: UnsafeMutablePointer<config_object>?) -> String {
-        return (conf?.pointee.last_error.map { String(cString: $0) } ?? "Unknown")
+        return (conf?.pointee.last_error.map { String(cString: $0) } ?? "Unknown")  // stringlint:disable
     }
 
     // MARK: - Loading
@@ -84,7 +84,7 @@ public enum SessionUtil {
         guard
             let secretKey: [UInt8] = ed25519SecretKey,
             SessionUtil.configStore.wrappedValue.isEmpty
-        else { return }
+        else { return SNLog("[SessionUtil] Ignoring loadState for '\(userPublicKey)' due to existing state") }
 
         // If we weren't given a database instance then get one
         guard let db: Database = db else {
@@ -125,6 +125,8 @@ public enum SessionUtil {
                 )
             }
         }
+
+        SNLog("[SessionUtil] Completed loadState for '\(userPublicKey)'")
     }
 
     private static func loadState(
@@ -169,7 +171,7 @@ public enum SessionUtil {
         }()
 
         guard result == 0 else {
-            let errorString: String = (error.map { String(cString: $0) } ?? "unknown error")
+            let errorString: String = (error.map { String(cString: $0) } ?? "unknown error")    // stringlint:disable
             SNLog("[SessionUtil Error] Unable to create \(variant.rawValue) config object: \(errorString)")
             throw SessionUtilError.unableToCreateConfigObject
         }
@@ -241,7 +243,7 @@ public enum SessionUtil {
 
                         var cPushData: UnsafeMutablePointer<config_push_data>!
                         let configCountInfo: String = {
-                            var result: String = "Invalid"
+                            var result: String = "Invalid"  // stringlint:disable
 
                             try? CExceptionHelper.performSafely {
                                 switch variant {
@@ -261,7 +263,7 @@ public enum SessionUtil {
                             }
                         }
                         catch {
-                            SNLog("[libSession] Failed to generate push data for \(variant) config data, size: \(configCountInfo), error: \(error)")
+                            SNLog("[SessionUtil] Failed to generate push data for \(variant) config data, size: \(configCountInfo), error: \(error)")
                             throw error
                         }
 
@@ -418,7 +420,7 @@ public enum SessionUtil {
                             }
                         }
                         catch {
-                            SNLog("[libSession] Failed to process merge of \(next.key) config data")
+                            SNLog("[SessionUtil] Failed to process merge of \(next.key) config data")
                             throw error
                         }
 

SessionUtilitiesKit/Crypto/Mnemonic.swift

@@ -118,7 +118,7 @@ public enum Mnemonic {
     }
 
     public static func decode(mnemonic: String, language: Language = .english) throws -> String {
-        var words: [String] = mnemonic.split(separator: " ").map { String($0) }
+        var words: [String] = mnemonic.components(separatedBy: .whitespacesAndNewlines)
         let truncatedWordSet: [String] = language.loadTruncatedWordSet()
         let prefixLength: Int = language.prefixLength
         var result = ""

SessionUtilitiesKit/Database/Storage.swift

@@ -41,6 +41,12 @@ open class Storage {
     /// this should be taken into consideration when used
     public private(set) var isSuspendedUnsafe: Bool = false
 
+    /// This property gets set the first time we successfully read from the database
+    public private(set) var hasSuccessfullyRead: Bool = false
+
+    /// This property gets set the first time we successfully write to the database
+    public private(set) var hasSuccessfullyWritten: Bool = false
+
     public var hasCompletedMigrations: Bool { migrationsCompleted.wrappedValue }
     public var currentlyRunningMigration: (identifier: TargetMigrations.Identifier, migration: Migration.Type)? {
         internalCurrentlyRunningMigration.wrappedValue
@@ -456,37 +462,60 @@ open class Storage {
 
     // MARK: - Logging Functions
 
-    typealias CallInfo = (file: String, function: String, line: Int)
-
-    private static func logSlowWrites<T>(
+    private enum Action {
+        case read
+        case write
+        case logIfSlow
+    }
+
+    private typealias CallInfo = (storage: Storage?, actions: [Action], file: String, function: String, line: Int)
+
+    private static func perform<T>(
         info: CallInfo,
         updates: @escaping (Database) throws -> T
     ) -> (Database) throws -> T {
         return { db in
             let start: CFTimeInterval = CACurrentMediaTime()
+            let actionName: String = (info.actions.contains(.write) ? "write" : "read")
             let fileName: String = (info.file.components(separatedBy: "/").last.map { " \($0):\(info.line)" } ?? "")
-            let timeout: Timer = Timer.scheduledTimerOnMainThread(withTimeInterval: writeWarningThreadshold) {
-                $0.invalidate()
+            let timeout: Timer? = {
+                guard info.actions.contains(.logIfSlow) else { return nil }
 
-                // Don't want to log on the main thread as to avoid confusion when debugging issues
-                DispatchQueue.global(qos: .default).async {
-                    SNLog("[Storage\(fileName)] Slow write taking longer than \(writeWarningThreadshold, format: ".2", omitZeroDecimal: true)s - \(info.function)")
+                return Timer.scheduledTimerOnMainThread(withTimeInterval: Storage.writeWarningThreadshold) {
+                    $0.invalidate()
+
+                    // Don't want to log on the main thread as to avoid confusion when debugging issues
+                    DispatchQueue.global(qos: .default).async {
+                        SNLog("[Storage\(fileName)] Slow \(actionName) taking longer than \(Storage.writeWarningThreadshold, format: ".2", omitZeroDecimal: true)s - \(info.function)")
+                    }
                 }
-            }
+            }()
+
+            // If we timed out and are logging slow actions then log the actual duration to help us
+            // prioritise performance issues
             defer {
-                // If we timed out then log the actual duration to help us prioritise performance issues
-                if !timeout.isValid {
+                if timeout != nil && timeout?.isValid == false {
                     let end: CFTimeInterval = CACurrentMediaTime()
 
                     DispatchQueue.global(qos: .default).async {
-                        SNLog("[Storage\(fileName)] Slow write completed after \(end - start, format: ".2", omitZeroDecimal: true)s")
+                        SNLog("[Storage\(fileName)] Slow \(actionName) completed after \(end - start, format: ".2", omitZeroDecimal: true)s")
                     }
                 }
 
-                timeout.invalidate()
+                timeout?.invalidate()
             }
 
-            return try updates(db)
+            // Get the result
+            let result: T = try updates(db)
+
+            // Update the state flags
+            switch info.actions {
+                case [.write], [.write, .logIfSlow]: info.storage?.hasSuccessfullyWritten = true
+                case [.read], [.read, .logIfSlow]: info.storage?.hasSuccessfullyRead = true
+                default: break
+            }
+
+            return result
         }
     }
 
@@ -516,9 +545,8 @@ open class Storage {
     ) -> T? {
         guard isValid, let dbWriter: DatabaseWriter = dbWriter else { return nil }
 
-        let info: CallInfo = (fileName, functionName, lineNumber)
-
-        do { return try dbWriter.write(Storage.logSlowWrites(info: info, updates: updates)) }
+        let info: CallInfo = { [weak self] in (self, [.write, .logIfSlow], fileName, functionName, lineNumber) }()
+        do { return try dbWriter.write(Storage.perform(info: info, updates: updates)) }
         catch { return Storage.logIfNeeded(error, isWrite: true) }
     }
 
@@ -549,10 +577,10 @@ open class Storage {
     ) {
         guard isValid, let dbWriter: DatabaseWriter = dbWriter else { return }
 
-        let info: CallInfo = (fileName, functionName, lineNumber)
+        let info: CallInfo = { [weak self] in (self, [.write, .logIfSlow], fileName, functionName, lineNumber) }()
 
         dbWriter.asyncWrite(
-            Storage.logSlowWrites(info: info, updates: updates),
+            Storage.perform(info: info, updates: updates),
             completion: { db, result in
                 switch result {
                     case .failure(let error): Storage.logIfNeeded(error, isWrite: true)
@@ -576,7 +604,7 @@ open class Storage {
                 .eraseToAnyPublisher()
         }
 
-        let info: CallInfo = (fileName, functionName, lineNumber)
+        let info: CallInfo = { [weak self] in (self, [.write, .logIfSlow], fileName, functionName, lineNumber) }()
 
         /// **Note:** GRDB does have a `writePublisher` method but it appears to asynchronously trigger
         /// both the `output` and `complete` closures at the same time which causes a lot of unexpected
@@ -587,7 +615,7 @@ open class Storage {
         /// which behaves in a much more expected way than the GRDB `writePublisher` does
         return Deferred {
             Future { resolver in
-                do { resolver(Result.success(try dbWriter.write(Storage.logSlowWrites(info: info, updates: updates)))) }
+                do { resolver(Result.success(try dbWriter.write(Storage.perform(info: info, updates: updates)))) }
                 catch {
                     Storage.logIfNeeded(error, isWrite: true)
                     resolver(Result.failure(error))
@@ -597,6 +625,9 @@ open class Storage {
     }
 
     open func readPublisher<T>(
+        fileName: String = #file,
+        functionName: String = #function,
+        lineNumber: Int = #line,
         using dependencies: Dependencies = Dependencies(),
         value: @escaping (Database) throws -> T
     ) -> AnyPublisher<T, Error> {
@@ -605,6 +636,8 @@ open class Storage {
                 .eraseToAnyPublisher()
         }
 
+        let info: CallInfo = { [weak self] in (self, [.read], fileName, functionName, lineNumber) }()
+
         /// **Note:** GRDB does have a `readPublisher` method but it appears to asynchronously trigger
         /// both the `output` and `complete` closures at the same time which causes a lot of unexpected
         /// behaviours (this behaviour is apparently expected but still causes a number of odd behaviours in our code
@@ -614,7 +647,7 @@ open class Storage {
         /// which behaves in a much more expected way than the GRDB `readPublisher` does
         return Deferred {
             Future { resolver in
-                do { resolver(Result.success(try dbWriter.read(value))) }
+                do { resolver(Result.success(try dbWriter.read(Storage.perform(info: info, updates: value)))) }
                 catch {
                     Storage.logIfNeeded(error, isWrite: false)
                     resolver(Result.failure(error))
@@ -624,12 +657,16 @@ open class Storage {
     }
 
     @discardableResult public func read<T>(
+        fileName: String = #file,
+        functionName: String = #function,
+        lineNumber: Int = #line,
         using dependencies: Dependencies = Dependencies(),
-        _ value: (Database) throws -> T?
+        _ value: @escaping (Database) throws -> T?
     ) -> T? {
         guard isValid, let dbWriter: DatabaseWriter = dbWriter else { return nil }
 
-        do { return try dbWriter.read(value) }
+        let info: CallInfo = { [weak self] in (self, [.read], fileName, functionName, lineNumber) }()
+        do { return try dbWriter.read(Storage.perform(info: info, updates: value)) }
         catch { return Storage.logIfNeeded(error, isWrite: false) }
     }
 

SessionUtilitiesKit/Database/Types/PagedDatabaseObserver.swift

@@ -131,6 +131,7 @@ public class PagedDatabaseObserver<ObservedTable, T>: TransactionObserver where
 
             // Retrieve the pagedRowId for the related value that is
             // getting deleted
+            let pagedTableName: String = self.pagedTableName
             let pagedRowIds: [Int64] = Storage.shared
                 .read { db in
                     PagedData.pagedRowIdsForRelatedRowIds(
@@ -183,10 +184,13 @@ public class PagedDatabaseObserver<ObservedTable, T>: TransactionObserver where
         // Store the instance variables locally to avoid unwrapping
         let dataCache: DataCache<T> = self.dataCache.wrappedValue
         let pageInfo: PagedData.PageInfo = self.pageInfo.wrappedValue
+        let pagedTableName: String = self.pagedTableName
         let joinSQL: SQL? = self.joinSQL
         let orderSQL: SQL = self.orderSQL
         let filterSQL: SQL = self.filterSQL
+        let dataQuery: ([Int64]) -> any FetchRequest<T> = self.dataQuery
         let associatedRecords: [ErasedAssociatedRecord] = self.associatedRecords
+        let observedTableChangeTypes: [String: PagedData.ObservedChanges] = self.observedTableChangeTypes
         let getAssociatedDataInfo: (Database, PagedData.PageInfo) -> AssociatedDataInfo = { db, updatedPageInfo in
             associatedRecords.map { associatedRecord in
                 let hasChanges: Bool = associatedRecord.tryUpdateForDatabaseCommit(