From 355ef49194ea954dca0c81a6d24a0879c65e64c9 Mon Sep 17 00:00:00 2001 From: Joshua Blum Date: Wed, 1 Apr 2026 12:21:50 -0400 Subject: [PATCH] Move startup log writes off the main thread --- shared/ios/Keybase/AppDelegate.swift | 79 +++++++++++++++------------- 1 file changed, 42 insertions(+), 37 deletions(-) diff --git a/shared/ios/Keybase/AppDelegate.swift b/shared/ios/Keybase/AppDelegate.swift index 175e89494a95..5bdf4a3075be 100644 --- a/shared/ios/Keybase/AppDelegate.swift +++ b/shared/ios/Keybase/AppDelegate.swift @@ -48,7 +48,8 @@ public class AppDelegate: ExpoAppDelegate, UNUserNotificationCenterDelegate, var fsPaths: [String: String] = [:] var shutdownTask: UIBackgroundTaskIdentifier = .invalid var iph: ItemProviderHelper? - var startupLogFileHandle: FileHandle? + private var startupLogFileHandle: FileHandle? + private let logQueue = DispatchQueue(label: "kb.startup.log", qos: .utility) private var watchdog: MainThreadWatchdog? private var bgEnterWallTime: CFAbsoluteTime = 0 @@ -154,6 +155,7 @@ public class AppDelegate: ExpoAppDelegate, UNUserNotificationCenterDelegate, /////// KB specific private static var appStartTime: CFAbsoluteTime = 0 + private static let initLog = OSLog(subsystem: "keybase", category: "init") private static let logDateFormatter: DateFormatter = { let f = DateFormatter() @@ -167,59 +169,62 @@ public class AppDelegate: ExpoAppDelegate, UNUserNotificationCenterDelegate, return } - if self.startupLogFileHandle == nil { - if !FileManager.default.fileExists(atPath: logFilePath) { - // Match the parent directory's protection class so the file remains accessible - // in the background after the device has been unlocked once. - FileManager.default.createFile( - atPath: logFilePath, contents: nil, - attributes: [.protectionKey: FileProtectionType.completeUntilFirstUserAuthentication]) - } - if let fileHandle = FileHandle(forWritingAtPath: logFilePath) { - fileHandle.seekToEndOfFile() - self.startupLogFileHandle = fileHandle - } else { - NSLog("Error opening startup timing log file: \(logFilePath)") - return - } - } - - guard let fileHandle = self.startupLogFileHandle else { - return - } - + // Capture timestamp on the calling thread so it reflects when the event actually occurred. let now = Date() let timeInterval = now.timeIntervalSince1970 let microseconds = Int(timeInterval.truncatingRemainder(dividingBy: 1) * 1_000_000) let dateString = AppDelegate.logDateFormatter.string(from: now) let timestamp = String(format: "%@.%06dZ", dateString, microseconds) - let fileName = URL(fileURLWithPath: file).lastPathComponent let logMessage = String( format: "%@ ▶ [DEBU keybase %@:%d] Delegate startup: %@\n", timestamp, fileName, line, message ) - guard let logData = logMessage.data(using: .utf8) else { return } - do { - try fileHandle.write(contentsOf: logData) - try fileHandle.synchronize() - } catch { - NSLog("Error writing startup timing log: \(error)") + // Dispatch file I/O (including fsync) to a background queue so the calling thread + // (often the main thread) is never blocked by disk latency. + logQueue.async { [weak self] in + guard let self else { return } + if self.startupLogFileHandle == nil { + if !FileManager.default.fileExists(atPath: logFilePath) { + // Match the parent directory's protection class so the file remains accessible + // in the background after the device has been unlocked once. + FileManager.default.createFile( + atPath: logFilePath, contents: nil, + attributes: [.protectionKey: FileProtectionType.completeUntilFirstUserAuthentication]) + } + if let fileHandle = FileHandle(forWritingAtPath: logFilePath) { + fileHandle.seekToEndOfFile() + self.startupLogFileHandle = fileHandle + } else { + NSLog("Error opening startup timing log file: \(logFilePath)") + return + } + } + guard let fileHandle = self.startupLogFileHandle else { return } + do { + try fileHandle.write(contentsOf: logData) + try fileHandle.synchronize() + } catch { + NSLog("Error writing startup timing log: \(error)") + } } } private func closeStartupLogFile() { - if let fileHandle = self.startupLogFileHandle { - do { - try fileHandle.synchronize() - try fileHandle.close() - } catch { - NSLog("Error closing startup timing log: \(error)") + // Use sync so all pending async log writes are flushed before we close the handle. + logQueue.sync { + if let fileHandle = self.startupLogFileHandle { + do { + try fileHandle.synchronize() + try fileHandle.close() + } catch { + NSLog("Error closing startup timing log: \(error)") + } + self.startupLogFileHandle = nil } - self.startupLogFileHandle = nil } } @@ -251,7 +256,7 @@ public class AppDelegate: ExpoAppDelegate, UNUserNotificationCenterDelegate, if let err { // Log to system log with public annotation so it's not redacted in logarchive. os_log( - .error, log: OSLog(subsystem: "keybase", category: "init"), + .error, log: AppDelegate.initLog, "KeybaseInit FAILED: %{public}@ (code=%ld domain=%{public}@)", err.localizedDescription, err.code, err.domain) // Also write to ios.log so it's captured in xcappdata even without a device attached.