Fixed an issue where return from background could hang

Stopped trying to run migrations if there aren't any to run (remove unneeded DBWrite thread use)
Shifted return from background migration running to a background thread to prevent hanging
Updated the slow write log to also output once the write completes
This commit is contained in:
Morgan Pretty 2023-07-07 14:55:03 +10:00
parent 6f4bdcdccb
commit 0f52d358d4
3 changed files with 70 additions and 35 deletions

View File

@ -143,6 +143,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")
let initialLaunchFailed: Bool = self.initialLaunchFailed
AppReadiness.invalidate()
@ -154,30 +155,33 @@ class AppDelegate: UIResponder, UIApplicationDelegate, UNUserNotificationCenterD
self.window?.rootViewController?.dismiss(animated: false)
}
AppSetup.runPostSetupMigrations(
migrationProgressChanged: { [weak self] progress, minEstimatedTotalTime in
self?.loadingViewController?.updateProgress(
progress: progress,
minEstimatedTotalTime: minEstimatedTotalTime
)
},
migrationsCompletion: { [weak self] result, needsConfigSync in
if case .failure(let error) = result {
DispatchQueue.main.async {
self?.showFailedStartupAlert(
calledFrom: .enterForeground(initialLaunchFailed: initialLaunchFailed),
error: .databaseError(error)
)
// Dispatch async so things can continue to be progressed if a migration does need to run
DispatchQueue.global(qos: .userInitiated).async { [weak self] in
AppSetup.runPostSetupMigrations(
migrationProgressChanged: { progress, minEstimatedTotalTime in
self?.loadingViewController?.updateProgress(
progress: progress,
minEstimatedTotalTime: minEstimatedTotalTime
)
},
migrationsCompletion: { result, needsConfigSync in
if case .failure(let error) = result {
DispatchQueue.main.async {
self?.showFailedStartupAlert(
calledFrom: .enterForeground(initialLaunchFailed: initialLaunchFailed),
error: .databaseError(error)
)
}
return
}
return
self?.completePostMigrationSetup(
calledFrom: .enterForeground(initialLaunchFailed: initialLaunchFailed),
needsConfigSync: needsConfigSync
)
}
self?.completePostMigrationSetup(
calledFrom: .enterForeground(initialLaunchFailed: initialLaunchFailed),
needsConfigSync: needsConfigSync
)
}
)
)
}
}
}
@ -322,8 +326,8 @@ 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")
self?.initialLaunchFailed = false
SNLog("Migrations completed, performing setup and ensuring rootViewController")
/// Trigger any launch-specific jobs and start the JobRunner with `JobRunner.appDidFinishLaunching()` some
/// of these jobs (eg. DisappearingMessages job) can impact the interactions which get fetched to display on the home

View File

@ -206,11 +206,6 @@ open class Storage {
}
})
// If we have an unperformed migration then trigger the progress updater immediately
if let firstMigrationKey: String = unperformedMigrations.first?.key {
self.migrationProgressUpdater?.wrappedValue(firstMigrationKey, 0)
}
// Store the logic to run when the migration completes
let migrationCompleted: (Swift.Result<Void, Error>) -> () = { [weak self] result in
self?.migrationsCompleted.mutate { $0 = true }
@ -230,10 +225,17 @@ open class Storage {
onComplete(result, needsConfigSync)
}
// Update the 'migrationsCompleted' state (since we not support running migrations when
// returning from the background it's possible for this flag to transition back to false)
if unperformedMigrations.isEmpty {
self.migrationsCompleted.mutate { $0 = false }
// if there aren't any migrations to run then just complete immediately (this way the migrator
// doesn't try to execute on the DBWrite thread so returning from the background can't get blocked
// due to some weird endless process running)
guard !unperformedMigrations.isEmpty else {
migrationCompleted(.success(()))
return
}
// If we have an unperformed migration then trigger the progress updater immediately
if let firstMigrationKey: String = unperformedMigrations.first?.key {
self.migrationProgressUpdater?.wrappedValue(firstMigrationKey, 0)
}
// Note: The non-async migration should only be used for unit tests
@ -377,16 +379,28 @@ open class Storage {
updates: @escaping (Database) throws -> T
) -> (Database) throws -> T {
return { db in
let start: CFTimeInterval = CACurrentMediaTime()
let fileName: String = (info.file.components(separatedBy: "/").last.map { " \($0):\(info.line)" } ?? "")
let timeout: Timer = Timer.scheduledTimerOnMainThread(withTimeInterval: writeWarningThreadshold) {
$0.invalidate()
// Don't want to log on the main thread as to avoid confusion when debugging issues
DispatchQueue.global(qos: .default).async {
let fileName: String = (info.file.components(separatedBy: "/").last.map { " \($0):\(info.line)" } ?? "")
SNLog("[Storage\(fileName)] Slow write taking longer than \(writeWarningThreadshold)s - \(info.function)")
SNLog("[Storage\(fileName)] Slow write taking longer than \(writeWarningThreadshold, format: ".2", omitZeroDecimal: true)s - \(info.function)")
}
}
defer { timeout.invalidate() }
defer {
// If we timed out then log the actual duration to help us prioritise performance issues
if !timeout.isValid {
let end: CFTimeInterval = CACurrentMediaTime()
DispatchQueue.global(qos: .default).async {
SNLog("[Storage\(fileName)] Slow write completed after \(end - start, format: ".2", omitZeroDecimal: true)s")
}
}
timeout.invalidate()
}
return try updates(db)
}

View File

@ -77,6 +77,23 @@ public extension String {
// MARK: - Formatting
extension String.StringInterpolation {
mutating func appendInterpolation(_ value: Int, format: String) {
let result: String = String(format: "%\(format)d", value)
appendLiteral(result)
}
mutating func appendInterpolation(_ value: Double, format: String, omitZeroDecimal: Bool = false) {
guard !omitZeroDecimal || Int(exactly: value) == nil else {
appendLiteral("\(Int(exactly: value)!)")
return
}
let result: String = String(format: "%\(format)f", value)
appendLiteral(result)
}
}
public extension String {
static func formattedDuration(_ duration: TimeInterval, format: TimeInterval.DurationFormat = .short) -> String {
let secondsPerMinute: TimeInterval = 60