Fix app start trace outliers from network delays (#10733)

FirebasePerformance/Sources/AppActivity/FPRAppActivityTracker.m

@@ -30,6 +30,8 @@
 static NSDate *doubleDispatchTime = nil;
 static NSDate *applicationDidFinishLaunchTime = nil;
 static NSTimeInterval gAppStartMaxValidDuration = 60 * 60;  // 60 minutes.
+static NSTimeInterval gAppStartReasonableValidDuration =
+    30.0;  // 30 seconds, reasonable app start time???
 static FPRCPUGaugeData *gAppStartCPUGaugeData = nil;
 static FPRMemoryGaugeData *gAppStartMemoryGaugeData = nil;
 static BOOL isActivePrewarm = NO;
@@ -71,6 +73,9 @@ @interface FPRAppActivityTracker ()
 /** Tracks if the gauge metrics are dispatched. */
 @property(nonatomic) BOOL appStartGaugeMetricDispatched;
 
+/** Tracks if TTI stage has been started for this instance. */
+@property(nonatomic) BOOL ttiStageStarted;
+
 /** Firebase Performance Configuration object */
 @property(nonatomic) FPRConfigurations *configurations;
 
@@ -113,6 +118,18 @@ + (void)windowDidBecomeVisible:(NSNotification *)notification {
 
 + (void)applicationDidFinishLaunching:(NSNotification *)notification {
   applicationDidFinishLaunchTime = [NSDate date];
+
+  // Detect a background launch and invalidate app start time
+  // this prevents we measure duration from background launch
+  UIApplicationState state = [UIApplication sharedApplication].applicationState;
+  if (state == UIApplicationStateBackground) {
+    // App launched in background so we invalidate the captured app start time
+    // to prevent incorrect measurement when user later opens the app
+    appStartTime = nil;
+    NSLog(@"Firebase Performance: Background launch detected. App start measurement will be "
+          @"skipped.");
+  }
+
   [[NSNotificationCenter defaultCenter] removeObserver:self
                                                   name:UIApplicationDidFinishLaunchingNotification
                                                 object:nil];
@@ -135,6 +152,7 @@ - (instancetype)initAppActivityTracker {
   if (self != nil) {
     _applicationState = FPRApplicationStateUnknown;
     _appStartGaugeMetricDispatched = NO;
+    _ttiStageStarted = NO;
     _configurations = [FPRConfigurations sharedInstance];
     [self startTrackingNetwork];
   }
@@ -242,6 +260,14 @@ - (void)appDidBecomeActiveNotification:(NSNotification *)notification {
 
   static dispatch_once_t onceToken;
   dispatch_once(&onceToken, ^{
+    // Early bailout if background launch was detected, appStartTime will be nil if the app was
+    // launched in background
+    if (appStartTime == nil) {
+      NSLog(@"Firebase Performance: App start trace skipped due to background launch. "
+            @"This prevents reporting incorrect multi-minute/hour durations.");
+      return;
+    }
+
     self.appStartTrace = [[FIRTrace alloc] initInternalTraceWithName:kFPRAppStartTraceName];
     [self.appStartTrace startWithStartTime:appStartTime];
     [self.appStartTrace startStageNamed:kFPRAppStartStageNameTimeToUI startTime:appStartTime];
@@ -250,9 +276,13 @@ - (void)appDidBecomeActiveNotification:(NSNotification *)notification {
     [self.appStartTrace startStageNamed:kFPRAppStartStageNameTimeToFirstDraw];
   });
 
-  // If ever the app start trace had it life in background stage, do not send the trace.
-  if (self.appStartTrace.backgroundTraceState != FPRTraceStateForegroundOnly) {
+  // If ever the app start trace had its life in background stage, do not send the trace.
+  if (self.appStartTrace &&
+      self.appStartTrace.backgroundTraceState != FPRTraceStateForegroundOnly) {
+    [self.appStartTrace cancel];
     self.appStartTrace = nil;
+    NSLog(
+        @"Firebase Performance: App start trace cancelled due to background state contamination.");
   }
 
   // Stop the active background session trace.
@@ -266,28 +296,43 @@ - (void)appDidBecomeActiveNotification:(NSNotification *)notification {
   self.foregroundSessionTrace = appTrace;
 
   // Start measuring time to make the app interactive on the App start trace.
-  static BOOL TTIStageStarted = NO;
-  if (!TTIStageStarted) {
+  if (!self.ttiStageStarted && self.appStartTrace) {
     [self.appStartTrace startStageNamed:kFPRAppStartStageNameTimeToUserInteraction];
-    TTIStageStarted = YES;
+    self.ttiStageStarted = YES;
 
-    // Assumption here is that - the app becomes interactive in the next runloop cycle.
-    // It is possible that the app does more things later, but for now we are not measuring that.
+    // Defer stopping the trace to the next run loop cycle, this ensures that the app is
+    // fully interactive and gives the UI a chance to settle before measuring completion.
+    __weak typeof(self) weakSelf = self;
     dispatch_async(dispatch_get_main_queue(), ^{
-      NSTimeInterval startTimeSinceEpoch = [self.appStartTrace startTimeSinceEpoch];
-      NSTimeInterval currentTimeSinceEpoch = [[NSDate date] timeIntervalSince1970];
+      __strong typeof(weakSelf) strongSelf = weakSelf;
+      if (!strongSelf || !strongSelf.appStartTrace) {
+        return;
+      }
 
-      // The below check is to account for 2 scenarios.
-      // 1. The app gets started in the background and might come to foreground a lot later.
-      // 2. The app is launched, but immediately backgrounded for some reason and the actual launch
-      // happens a lot later.
-      // Dropping the app start trace in such situations where the launch time is taking more than
-      // 60 minutes. This is an approximation, but a more agreeable timelimit for app start.
-      if ((currentTimeSinceEpoch - startTimeSinceEpoch < gAppStartMaxValidDuration) &&
-          [self isAppStartEnabled] && ![self isApplicationPreWarmed]) {
-        [self.appStartTrace stop];
+      NSTimeInterval startTimeSinceEpoch = [strongSelf.appStartTrace startTimeSinceEpoch];
+      NSTimeInterval currentTimeSinceEpoch = [[NSDate date] timeIntervalSince1970];
+      NSTimeInterval elapsed = currentTimeSinceEpoch - startTimeSinceEpoch;
+
+      // The below check accounts for multiple scenarios:
+      // 1. App started in background and comes to foreground later (60 min or more)
+      // 2. App launched but immediately backgrounded
+      // 3. Network delays during startup inflating metrics (30 sec or more)
+      // 4. iOS prewarm scenarios
+      BOOL shouldCompleteTrace = (elapsed < gAppStartMaxValidDuration) &&
+                                 [strongSelf isAppStartEnabled] &&
+                                 ![strongSelf isApplicationPreWarmed];
+
+      // Cancel if elapsed time is unreasonably long for app start this should catch network induced
+      // delays and other edge cases that slip through as an additional safety check
+      if (shouldCompleteTrace && elapsed < gAppStartReasonableValidDuration) {
+        [strongSelf.appStartTrace stop];
       } else {
-        [self.appStartTrace cancel];
+        [strongSelf.appStartTrace cancel];
+        if (elapsed >= gAppStartReasonableValidDuration) {
+          // Log for debugging network related delays
+          NSLog(@"Firebase Performance: App start trace cancelled due to excessive duration: %.2fs",
+                elapsed);
+        }
       }
     });
   }