Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
41 changes: 32 additions & 9 deletions desktop/macos/Desktop/Sources/AnalyticsManager.swift
Original file line number Diff line number Diff line change
@@ -1,4 +1,4 @@
import AppKit

Check warning on line 1 in desktop/macos/Desktop/Sources/AnalyticsManager.swift

View workflow job for this annotation

GitHub Actions / Hygiene

Large changed file

desktop/macos/Desktop/Sources/AnalyticsManager.swift is 1486 lines; consider splitting files over 800 lines.
import Foundation
import Sentry

Expand Down Expand Up @@ -559,23 +559,46 @@
PostHogManager.shared.appLaunched()
}

/// A process reports startup once. `ViewModelContainer.loadAllData()` runs
/// again after an owner switch, and that second run is not a launch.
private var didReportStartupTiming = false

/// Report one launch's startup timing.
///
/// - `dataLoadMs` is the critical startup path inside `loadAllData()`. This is
/// what the old `time_to_interactive_ms` actually measured, which is why it
/// reported 11–131ms for a "cold start".
/// - `timeToInteractiveMs` is measured from the kernel's process-start stamp,
/// so it includes dyld, `main`, and everything before the data load. It is
/// omitted rather than faked when the kernel lookup fails.
func trackStartupTiming(
dbInitMs: Double, timeToInteractiveMs: Double, hadUncleanShutdown: Bool,
databaseInitFailed: Bool
dbInitMs: Double, dataLoadMs: Double, hadUncleanShutdown: Bool,
databaseInitFailed: Bool,
timeToInteractiveMs: Double? = AppStartupTiming.millisecondsSinceProcessStart()
) {
guard !Self.isDevBuild else { return }
// Routed to Sentry as a breadcrumb (perf telemetry, not product analytics) so the data
// is attached to any same-session crash report without creating a per-launch analytics
// event. If we ever need real perf metrics, wire up SentrySDK.startTransaction here.
let breadcrumb = Breadcrumb(level: .info, category: "app.startup")
breadcrumb.message = "App Startup Timing"
breadcrumb.data = [
guard !didReportStartupTiming else { return }
didReportStartupTiming = true

var properties: [String: Any] = [
"db_init_ms": round(dbInitMs),
"time_to_interactive_ms": round(timeToInteractiveMs),
"data_load_ms": round(dataLoadMs),
"had_unclean_shutdown": hadUncleanShutdown,
"database_init_failed": databaseInitFailed,
]
if let timeToInteractiveMs {
properties["time_to_interactive_ms"] = round(timeToInteractiveMs)
}

// Also a Sentry breadcrumb so the numbers stay attached to a same-session
// crash report. Sentry is a per-issue view; it cannot answer "is startup
// getting slower across the fleet", which is why this is in PostHog too.
let breadcrumb = Breadcrumb(level: .info, category: "app.startup")
breadcrumb.message = "App Startup Timing"
breadcrumb.data = properties
SentrySDK.addBreadcrumb(breadcrumb)

PostHogManager.shared.track("App Startup Timing", properties: properties)
}

/// Track first launch with comprehensive system diagnostics
Expand Down
46 changes: 46 additions & 0 deletions desktop/macos/Desktop/Sources/Observability/AppStartupTiming.swift
Original file line number Diff line number Diff line change
@@ -0,0 +1,46 @@
import Darwin
import Foundation

/// Wall-clock start of this process, read from the kernel process table.
///
/// `App Startup Timing` reported `time_to_interactive_ms` values of 11–131ms,
/// which is not a cold start of a SwiftUI app — it was the duration of
/// `ViewModelContainer.loadAllData()`, which begins long after `main()`. The
/// only honest source for "when did this process actually start" is
/// `kinfo_proc.kp_proc.p_starttime`, which the kernel stamps at exec, before
/// dyld, before `main`, and before any code of ours could take a timestamp.
enum AppStartupTiming {
/// Wall-clock start of `pid` as recorded by the kernel, or nil when the
/// sysctl is unavailable.
static func processStartDate(pid: pid_t = getpid()) -> Date? {
var mib: [Int32] = [CTL_KERN, KERN_PROC, KERN_PROC_PID, pid]
var info = kinfo_proc()
var size = MemoryLayout<kinfo_proc>.stride
let result = sysctl(&mib, UInt32(mib.count), &info, &size, nil, 0)
guard result == 0, size > 0 else { return nil }
let started = info.kp_proc.p_starttime
guard started.tv_sec > 0 else { return nil }
return Date(
timeIntervalSince1970: Double(started.tv_sec) + Double(started.tv_usec) / 1_000_000)
}

/// Milliseconds between two instants, floored at zero.
///
/// The process-start stamp and `Date()` both come from the wall clock, so a
/// clock adjustment between them can produce a negative or absurd interval.
/// A startup metric must never report a negative duration.
static func elapsedMilliseconds(from start: Date, to end: Date) -> Double {
max(0, end.timeIntervalSince(start) * 1_000)
}

/// Milliseconds from process start to `now`, or nil when the process start is
/// unavailable. Callers omit the property rather than substituting a
/// plausible-looking number.
static func millisecondsSinceProcessStart(
now: Date = Date(),
processStart: Date? = AppStartupTiming.processStartDate()
) -> Double? {
guard let processStart else { return nil }
return elapsedMilliseconds(from: processStart, to: now)
}
}
29 changes: 28 additions & 1 deletion desktop/macos/Desktop/Sources/Rewind/Core/RewindDatabase.swift
Original file line number Diff line number Diff line change
@@ -1,4 +1,4 @@
import Foundation

Check warning on line 1 in desktop/macos/Desktop/Sources/Rewind/Core/RewindDatabase.swift

View workflow job for this annotation

GitHub Actions / Hygiene

Large changed file

desktop/macos/Desktop/Sources/Rewind/Core/RewindDatabase.swift is 3508 lines; consider splitting files over 800 lines.
@preconcurrency import GRDB
import OmiSupport
import os
Expand All @@ -23,6 +23,14 @@
/// Path to the running flag file (used to detect unclean shutdown)
private var runningFlagPath: String?

/// Whether the *previous* session ended uncleanly, latched at the first
/// observation in this process. `.omi_running` is created at the end of
/// `performInitialization()`, so the answer stops being observable once the
/// database opens — and any of the lazily-initializing storage actors can get
/// there first. That race is why `App Startup Timing` reported
/// `had_unclean_shutdown = true` on ~every sample.
private var uncleanShutdownVerdict: Bool?

/// The user ID this database is configured for (nil = not yet configured → "anonymous")
private var configuredUserId: String?

Expand Down Expand Up @@ -332,6 +340,10 @@
initializationTask = nil
runningFlagPath = nil
openedForUserId = nil
// The database identity is being torn down, so the latched verdict no longer
// describes anything. The next performInitialization() makes a fresh
// authoritative observation for whichever user it opens.
uncleanShutdownVerdict = nil
initGeneration += 1
poolEpoch += 1
log("RewindDatabase: Closed database (generation \(initGeneration), pool epoch \(poolEpoch))")
Expand Down Expand Up @@ -383,9 +395,17 @@
}

