oxen-io
/
session-ios
mirror of https://github.com/oxen-io/session-ios.git
1
0
Fork 0
Code Issues Projects Releases Wiki Activity

Fixed a couple of onboarding bugs and tweaks some logs 

Fixed an issue where starting and then restarting onboarding would get the app into an invalid state
Fixed an issue where newline characters could cause issues with parsing the recovery phrase
Added additional logs to better be able to understand the database state
This commit is contained in:
Morgan Pretty 2023-10-02 12:59:52 +11:00
parent 0c5f3f2db9
commit f9dc85b7ab
12 changed files with 98 additions and 52 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

2
Session/Calls/Views & Modals/IncomingCallBanner.swift
View File

@ -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

2
Session/Meta/AppDelegate.swift
View File

@ -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

4
Session/Onboarding/LinkDeviceVC.swift
View File

@ -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)

15
Session/Onboarding/Onboarding.swift
View File

@ -121,7 +121,7 @@ enum Onboarding {
.eraseToAnyPublisher()
}
enum State {
enum State: CustomStringConvertible {
case newUser
case missingName
case completed
@ -138,6 +138,14 @@ 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 {
@ -145,7 +153,7 @@ enum Onboarding {
/// 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
}

4
Session/Onboarding/SeedVC.swift
View File

@ -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

4
SessionMessagingKit/SessionUtil/Config Handling/SessionUtil+Shared.swift
View File

@ -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
}
}

16
SessionMessagingKit/SessionUtil/SessionUtil.swift
View File

@ -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
}

2
SessionUtilitiesKit/Crypto/Mnemonic.swift
View File

@ -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 = ""

85
SessionUtilitiesKit/Database/Storage.swift
View File

@ -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) }
}

4
SessionUtilitiesKit/Database/Types/PagedDatabaseObserver.swift
View File

@ -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(

2
SessionUtilitiesKit/JobRunner/JobRunner.swift
View File

@ -1096,6 +1096,7 @@ public final class JobQueue: Hashable {
hasStartedAtLeastOnce.mutate { $0 = true }
// Get any pending jobs
let jobVariants: [Job.Variant] = self.jobVariants
let jobIdsAlreadyRunning: Set<Int64> = currentlyRunningJobIds.wrappedValue
let jobsAlreadyInQueue: Set<Int64> = pendingJobsQueue.wrappedValue.compactMap { $0.id }.asSet()
let jobsToRun: [Job] = dependencies.storage.read(using: dependencies) { db in
@ -1320,6 +1321,7 @@ public final class JobQueue: Hashable {
}
private func scheduleNextSoonestJob(using dependencies: Dependencies) {
let jobVariants: [Job.Variant] = self.jobVariants
let jobIdsAlreadyRunning: Set<Int64> = currentlyRunningJobIds.wrappedValue
let nextJobTimestamp: TimeInterval? = dependencies.storage.read(using: dependencies) { db in
try Job

10
SignalUtilitiesKit/Utilities/AppSetup.swift
View File

@ -112,16 +112,6 @@ public enum AppSetup {
}
},
onComplete: { result, needsConfigSync in
// After the migrations have run but before the migration completion we load the
// SessionUtil state and update the 'needsConfigSync' flag based on whether the
// configs also need to be sync'ed
if Identity.userExists() {
SessionUtil.loadState(
userPublicKey: getUserHexEncodedPublicKey(),
ed25519SecretKey: Identity.fetchUserEd25519KeyPair()?.secretKey
)
}
// The 'needsConfigSync' flag should be based on whether either a migration or the
// configs need to be sync'ed
migrationsCompletion(result, (needsConfigSync || SessionUtil.needsSync))