Report pre-warmed app starts (#1969)

Report pre-warmed app starts by dropping the first app start spans if pre-warming paused during these steps. This approach will shorten the app start duration, but it represents the duration a user has to wait after clicking the app icon until the app is responsive. We report the app start type in the appContext, so Sentry can make changes to the UI for prewarmed app starts. Fixes GH-1897
getsentry · Nov 14, 2022 · 0032a5d · 0032a5d
1 parent e2a3f3e
commit 0032a5d
Show file tree

Hide file tree

Showing 24 changed files with 514 additions and 122 deletions.
diff --git a/CHANGELOG.md b/CHANGELOG.md
@@ -2,6 +2,10 @@
 
 ## Unreleased
 
+### Features
+
+- Report pre-warmed app starts (#1969)
+
 ### Fixes
 
 - Too long flush duration (#2370)

diff --git a/Samples/iOS-Swift/iOS-Swift/AppDelegate.swift b/Samples/iOS-Swift/iOS-Swift/AppDelegate.swift
@@ -36,6 +36,7 @@ class AppDelegate: UIResponder, UIApplicationDelegate {
             // the benchmark test starts and stops a custom transaction using a UIButton, and automatic user interaction tracing stops the transaction that begins with that button press after the idle timeout elapses, stopping the profiler (only one profiler runs regardless of the number of concurrent transactions)
             options.enableUserInteractionTracing = !isBenchmarking
             options.enableAutoPerformanceTracking = !isBenchmarking
+            options.enablePreWarmedAppStartTracking = !isBenchmarking
 
             // because we run CPU for 15 seconds at full throttle, we trigger ANR issues being sent. disable such during benchmarks.
             options.enableAppHangTracking = !isBenchmarking

diff --git a/Sentry.xcodeproj/project.pbxproj b/Sentry.xcodeproj/project.pbxproj
@@ -296,6 +296,9 @@
 		7B0A542E2521C62400A71716 /* SentryFrameRemoverTests.swift in Sources */ = {isa = PBXBuildFile; fileRef = 7B0A542D2521C62400A71716 /* SentryFrameRemoverTests.swift */; };
 		7B0A5452252311CE00A71716 /* SentryBreadcrumbTests.swift in Sources */ = {isa = PBXBuildFile; fileRef = 7B0A5451252311CE00A71716 /* SentryBreadcrumbTests.swift */; };
 		7B0A54562523178700A71716 /* SentryScopeSwiftTests.swift in Sources */ = {isa = PBXBuildFile; fileRef = 7B0A54552523178700A71716 /* SentryScopeSwiftTests.swift */; };
+		7B0DC72F288698F70039995F /* NSMutableDictionary+Sentry.h in Headers */ = {isa = PBXBuildFile; fileRef = 7B0DC72D288698F70039995F /* NSMutableDictionary+Sentry.h */; };
+		7B0DC730288698F70039995F /* NSMutableDictionary+Sentry.m in Sources */ = {isa = PBXBuildFile; fileRef = 7B0DC72E288698F70039995F /* NSMutableDictionary+Sentry.m */; };
+		7B0DC73428869BF40039995F /* NSMutableDictionarySentryTests.swift in Sources */ = {isa = PBXBuildFile; fileRef = 7B0DC73328869BF40039995F /* NSMutableDictionarySentryTests.swift */; };
 		7B127B0D27CF6F2300A71ED2 /* SentryANRTrackingIntegration.h in Headers */ = {isa = PBXBuildFile; fileRef = 7B127B0C27CF6F2300A71ED2 /* SentryANRTrackingIntegration.h */; };
 		7B127B0F27CF6F4700A71ED2 /* SentryANRTrackingIntegration.m in Sources */ = {isa = PBXBuildFile; fileRef = 7B127B0E27CF6F4700A71ED2 /* SentryANRTrackingIntegration.m */; };
 		7B14089624878F090035403D /* SentryCrashStackEntryMapper.h in Headers */ = {isa = PBXBuildFile; fileRef = 7B14089524878F090035403D /* SentryCrashStackEntryMapper.h */; };
@@ -1034,6 +1037,9 @@
 		7B0A542D2521C62400A71716 /* SentryFrameRemoverTests.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = SentryFrameRemoverTests.swift; sourceTree = "<group>"; };
 		7B0A5451252311CE00A71716 /* SentryBreadcrumbTests.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = SentryBreadcrumbTests.swift; sourceTree = "<group>"; };
 		7B0A54552523178700A71716 /* SentryScopeSwiftTests.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = SentryScopeSwiftTests.swift; sourceTree = "<group>"; };
+		7B0DC72D288698F70039995F /* NSMutableDictionary+Sentry.h */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.c.h; name = "NSMutableDictionary+Sentry.h"; path = "include/NSMutableDictionary+Sentry.h"; sourceTree = "<group>"; };
+		7B0DC72E288698F70039995F /* NSMutableDictionary+Sentry.m */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.c.objc; path = "NSMutableDictionary+Sentry.m"; sourceTree = "<group>"; };
+		7B0DC73328869BF40039995F /* NSMutableDictionarySentryTests.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = NSMutableDictionarySentryTests.swift; sourceTree = "<group>"; };
 		7B127B0C27CF6F2300A71ED2 /* SentryANRTrackingIntegration.h */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.c.h; name = SentryANRTrackingIntegration.h; path = include/SentryANRTrackingIntegration.h; sourceTree = "<group>"; };
 		7B127B0E27CF6F4700A71ED2 /* SentryANRTrackingIntegration.m */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.c.objc; path = SentryANRTrackingIntegration.m; sourceTree = "<group>"; };
 		7B14089524878F090035403D /* SentryCrashStackEntryMapper.h */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.c.h; name = SentryCrashStackEntryMapper.h; path = include/SentryCrashStackEntryMapper.h; sourceTree = "<group>"; };