/// Check if the previous session ended with an unclean shutdown (crash, force quit, etc.)
///
/// Order-independent: whoever observes first latches the verdict for the whole
/// process, and `performInitialization()` latches it before it writes this
/// session's own running flag. A later caller therefore reads the previous
/// session's state, not this one's.
func hadUncleanShutdown() -> Bool {
if let uncleanShutdownVerdict { return uncleanShutdownVerdict }
let flagPath = userBaseDirectory().appendingPathComponent(".omi_running").path
return FileManager.default.fileExists(atPath: flagPath)
let verdict = FileManager.default.fileExists(atPath: flagPath)
uncleanShutdownVerdict = verdict
return verdict
}

/// Initialize the database with migrations.
Expand Down Expand Up @@ -471,6 +491,13 @@
// Detect unclean shutdown: if the running flag file exists, the previous launch
// didn't exit cleanly (crash, force quit, power loss)
let previousCrashed = FileManager.default.fileExists(atPath: flagPath)
// This is the authoritative, user-scoped observation and it happens before
// this session's flag is written below. Latch it here so a startup-timing
// reader that arrives after the database opened still reports the previous
// session, whatever order the storage actors initialized in.
if uncleanShutdownVerdict == nil {
uncleanShutdownVerdict = previousCrashed
}
if previousCrashed {
log("RewindDatabase: Unclean shutdown detected (running flag exists)")
}
Expand Down Expand Up @@ -1145,7 +1172,7 @@

// MARK: - Migrations

