feat: Split up UIKit and App Init App Start Spans (#3534)

Split the UIKit and Application Init span into one span for UIKit Init
and another for Application Init. The UIKit Init span ends when the
users start the SentrySDK. We recommend that the SentrySDK is the first
to call in the UIApplication.didFinishLaunching method because
otherwise, users won't receive any potential crash reports for code
running before our SDK. Therefore, we pick the start time of our SDK as
when the UIApplicationDelegate.didFinishLaunching is called.

Fixes GH-3345

Author: philipphofmann

CHANGELOG.md

@@ -6,6 +6,7 @@
 
 - Add frames delay to transactions and spans (#3487, #3496)
 - Add slow and frozen frames to spans (#3450, #3478)
+- Split up UIKit and App Init App Start Span (#3534)
 - Prewarmed App Start Tracing is stable (#3536)
 
 ### Fixes

Sources/Sentry/SentryAppStartMeasurement.m

@@ -15,6 +15,7 @@ @implementation SentryAppStartMeasurement
     NSDate *_appStartTimestamp;
     NSDate *_runtimeInitTimestamp;
     NSDate *_moduleInitializationTimestamp;
+    NSDate *_sdkStartTimestamp;
     NSDate *_didFinishLaunchingTimestamp;
 }
 #    endif // SENTRY_HAS_UIKIT
@@ -25,6 +26,7 @@ - (instancetype)initWithType:(SentryAppStartType)type
                          duration:(NSTimeInterval)duration
              runtimeInitTimestamp:(NSDate *)runtimeInitTimestamp
     moduleInitializationTimestamp:(NSDate *)moduleInitializationTimestamp
+                sdkStartTimestamp:(NSDate *)sdkStartTimestamp
       didFinishLaunchingTimestamp:(NSDate *)didFinishLaunchingTimestamp
 {
 #    if SENTRY_HAS_UIKIT
@@ -35,6 +37,7 @@ - (instancetype)initWithType:(SentryAppStartType)type
         _duration = duration;
         _runtimeInitTimestamp = runtimeInitTimestamp;
         _moduleInitializationTimestamp = moduleInitializationTimestamp;
+        _sdkStartTimestamp = sdkStartTimestamp;
         _didFinishLaunchingTimestamp = didFinishLaunchingTimestamp;
     }
 

Sources/Sentry/SentryAppStartTracker.m

@@ -216,6 +216,7 @@ - (void)buildAppStartMeasurement:(NSDate *)appStartEnd
                                                    duration:appStartDuration
                                        runtimeInitTimestamp:runtimeInit
                               moduleInitializationTimestamp:sysctl.moduleInitializationTimestamp
+                                          sdkStartTimestamp:SentrySDK.startTimestamp
                                 didFinishLaunchingTimestamp:self.didFinishLaunchingTimestamp];
 
         SentrySDK.appStartMeasurement = appStartMeasurement;

Sources/Sentry/SentryBuildAppStartSpans.m

@@ -74,12 +74,18 @@
         [appStartSpans addObject:runtimeInitSpan];
     }
 
-    SentrySpan *appInitSpan = sentryBuildAppStartSpan(
-        tracer, appStartSpan.spanId, operation, @"UIKit and Application Init");
+    SentrySpan *appInitSpan
+        = sentryBuildAppStartSpan(tracer, appStartSpan.spanId, operation, @"UIKit Init");
     [appInitSpan setStartTimestamp:appStartMeasurement.moduleInitializationTimestamp];
-    [appInitSpan setTimestamp:appStartMeasurement.didFinishLaunchingTimestamp];
+    [appInitSpan setTimestamp:appStartMeasurement.sdkStartTimestamp];
     [appStartSpans addObject:appInitSpan];
 
+    SentrySpan *didFinishLaunching
+        = sentryBuildAppStartSpan(tracer, appStartSpan.spanId, operation, @"Application Init");
+    [didFinishLaunching setStartTimestamp:appStartMeasurement.sdkStartTimestamp];
+    [didFinishLaunching setTimestamp:appStartMeasurement.didFinishLaunchingTimestamp];
+    [appStartSpans addObject:didFinishLaunching];
+
     SentrySpan *frameRenderSpan
         = sentryBuildAppStartSpan(tracer, appStartSpan.spanId, operation, @"Initial Frame Render");
     [frameRenderSpan setStartTimestamp:appStartMeasurement.didFinishLaunchingTimestamp];

Sources/Sentry/SentrySDK.m

@@ -7,6 +7,7 @@
 #import "SentryClient+Private.h"
 #import "SentryCrash.h"
 #import "SentryCrashWrapper.h"
+#import "SentryCurrentDateProvider.h"
 #import "SentryDependencyContainer.h"
 #import "SentryDispatchQueueWrapper.h"
 #import "SentryFileManager.h"
@@ -42,6 +43,7 @@ @implementation SentrySDK
  * reenable the integrations.
  */
 static NSUInteger startInvocations;
+static NSDate *_Nullable startTimestamp = nil;
 
 + (void)initialize
 {
@@ -135,6 +137,22 @@ + (void)setStartInvocations:(NSUInteger)value
     startInvocations = value;
 }
 
+/**
+ * Not public, only for internal use.
+ */
++ (nullable NSDate *)startTimestamp
+{
+    return startTimestamp;
+}
+
+/**
+ * Only needed for testing.
+ */
++ (void)setStartTimestamp:(NSDate *)value
+{
+    startTimestamp = value;
+}
+
 + (void)startWithOptions:(SentryOptions *)options
 {
     [SentryLog configure:options.debug diagnosticLevel:options.diagnosticLevel];
@@ -145,6 +163,7 @@ + (void)startWithOptions:(SentryOptions *)options
     SENTRY_LOG_DEBUG(@"Starting SDK...");
 
     startInvocations++;
+    startTimestamp = [SentryDependencyContainer.sharedInstance.dateProvider date];
 
     SentryClient *newClient = [[SentryClient alloc] initWithOptions:options];
     [newClient.fileManager moveAppStateToPreviousAppState];
@@ -402,6 +421,8 @@ + (void)close
 {
     SENTRY_LOG_DEBUG(@"Starting to close SDK.");
 
+    startTimestamp = nil;
+
     SentryHub *hub = SentrySDK.currentHub;
     [hub removeAllIntegrations];
 

Sources/Sentry/include/HybridPublic/SentryAppStartMeasurement.h

@@ -26,6 +26,7 @@ SENTRY_NO_INIT
                          duration:(NSTimeInterval)duration
              runtimeInitTimestamp:(NSDate *)runtimeInitTimestamp
     moduleInitializationTimestamp:(NSDate *)moduleInitializationTimestamp
+                sdkStartTimestamp:(NSDate *)sdkStartTimestamp
       didFinishLaunchingTimestamp:(NSDate *)didFinishLaunchingTimestamp;
 
 /**
@@ -58,6 +59,11 @@ SENTRY_NO_INIT
  */
 @property (readonly, nonatomic, strong) NSDate *moduleInitializationTimestamp;
 
+/**
+ * When the SentrySDK start method is called.
+ */
+@property (readonly, nonatomic, strong) NSDate *sdkStartTimestamp;
+
 /**
  * When OS posts UIApplicationDidFinishLaunchingNotification.
  */

Sources/Sentry/include/SentrySDK+Private.h

@@ -21,6 +21,7 @@ SentrySDK ()
 + (nullable SentryAppStartMeasurement *)getAppStartMeasurement;
 
 @property (nonatomic, class) NSUInteger startInvocations;
+@property (nullable, nonatomic, class) NSDate *startTimestamp;
 
 + (SentryHub *)currentHub;
 

Tests/SentryProfilerTests/SentryProfilerSwiftTests.swift

@@ -228,7 +228,8 @@ class SentryProfilerSwiftTests: XCTestCase {
             appStart = preWarmed ? main : appStart
             appStartDuration = preWarmed ? appStartDuration - runtimeInitDuration - mainDuration : appStartDuration
             appStartEnd = appStart.addingTimeInterval(appStartDuration)
-            return SentryAppStartMeasurement(type: type, isPreWarmed: preWarmed, appStartTimestamp: appStart, duration: appStartDuration, runtimeInitTimestamp: runtimeInit, moduleInitializationTimestamp: main, didFinishLaunchingTimestamp: didFinishLaunching)
+            return SentryAppStartMeasurement(type: type, isPreWarmed: preWarmed, appStartTimestamp: appStart, duration: appStartDuration, runtimeInitTimestamp: runtimeInit, moduleInitializationTimestamp: main,
+                                             sdkStartTimestamp: appStart, didFinishLaunchingTimestamp: didFinishLaunching)
         }
         #endif // os(iOS) || os(tvOS) || targetEnvironment(macCatalyst)
     }

Tests/SentryTests/Integrations/Performance/AppStartTracking/SentryAppStartTrackerTests.swift

@@ -24,6 +24,7 @@ class SentryAppStartTrackerTests: NotificationCenterTestCase {
         let appStartDuration: TimeInterval = 0.4
         var runtimeInitTimestamp: Date
         var moduleInitializationTimestamp: Date
+        var sdkStartTimestamp: Date
         var didFinishLaunchingTimestamp: Date
 
         init() {
@@ -50,7 +51,10 @@ class SentryAppStartTrackerTests: NotificationCenterTestCase {
 
             runtimeInitTimestamp = SentryDependencyContainer.sharedInstance().dateProvider.date().addingTimeInterval(0.2)
             moduleInitializationTimestamp = SentryDependencyContainer.sharedInstance().dateProvider.date().addingTimeInterval(0.1)
-            didFinishLaunchingTimestamp = SentryDependencyContainer.sharedInstance().dateProvider.date().addingTimeInterval(0.3)
+            sdkStartTimestamp = SentryDependencyContainer.sharedInstance().dateProvider.date().addingTimeInterval(0.1)
+            SentrySDK.startTimestamp = sdkStartTimestamp
+            
+            didFinishLaunchingTimestamp = SentryDependencyContainer.sharedInstance().dateProvider.date().addingTimeInterval(0.2)
         }
 
         var sut: SentryAppStartTracker {
@@ -440,10 +444,12 @@ class SentryAppStartTrackerTests: NotificationCenterTestCase {
             XCTAssertEqual(fixture.sysctl.processStartTimestamp, appStartMeasurement.appStartTimestamp)
         }
 
-        XCTAssertEqual(fixture.sysctl.moduleInitializationTimestamp, appStartMeasurement.moduleInitializationTimestamp)
-        XCTAssertEqual(fixture.runtimeInitTimestamp, appStartMeasurement.runtimeInitTimestamp)
-        XCTAssertEqual(fixture.didFinishLaunchingTimestamp, appStartMeasurement.didFinishLaunchingTimestamp)
-        XCTAssertEqual(preWarmed, appStartMeasurement.isPreWarmed)
+        expect(appStartMeasurement.moduleInitializationTimestamp) == fixture.sysctl.moduleInitializationTimestamp
+        expect(appStartMeasurement.runtimeInitTimestamp) == fixture.runtimeInitTimestamp
+        
+        expect(appStartMeasurement.sdkStartTimestamp) == fixture.sdkStartTimestamp
+        expect(appStartMeasurement.didFinishLaunchingTimestamp) == fixture.didFinishLaunchingTimestamp
+        expect(appStartMeasurement.isPreWarmed) == preWarmed
     }
 
     private func assertValidHybridStart(type: SentryAppStartType) {

Tests/SentryTests/Protocol/TestData.swift

@@ -328,9 +328,10 @@ class TestData {
         let appStartDuration = 0.5
         let main = appStartTimestamp.addingTimeInterval(0.15)
         let runtimeInit = appStartTimestamp.addingTimeInterval(0.05)
-        let didFinishLaunching = appStartTimestamp.addingTimeInterval(0.3)
+        let sdkStart = appStartTimestamp.addingTimeInterval(0.1)
+        let didFinishLaunching = appStartTimestamp.addingTimeInterval(0.2)
 
-        return SentryAppStartMeasurement(type: type, isPreWarmed: false, appStartTimestamp: appStartTimestamp, duration: appStartDuration, runtimeInitTimestamp: runtimeInit, moduleInitializationTimestamp: main, didFinishLaunchingTimestamp: didFinishLaunching)
+        return SentryAppStartMeasurement(type: type, isPreWarmed: false, appStartTimestamp: appStartTimestamp, duration: appStartDuration, runtimeInitTimestamp: runtimeInit, moduleInitializationTimestamp: main, sdkStartTimestamp: sdkStart, didFinishLaunchingTimestamp: didFinishLaunching)
     }
 
     #endif // os(iOS) || os(tvOS) || targetEnvironment(macCatalyst)

Tests/SentryTests/SentrySDKTests.swift

@@ -1,3 +1,4 @@
+import Nimble
 @testable import Sentry
 import SentryTestUtils
 import XCTest
@@ -504,6 +505,23 @@ class SentrySDKTests: XCTestCase {
         XCTAssertEqual(1, SentrySDK.startInvocations)
     }
 
+    func testSDKStartTimestamp() {
+        let currentDateProvider = TestCurrentDateProvider()
+        SentryDependencyContainer.sharedInstance().dateProvider = currentDateProvider
+        
+        expect(SentrySDK.startTimestamp) == nil
+        
+        SentrySDK.start { options in
+            options.dsn = SentrySDKTests.dsnAsString
+            options.removeAllIntegrations()
+        }
+        
+        expect(SentrySDK.startTimestamp) == currentDateProvider.date()
+        
+        SentrySDK.close()
+        expect(SentrySDK.startTimestamp) == nil
+    }
+    
     func testIsEnabled() {
         XCTAssertFalse(SentrySDK.isEnabled)
 

Tests/SentryTests/Transaction/SentryTracerTests.swift

@@ -78,13 +78,14 @@ class SentryTracerTests: XCTestCase {
             let runtimeInit = appStart.addingTimeInterval(runtimeInitDuration)
             let mainDuration = 0.15
             let main = appStart.addingTimeInterval(mainDuration)
-            let didFinishLaunching = appStart.addingTimeInterval(0.3)
+            let sdkStart = appStart.addingTimeInterval(0.1)
+            let didFinishLaunching = appStart.addingTimeInterval(0.2)
             appStart = preWarmed ? main : appStart
             appStartDuration = preWarmed ? appStartDuration - runtimeInitDuration - mainDuration : appStartDuration
 
             appStartEnd = appStart.addingTimeInterval(appStartDuration)
 
-            return SentryAppStartMeasurement(type: type, isPreWarmed: preWarmed, appStartTimestamp: appStart, duration: appStartDuration, runtimeInitTimestamp: runtimeInit, moduleInitializationTimestamp: main, didFinishLaunchingTimestamp: didFinishLaunching)
+            return SentryAppStartMeasurement(type: type, isPreWarmed: preWarmed, appStartTimestamp: appStart, duration: appStartDuration, runtimeInitTimestamp: runtimeInit, moduleInitializationTimestamp: main, sdkStartTimestamp: sdkStart, didFinishLaunchingTimestamp: didFinishLaunching)
         }
         #endif // os(iOS) || os(tvOS) || targetEnvironment(macCatalyst)
 
@@ -763,6 +764,7 @@ class SentryTracerTests: XCTestCase {
             duration: 0.5,
             runtimeInitTimestamp: fixture.currentDateProvider.date(),
             moduleInitializationTimestamp: fixture.currentDateProvider.date(),
+            sdkStartTimestamp: fixture.currentDateProvider.date(),
             didFinishLaunchingTimestamp: fixture.currentDateProvider.date()
         ))
 
@@ -1188,7 +1190,7 @@ class SentryTracerTests: XCTestCase {
     #if os(iOS) || os(tvOS) || targetEnvironment(macCatalyst)
     private func assertAppStartsSpanAdded(transaction: Transaction, startType: String, operation: String, appStartMeasurement: SentryAppStartMeasurement) {
         let spans: [SentrySpan]? = Dynamic(transaction).spans
-        XCTAssertEqual(5, spans?.count)
+        expect(spans?.count) == 6
 
         let appLaunchSpan = spans?.first { span in
             span.spanDescription == startType
@@ -1214,7 +1216,8 @@ class SentryTracerTests: XCTestCase {
 
         assertSpan("Pre Runtime Init", appStartMeasurement.appStartTimestamp, appStartMeasurement.runtimeInitTimestamp)
         assertSpan("Runtime Init to Pre Main Initializers", appStartMeasurement.runtimeInitTimestamp, appStartMeasurement.moduleInitializationTimestamp)
-        assertSpan("UIKit and Application Init", appStartMeasurement.moduleInitializationTimestamp, appStartMeasurement.didFinishLaunchingTimestamp)
+        assertSpan("UIKit Init", appStartMeasurement.moduleInitializationTimestamp, appStartMeasurement.sdkStartTimestamp)
+        assertSpan("Application Init", appStartMeasurement.sdkStartTimestamp, appStartMeasurement.didFinishLaunchingTimestamp)
         assertSpan("Initial Frame Render", appStartMeasurement.didFinishLaunchingTimestamp, fixture.appStartEnd)
     }
 
@@ -1230,7 +1233,7 @@ class SentryTracerTests: XCTestCase {
 
     private func assertPreWarmedAppStartsSpanAdded(transaction: Transaction, startType: String, operation: String, appStartMeasurement: SentryAppStartMeasurement) {
             let spans: [SentrySpan]? = Dynamic(transaction).spans
-            XCTAssertEqual(3, spans?.count)
+            expect(spans?.count) == 4
 
             let appLaunchSpan = spans?.first { span in
                 span.spanDescription == startType
@@ -1252,7 +1255,8 @@ class SentryTracerTests: XCTestCase {
                 XCTAssertEqual(timestamp, span?.timestamp)
             }
 
-            assertSpan("UIKit and Application Init", appStartMeasurement.moduleInitializationTimestamp, appStartMeasurement.didFinishLaunchingTimestamp)
+            assertSpan("UIKit Init", appStartMeasurement.moduleInitializationTimestamp, appStartMeasurement.sdkStartTimestamp)
+            assertSpan("Application Init", appStartMeasurement.sdkStartTimestamp, appStartMeasurement.didFinishLaunchingTimestamp)
             assertSpan("Initial Frame Render", appStartMeasurement.didFinishLaunchingTimestamp, fixture.appStartEnd)
         }