@@ -1676,6 +1682,8 @@
 				63BE856F1ECEC6DE00DC44F5 /* NSDate+SentryExtras.m */,
 				63295AF31EF3C7DB002D4490 /* NSDictionary+SentrySanitize.h */,
 				63295AF41EF3C7DB002D4490 /* NSDictionary+SentrySanitize.m */,
+				7B0DC72D288698F70039995F /* NSMutableDictionary+Sentry.h */,
+				7B0DC72E288698F70039995F /* NSMutableDictionary+Sentry.m */,
 				861265F72404EC1500C4AFDE /* NSArray+SentrySanitize.h */,
 				861265F82404EC1500C4AFDE /* NSArray+SentrySanitize.m */,
 				7B6438A826A70F24000D0F65 /* UIViewController+Sentry.h */,
@@ -2327,6 +2335,7 @@
 			isa = PBXGroup;
 			children = (
 				7B6438A626A70DDB000D0F65 /* UIViewControllerSentryTests.swift */,
+				7B0DC73328869BF40039995F /* NSMutableDictionarySentryTests.swift */,
 				0A6EEADC28A657970076B469 /* UIViewRecursiveDescriptionTests.swift */,
 			);
 			path = Categories;
@@ -3118,6 +3127,7 @@
 				D867063F27C3BC2400048851 /* SentryCoreDataTracker.h in Headers */,
 				7B9657252683104C00C66E25 /* NSData+Sentry.h in Headers */,
 				7B6C5EDA264E8D860010D138 /* SentryFramesTrackingIntegration.h in Headers */,
+				7B0DC72F288698F70039995F /* NSMutableDictionary+Sentry.h in Headers */,
 				63FE713920DA4C1100CDBAE8 /* SentryCrashMach.h in Headers */,
 				63EED6BE2237923600E02400 /* SentryOptions.h in Headers */,
 				7BD86EC5264A63F6005439DB /* SentrySysctl.h in Headers */,
@@ -3312,6 +3322,7 @@
 				7B3398652459C15200BD9C96 /* SentryEnvelopeRateLimit.m in Sources */,
 				0A2D8D9628997845008720F6 /* NSLocale+Sentry.m in Sources */,
 				A2475E1F25FB648B007D9080 /* fishhook.c in Sources */,
+				7B0DC730288698F70039995F /* NSMutableDictionary+Sentry.m in Sources */,
 				7BD4BD4527EB29F50071F4FF /* SentryClientReport.m in Sources */,
 				631E6D341EBC679C00712345 /* SentryQueueableRequestManager.m in Sources */,
 				7B8713B426415BAA006D6004 /* SentryAppStartTracker.m in Sources */,
@@ -3733,6 +3744,7 @@
 				7B965728268321CD00C66E25 /* SentryCrashScopeObserverTests.swift in Sources */,
 				7BD86ECB264A6DB5005439DB /* TestSysctl.swift in Sources */,
 				035E73CA27D57398005EEB11 /* SentryThreadHandleTests.mm in Sources */,
+				7B0DC73428869BF40039995F /* NSMutableDictionarySentryTests.swift in Sources */,
 				7B6ADFCF26A02CAE0076C206 /* SentryCrashReportTests.swift in Sources */,
 				D8B76B062808066D000A58C4 /* SentryScreenshotIntegrationTests.swift in Sources */,
 				7B8CA85726DD4E6200DD872C /* SentryNetworkTrackerIntegrationTests.swift in Sources */,