private func migrate(_ queue: DatabasePool, legacyOwnerFallback: String? = nil) throws {

Check warning on line 1175 in desktop/macos/Desktop/Sources/Rewind/Core/RewindDatabase.swift

View workflow job for this annotation

GitHub Actions / Hygiene

Long function

private func migrate(_ queue: DatabasePool, legacyOwnerFallback: String? = nil) is 1444 lines; consider extracting focused helpers over 150 lines.
var migrator = DatabaseMigrator()

// Migration 1: Create screenshots table
Expand Down
9 changes: 6 additions & 3 deletions desktop/macos/Desktop/Sources/ViewModelContainer.swift
Original file line number Diff line number Diff line change
Expand Up @@ -90,15 +90,18 @@ class ViewModelContainer: ObservableObject {
// API calls and data fetches continue in the background
isInitialLoadComplete = true
loadedUserId = currentUserId
let timeToInteractive = CFAbsoluteTimeGetCurrent() - startupStart
// This is the critical startup path inside loadAllData, not time from
// process start. It is reported as `data_load_ms`; `time_to_interactive_ms`
// comes from the kernel's process-start stamp.
let dataLoadDuration = CFAbsoluteTimeGetCurrent() - startupStart

// Track startup timing
logPerf(
"DATA LOAD: DB init \(String(format: "%.1f", dbInitDuration * 1000))ms, time-to-interactive \(String(format: "%.1f", timeToInteractive * 1000))ms, uncleanShutdown=\(hadUncleanShutdown)"
"DATA LOAD: DB init \(String(format: "%.1f", dbInitDuration * 1000))ms, data load \(String(format: "%.1f", dataLoadDuration * 1000))ms, uncleanShutdown=\(hadUncleanShutdown)"
)
AnalyticsManager.shared.trackStartupTiming(
dbInitMs: dbInitDuration * 1000,
timeToInteractiveMs: timeToInteractive * 1000,
dataLoadMs: dataLoadDuration * 1000,
hadUncleanShutdown: hadUncleanShutdown,
databaseInitFailed: databaseInitFailed
)
Expand Down
58 changes: 58 additions & 0 deletions desktop/macos/Desktop/Tests/AppStartupTimingTests.swift
Original file line number Diff line number Diff line change
@@ -0,0 +1,58 @@
import XCTest

@testable import Omi_Computer

/// `App Startup Timing` reported `time_to_interactive_ms` of 11–131ms, which is
/// not a cold start of this app. It was the duration of
/// `ViewModelContainer.loadAllData()`, which begins long after `main()`. These
/// tests pin the replacement measurement.
final class AppStartupTimingTests: XCTestCase {
func testProcessStartIsReadFromTheKernelAndPrecedesNow() throws {
let start = try XCTUnwrap(
AppStartupTiming.processStartDate(),
"the kernel process table is the only source for a real process start")
XCTAssertLessThanOrEqual(start, Date(), "a process cannot start in the future")

let elapsed = try XCTUnwrap(AppStartupTiming.millisecondsSinceProcessStart())
XCTAssertGreaterThan(
elapsed, 0,
"time from process start to now must be positive; a zero here means the stamp was not read")
}

/// The old measurement started inside `loadAllData()`. The new one starts at
/// exec, so it must include everything before the data load — otherwise the
/// rename bought nothing.
func testProcessStartPrecedesAnyTimestampTakenByOurOwnCode() throws {
let start = try XCTUnwrap(AppStartupTiming.processStartDate())
let takenNow = Date()
XCTAssertLessThan(
start, takenNow,
"any Date() our code can take is necessarily after the kernel's exec stamp")
XCTAssertGreaterThan(
AppStartupTiming.elapsedMilliseconds(from: start, to: takenNow),
0)
}

func testElapsedMillisecondsConvertsAndNeverGoesNegative() {
let base = Date(timeIntervalSince1970: 1_000)
XCTAssertEqual(
AppStartupTiming.elapsedMilliseconds(from: base, to: base.addingTimeInterval(1.5)),
1_500,
accuracy: 0.001)

// Both instants come from the wall clock, so an adjustment between them can
// invert them. A startup metric must never report a negative duration.
XCTAssertEqual(
AppStartupTiming.elapsedMilliseconds(from: base, to: base.addingTimeInterval(-30)),
0,
accuracy: 0.001)
}

/// When the kernel lookup fails the property is omitted rather than replaced
/// with a plausible-looking number, which is how the implausible 11–131ms
/// values became indistinguishable from real ones.
func testMissingProcessStartYieldsNoMeasurementRatherThanAFabricatedOne() {
XCTAssertNil(
AppStartupTiming.millisecondsSinceProcessStart(now: Date(), processStart: nil))
}
}
69 changes: 69 additions & 0 deletions desktop/macos/Desktop/Tests/RewindDatabaseLifecycleTests.swift
Original file line number Diff line number Diff line change
Expand Up @@ -132,6 +132,75 @@ final class RewindDatabaseLifecycleTests: XCTestCase {
RewindDatabase.currentUserId = nil
}

/// `App Startup Timing` reported `had_unclean_shutdown = true` on 10 of 11
/// samples. The flag file is created at the end of `performInitialization()`,
/// so any of the seventeen storage actors that open the database lazily could
/// beat the startup-timing reader to it — after which the reader observed
/// *this* session's flag and called every launch a crash. The verdict must be
/// a property of the process, not of who asked first.
func testUncleanShutdownVerdictSurvivesTheDatabaseOpeningFirst() async throws {
let testUserId = "rewind-db-unclean-order-\(UUID().uuidString)"
let applicationSupportDirectory = try XCTUnwrap(
FileManager.default.urls(for: .applicationSupportDirectory, in: .userDomainMask).first
)
let userDir =
applicationSupportDirectory
.appendingPathComponent("Omi", isDirectory: true)
.appendingPathComponent("users", isDirectory: true)
.appendingPathComponent(testUserId, isDirectory: true)
defer { try? FileManager.default.removeItem(at: userDir) }

await RewindDatabase.shared.close()
RewindDatabase.currentUserId = testUserId
await RewindDatabase.shared.configure(userId: testUserId)

// A storage actor opens the database before anything reads the verdict.
try await RewindDatabase.shared.initialize()
let runningFlag = userDir.appendingPathComponent(".omi_running")
XCTAssertTrue(
FileManager.default.fileExists(atPath: runningFlag.path),
"this session's running flag must exist, otherwise the test proves nothing")

let verdict = await RewindDatabase.shared.hadUncleanShutdown()
XCTAssertFalse(
verdict,
"the previous session ended cleanly; this session's own running flag must not be read as a crash")

await RewindDatabase.shared.close()
RewindDatabase.currentUserId = nil
}

/// The latch must not swallow a real crash: a running flag left behind by a
/// previous session still reports unclean, whatever order it is read in.
func testPreviousSessionCrashIsStillReportedAfterTheDatabaseOpens() async throws {
let testUserId = "rewind-db-unclean-crash-\(UUID().uuidString)"
let applicationSupportDirectory = try XCTUnwrap(
FileManager.default.urls(for: .applicationSupportDirectory, in: .userDomainMask).first
)
let userDir =
applicationSupportDirectory
.appendingPathComponent("Omi", isDirectory: true)
.appendingPathComponent("users", isDirectory: true)
.appendingPathComponent(testUserId, isDirectory: true)
defer { try? FileManager.default.removeItem(at: userDir) }

// Simulate a previous launch that never removed its running flag.
try FileManager.default.createDirectory(at: userDir, withIntermediateDirectories: true)
FileManager.default.createFile(
atPath: userDir.appendingPathComponent(".omi_running").path, contents: nil)

await RewindDatabase.shared.close()
RewindDatabase.currentUserId = testUserId
await RewindDatabase.shared.configure(userId: testUserId)
try await RewindDatabase.shared.initialize()

let verdict = await RewindDatabase.shared.hadUncleanShutdown()
XCTAssertTrue(verdict, "a stale running flag from the previous session is a real unclean shutdown")

await RewindDatabase.shared.close()
RewindDatabase.currentUserId = nil
}

func testPoolGenerationAdvancesAcrossReopen() async throws {
let testUserId = "rewind-db-pool-generation-\(UUID().uuidString)"
let applicationSupportDirectory = try XCTUnwrap(
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,3 @@
{
"change": "Startup timing is measured and reported again, from real process start, and no longer calls every clean launch a crash"
}
1 change: 1 addition & 0 deletions desktop/macos/e2e/flows/harness-smoke.yaml
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,7 @@ covers:
- desktop/macos/Desktop/Sources/DesktopKeychainStore.swift
- desktop/macos/Desktop/Sources/Logger.swift
- desktop/macos/Desktop/Sources/Observability/SentryBeforeSendPolicy.swift
- desktop/macos/Desktop/Sources/Observability/AppStartupTiming.swift
- desktop/macos/Desktop/Sources/ClientDeviceService.swift
- desktop/macos/Desktop/Sources/LocalAgentAPIServer.swift
- desktop/macos/Desktop/Sources/AgentSyncService.swift
Expand Down
Loading