diff --git a/Sources/Sentry/NSMutableDictionary+Sentry.m b/Sources/Sentry/NSMutableDictionary+Sentry.m
@@ -0,0 +1,21 @@
+#import "NSMutableDictionary+Sentry.h"
+
+@implementation
+NSMutableDictionary (Sentry)
+
+- (void)mergeEntriesFromDictionary:(NSDictionary *)otherDictionary
+{
+    [otherDictionary enumerateKeysAndObjectsUsingBlock:^(id otherKey, id otherObj, BOOL *stop) {
+        if ([otherObj isKindOfClass:NSDictionary.class] &&
+            [self[otherKey] isKindOfClass:NSDictionary.class]) {
+            NSMutableDictionary *mergedDict = ((NSDictionary *)self[otherKey]).mutableCopy;
+            [mergedDict mergeEntriesFromDictionary:(NSDictionary *)otherObj];
+            self[otherKey] = mergedDict;
+            return;
+        }
+
+        self[otherKey] = otherObj;
+    }];
+}
+
+@end
diff --git a/Sources/Sentry/Public/SentryAppStartMeasurement.h b/Sources/Sentry/Public/SentryAppStartMeasurement.h
@@ -27,6 +27,7 @@ SENTRY_NO_INIT
  * Initializes SentryAppStartMeasurement with the given parameters.
  */
 - (instancetype)initWithType:(SentryAppStartType)type
+                      isPreWarmed:(BOOL)isPreWarmed
                 appStartTimestamp:(NSDate *)appStartTimestamp
                          duration:(NSTimeInterval)duration
              runtimeInitTimestamp:(NSDate *)runtimeInitTimestamp
@@ -38,14 +39,17 @@ SENTRY_NO_INIT
  */
 @property (readonly, nonatomic, assign) SentryAppStartType type;
 
+@property (readonly, nonatomic, assign) BOOL isPreWarmed;
+
 /**
  * How long the app start took. From appStartTimestamp to when the SDK creates the
  * AppStartMeasurement, which is done when the OS posts UIWindowDidBecomeVisibleNotification.
  */
 @property (readonly, nonatomic, assign) NSTimeInterval duration;
 
 /**
- * The timestamp when the app started, which is the process start timestamp.
+ * The timestamp when the app started, which is the process start timestamp and for prewarmed app
+ * starts the moduleInitializationTimestamp.
  */
 @property (readonly, nonatomic, strong) NSDate *appStartTimestamp;
 

diff --git a/Sources/Sentry/Public/SentryOptions.h b/Sources/Sentry/Public/SentryOptions.h
@@ -240,6 +240,20 @@ NS_SWIFT_NAME(Options)
  */
 @property (nonatomic, assign) NSTimeInterval idleTimeout;
 
+/**
+ * This feature is EXPERIMENTAL.
+ *
+ * Report pre-warmed app starts by dropping the first app start spans if pre-warming paused during
+ * these steps. This approach will shorten the app start duration, but it represents the duration a
+ * user has to wait after clicking the app icon until the app is responsive.
+ *
+ * You can filter for different app start types in Discover with app_start_type:cold.prewarmed,
+ * app_start_type:warm.prewarmed, app_start_type:cold, and app_start_type:warm.
+ *
+ * Default value is <code>NO</code>
+ */
+@property (nonatomic, assign) BOOL enablePreWarmedAppStartTracking;
+
 #endif
 
 /**

diff --git a/Sources/Sentry/SentryAppStartMeasurement.m b/Sources/Sentry/SentryAppStartMeasurement.m
@@ -11,6 +11,7 @@ - (instancetype)initWithType:(SentryAppStartType)type
     didFinishLaunchingTimestamp:(NSDate *)didFinishLaunchingTimestamp
 {
     return [self initWithType:type
+                          isPreWarmed:NO
                     appStartTimestamp:appStartTimestamp
                              duration:duration
                  runtimeInitTimestamp:runtimeInitTimestamp
@@ -19,6 +20,7 @@ - (instancetype)initWithType:(SentryAppStartType)type
 }
 
 - (instancetype)initWithType:(SentryAppStartType)type
+                      isPreWarmed:(BOOL)isPreWarmed
                 appStartTimestamp:(NSDate *)appStartTimestamp
                          duration:(NSTimeInterval)duration
              runtimeInitTimestamp:(NSDate *)runtimeInitTimestamp
@@ -27,6 +29,7 @@ - (instancetype)initWithType:(SentryAppStartType)type
 {
     if (self = [super init]) {
         _type = type;
+        _isPreWarmed = isPreWarmed;
         _appStartTimestamp = appStartTimestamp;
         _duration = duration;
         _runtimeInitTimestamp = runtimeInitTimestamp;

diff --git a/Sources/Sentry/SentryAppStartTracker.m b/Sources/Sentry/SentryAppStartTracker.m
@@ -34,6 +34,7 @@
 @property (nonatomic, strong) SentrySysctl *sysctl;
 @property (nonatomic, assign) BOOL wasInBackground;
 @property (nonatomic, strong) NSDate *didFinishLaunchingTimestamp;
+@property (nonatomic, assign) BOOL enablePreWarmedAppStartTracking;
 
 @end
 
@@ -55,6 +56,7 @@ - (instancetype)initWithCurrentDateProvider:(id<SentryCurrentDateProvider>)curre
                        dispatchQueueWrapper:(SentryDispatchQueueWrapper *)dispatchQueueWrapper
                             appStateManager:(SentryAppStateManager *)appStateManager
                                      sysctl:(SentrySysctl *)sysctl
+            enablePreWarmedAppStartTracking:(BOOL)enablePreWarmedAppStartTracking
 {
     if (self = [super init]) {
         self.currentDate = currentDateProvider;
@@ -64,6 +66,7 @@ - (instancetype)initWithCurrentDateProvider:(id<SentryCurrentDateProvider>)curre
         self.previousAppState = [self.appStateManager loadPreviousAppState];
         self.wasInBackground = NO;
         self.didFinishLaunchingTimestamp = [currentDateProvider date];
+        self.enablePreWarmedAppStartTracking = enablePreWarmedAppStartTracking;
     }
     return self;
 }
@@ -120,12 +123,17 @@ - (void)buildAppStartMeasurement
     void (^block)(void) = ^(void) {
         [self stop];
 
-        // Don't (yet) report pre warmed app starts.
-        // Check if prewarm is available. Just to be safe to not drop app start data on earlier OS
-        // verions.
+        BOOL isPreWarmed = NO;
         if ([self isActivePrewarmAvailable] && isActivePrewarm) {
-            SENTRY_LOG_INFO(@"The app was prewarmed. Not measuring app start.");
-            return;
+            SENTRY_LOG_INFO(@"The app was prewarmed.");
+
+            if (self.enablePreWarmedAppStartTracking) {
+                isPreWarmed = YES;
+            } else {
+                SENTRY_LOG_INFO(
+                    @"EnablePreWarmedAppStartTracking disabled. Not measuring app start.");
+                return;
+            }
         }
 
         SentryAppStartType appStartType = [self getStartType];
@@ -145,16 +153,29 @@ - (void)buildAppStartMeasurement
         // According to a talk at WWDC about optimizing app launch
         // (https://devstreaming-cdn.apple.com/videos/wwdc/2019/423lzf3qsjedrzivc7/423/423_optimizing_app_launch.pdf?dl=1
         // slide 17) no process exists for cold and warm launches. Since iOS 15, though, the system
-        // might decide to pre-warm your app before the user tries to open it. The process start
-        // time returned valid values when testing with real devices if the app start is not
-        // prewarmed. See:
+        // might decide to pre-warm your app before the user tries to open it.
+        // Prewarming can stop at any of the app launch steps. Our findings show that most of
+        // the prewarmed app starts don't call the main method. Therefore we subtract the
+        // time before the module initialization / main method to calculate the app start
+        // duration. If the app start stopped during a later launch step, we drop it below with
+        // checking the SENTRY_APP_START_MAX_DURATION. With this approach, we will
+        // lose some warm app starts, but we accept this tradeoff. Useful resources:
         // https://developer.apple.com/documentation/uikit/app_and_environment/responding_to_the_launch_of_your_app/about_the_app_launch_sequence#3894431
         // https://developer.apple.com/documentation/metrickit/mxapplaunchmetric,
         // https://twitter.com/steipete/status/1466013492180312068,
         // https://github.com/MobileNativeFoundation/discussions/discussions/146
-
-        NSTimeInterval appStartDuration =
-            [[self.currentDate date] timeIntervalSinceDate:self.sysctl.processStartTimestamp];
+        // https://eisel.me/startup
+        NSTimeInterval appStartDuration = 0.0;
+        NSDate *appStartTimestamp;
+        if (isPreWarmed) {
+            appStartDuration = [[self.currentDate date]
+                timeIntervalSinceDate:self.sysctl.moduleInitializationTimestamp];
+            appStartTimestamp = self.sysctl.moduleInitializationTimestamp;
+        } else {
+            appStartDuration =
+                [[self.currentDate date] timeIntervalSinceDate:self.sysctl.processStartTimestamp];
+            appStartTimestamp = self.sysctl.processStartTimestamp;
+        }
 
         // Safety check to not report app starts that are completely off.
         if (appStartDuration >= SENTRY_APP_START_MAX_DURATION) {
@@ -177,7 +198,8 @@ - (void)buildAppStartMeasurement
 
         SentryAppStartMeasurement *appStartMeasurement = [[SentryAppStartMeasurement alloc]
                              initWithType:appStartType
-                        appStartTimestamp:self.sysctl.processStartTimestamp
+                              isPreWarmed:isPreWarmed
+                        appStartTimestamp:appStartTimestamp
                                  duration:appStartDuration
                      runtimeInitTimestamp:runtimeInit
             moduleInitializationTimestamp:self.sysctl.moduleInitializationTimestamp

diff --git a/Sources/Sentry/SentryAppStartTrackingIntegration.m b/Sources/Sentry/SentryAppStartTrackingIntegration.m
@@ -37,10 +37,11 @@ - (BOOL)installWithOptions:(SentryOptions *)options
         [SentryDependencyContainer sharedInstance].appStateManager;
 
     self.tracker = [[SentryAppStartTracker alloc]
-        initWithCurrentDateProvider:currentDateProvider
-               dispatchQueueWrapper:[[SentryDispatchQueueWrapper alloc] init]
-                    appStateManager:appStateManager
-                             sysctl:sysctl];
+            initWithCurrentDateProvider:currentDateProvider
+                   dispatchQueueWrapper:[[SentryDispatchQueueWrapper alloc] init]
+                        appStateManager:appStateManager
+                                 sysctl:sysctl
+        enablePreWarmedAppStartTracking:options.enablePreWarmedAppStartTracking];
     [self.tracker start];
 
     return YES;

diff --git a/Sources/Sentry/SentryClient.m b/Sources/Sentry/SentryClient.m
@@ -654,6 +654,12 @@ - (void)setSdk:(SentryEvent *)event
         if (self.options.stitchAsyncCode) {
             [integrations addObject:@"StitchAsyncCode"];
         }
+
+#if SENTRY_HAS_UIKIT
+        if (self.options.enablePreWarmedAppStartTracking) {
+            [integrations addObject:@"PreWarmedAppStartTracking"];
+        }
+#endif
     }
 
     event.sdk = @{

diff --git a/Sources/Sentry/SentryOptions.m b/Sources/Sentry/SentryOptions.m
@@ -69,6 +69,7 @@ - (instancetype)init
         self.attachViewHierarchy = NO;
         self.enableUserInteractionTracing = NO;
         self.idleTimeout = 3.0;
+        self.enablePreWarmedAppStartTracking = NO;
 #endif
         self.enableAppHangTracking = NO;
         self.appHangTimeoutInterval = 2.0;
@@ -311,6 +312,9 @@ - (BOOL)validateOptions:(NSDictionary<NSString *, id> *)options
     if ([options[@"idleTimeout"] isKindOfClass:[NSNumber class]]) {
         self.idleTimeout = [options[@"idleTimeout"] doubleValue];
     }
+
+    [self setBool:options[@"enablePreWarmedAppStartTracking"]
+            block:^(BOOL value) { self->_enablePreWarmedAppStartTracking = value; }];
 #endif
 
     [self setBool:options[@"enableAppHangTracking"]

diff --git a/Sources/Sentry/SentryScope.m b/Sources/Sentry/SentryScope.m
@@ -1,4 +1,5 @@
 #import "SentryScope.h"
+#import "NSMutableDictionary+Sentry.h"
 #import "SentryAttachment.h"
 #import "SentryBreadcrumb.h"
 #import "SentryEnvelopeItemType.h"
@@ -513,13 +514,9 @@ - (SentryEvent *__nullable)applyToEvent:(SentryEvent *)event
         event.level = level;
     }
 
-    NSMutableDictionary *newContext;
-    if (nil == event.context) {
-        newContext = [self context].mutableCopy;
-    } else {
-        newContext = [NSMutableDictionary new];
-        [newContext addEntriesFromDictionary:[self context]];
-        [newContext addEntriesFromDictionary:event.context];
+    NSMutableDictionary *newContext = [self context].mutableCopy;
+    if (event.context != nil) {
+        [newContext mergeEntriesFromDictionary:event.context];
     }
 
     if (self.span != nil) {