RUMM-1803 Stop reporting pre-warmed application launch time

CHANGELOG.md

@@ -2,6 +2,7 @@
 
 * [FEATURE] Web-view tracking. See [#729][]
 * [BUGFIX] Strip query parameters from span resource. See [#728][]
+* [BUGFIX] Stop reporting pre-warmed application launch time. See [#789][]
 
 # 1.9.0 / 01-26-2022
 
@@ -324,6 +325,7 @@
 [#725]: https://github.com/DataDog/dd-sdk-ios/issues/725
 [#728]: https://github.com/DataDog/dd-sdk-ios/issues/728
 [#729]: https://github.com/DataDog/dd-sdk-ios/issues/729
+[#789]: https://github.com/DataDog/dd-sdk-ios/issues/789
 [@00FA9A]: https://github.com/00FA9A
 [@Britton-Earnin]: https://github.com/Britton-Earnin
 [@Hengyu]: https://github.com/Hengyu

Sources/Datadog/Core/System/LaunchTimeProvider.swift

@@ -19,14 +19,26 @@ internal protocol LaunchTimeProviderType {
     /// time this variable is requested, the value should represent the time interval between now and the
     /// process start time.
     var launchTime: TimeInterval { get }
+
+    /// Returns `true` if the application is pre-warmed.
+    var isActivePrewarm: Bool { get }
 }
 
 internal class LaunchTimeProvider: LaunchTimeProviderType {
     var launchTime: TimeInterval {
-        // Even if __dd_private_AppLaunchTime() is using a lock behind the scenes, TSAN will report a data race if there are no synchronizations at this level.
+        // Even if __dd_private_AppLaunchTime() is using a lock behind the
+        // scenes, TSAN will report a data race if there are no
+        // synchronizations at this level.
         objc_sync_enter(self)
         let time = __dd_private_AppLaunchTime()
         objc_sync_exit(self)
         return time
     }
+
+    var isActivePrewarm: Bool {
+        objc_sync_enter(self)
+        let isActivePrewarm = __dd_private_isActivePrewarm()
+        objc_sync_exit(self)
+        return isActivePrewarm
+    }
 }

Sources/Datadog/RUM/RUMMonitor/Scopes/RUMViewScope.swift

@@ -10,6 +10,8 @@ internal class RUMViewScope: RUMScope, RUMContextProvider {
     struct Constants {
         static let frozenFrameThresholdInNs = (0.07).toInt64Nanoseconds // 70ms
         static let slowRenderingThresholdFPS = 55.0
+        /// The pre-warming detection attribute key
+        static let activePrewarm = "active_pre_warm"
     }
 
     // MARK: - Child Scopes
@@ -303,6 +305,18 @@ internal class RUMViewScope: RUMScope, RUMContextProvider {
     // MARK: - Sending RUM Events
 
     private func sendApplicationStartAction() -> Bool {
+        var attributes = self.attributes
+        var loadingTime: Int64? = nil
+
+        if dependencies.launchTimeProvider.isActivePrewarm {
+            // Set `active_pre_warm` attribute to true in case
+            // of pre-warmed app
+            attributes[Constants.activePrewarm] = true
+        } else {
+            // Report Application Launch Time only if not pre-warmed
+            loadingTime = dependencies.launchTimeProvider.launchTime.toInt64Nanoseconds
+        }
+
         let eventData = RUMActionEvent(
             dd: .init(
                 browserSdkVersion: nil,
@@ -312,7 +326,7 @@ internal class RUMViewScope: RUMScope, RUMContextProvider {
                 crash: nil,
                 error: nil,
                 id: dependencies.rumUUIDGenerator.generateUnique().toRUMDataFormat,
-                loadingTime: dependencies.launchTimeProvider.launchTime.toInt64Nanoseconds,
+                loadingTime: loadingTime,
                 longTask: nil,
                 resource: nil,
                 target: nil,

Sources/_Datadog_Private/ObjcAppLaunchHandler.m

@@ -18,6 +18,11 @@
 static NSTimeInterval FrameworkLoadTime = 0.0;
 // The time interval between the application starts and it's responsive and accepts touch events.
 static NSTimeInterval TimeToApplicationDidBecomeActive = 0.0;
+// System sets environment variable ActivePrewarm to 1 when app is pre-warmed.
+static BOOL isActivePrewarm = NO;
+// A very long application launch time is most-likely the result of a pre-warmed process.
+// We consider 30s as a threshold for pre-warm detection.
+static NSTimeInterval ValidAppLaunchTimeThreshold = 30;
 
 NS_INLINE NSTimeInterval QueryProcessStartTimeWithFallback(NSTimeInterval fallbackTime) {
     NSTimeInterval processStartTime;
@@ -59,6 +64,8 @@ + (void)load {
     // This is called at the `_Datadog_Private` load time, keep the work minimal
     FrameworkLoadTime = CFAbsoluteTimeGetCurrent();
 
+    isActivePrewarm = [NSProcessInfo.processInfo.environment[@"ActivePrewarm"] isEqualToString:@"1"];
+
     NSNotificationCenter * __weak center = NSNotificationCenter.defaultCenter;
     id __block token = [center
                         addObserverForName:UIApplicationDidBecomeActiveNotification
@@ -81,7 +88,13 @@ + (void)load {
 CFTimeInterval __dd_private_AppLaunchTime() {
     pthread_rwlock_rdlock(&rwLock);
     CFTimeInterval time = TimeToApplicationDidBecomeActive;
-    if (time == 0) time = ComputeProcessTimeFromStart();
     pthread_rwlock_unlock(&rwLock);
+    if (time == 0) time = ComputeProcessTimeFromStart();
     return time;
 }
+
+BOOL __dd_private_isActivePrewarm() {
+    if (isActivePrewarm) return isActivePrewarm;
+    CFTimeInterval time = __dd_private_AppLaunchTime();
+    return time > ValidAppLaunchTimeThreshold;
+}

Sources/_Datadog_Private/include/ObjcAppLaunchHandler.h

@@ -4,11 +4,16 @@
 * Copyright 2019-2020 Datadog, Inc.
 */
 
-#import <CoreFoundation/CFDate.h>
+#import <CoreFoundation/CoreFoundation.h>
 
 /// Returns the time interval between startup of the application process and the
 /// `UIApplicationDidBecomeActiveNotification`.
 ///
 /// If the `UIApplicationDidBecomeActiveNotification` has not been reached yet,
 /// it returns  time interval between startup of the application process and now.
 CFTimeInterval __dd_private_AppLaunchTime(void);
+
+/// Returns `true` when the application is pre-warmed.
+///
+/// System sets environment variable `ActivePrewarm` to 1 when app is pre-warmed.
+BOOL __dd_private_isActivePrewarm(void);

Tests/DatadogTests/Datadog/LoggerTests.swift

@@ -167,7 +167,7 @@ class LoggerTests: XCTestCase {
         Datadog.instance = Datadog(
             consentProvider: ConsentProvider(initialConsent: .granted),
             userInfoProvider: UserInfoProvider(),
-            launchTimeProvider: LaunchTimeProviderMock()
+            launchTimeProvider: LaunchTimeProviderMock.mockAny()
         )
         defer { Datadog.flushAndDeinitialize() }
 

Tests/DatadogTests/Datadog/Mocks/CoreMocks.swift

@@ -491,7 +491,7 @@ extension FeaturesCommonDependencies {
             )
         ),
         carrierInfoProvider: CarrierInfoProviderType = CarrierInfoProviderMock.mockAny(),
-        launchTimeProvider: LaunchTimeProviderType = LaunchTimeProviderMock(),
+        launchTimeProvider: LaunchTimeProviderType = LaunchTimeProviderMock.mockAny(),
         appStateListener: AppStateListening = AppStateListenerMock.mockAny()
     ) -> FeaturesCommonDependencies {
         let httpClient: HTTPClient
@@ -682,7 +682,22 @@ class DateCorrectorMock: DateCorrectorType {
 }
 
 struct LaunchTimeProviderMock: LaunchTimeProviderType {
-    var launchTime: TimeInterval = 0
+    let launchTime: TimeInterval
+    let isActivePrewarm: Bool
+}
+
+extension LaunchTimeProviderMock {
+    static func mockAny() -> LaunchTimeProviderMock {
+        return mockWith(launchTime: 0, isActivePrewarm: false)
+    }
+
+    static func mockWith(launchTime: TimeInterval, isActivePrewarm: Bool = false) -> LaunchTimeProviderMock {
+        return LaunchTimeProviderMock(launchTime: launchTime, isActivePrewarm: isActivePrewarm)
+    }
+
+    static func mockRandom(launchTime: TimeInterval = .mockRandom(), isActivePrewarm: Bool = .random()) -> LaunchTimeProviderMock {
+        return mockWith(launchTime: launchTime, isActivePrewarm: isActivePrewarm)
+    }
 }
 
 extension AppState: AnyMockable, RandomMockable {

Tests/DatadogTests/Datadog/Mocks/RUMFeatureMocks.swift

@@ -613,7 +613,7 @@ extension RUMScopeDependencies {
     static func mockWith(
         appStateListener: AppStateListening = AppStateListenerMock.mockAny(),
         userInfoProvider: RUMUserInfoProvider = RUMUserInfoProvider(userInfoProvider: .mockAny()),
-        launchTimeProvider: LaunchTimeProviderType = LaunchTimeProviderMock(),
+        launchTimeProvider: LaunchTimeProviderType = LaunchTimeProviderMock.mockAny(),
         connectivityInfoProvider: RUMConnectivityInfoProvider = RUMConnectivityInfoProvider(
             networkConnectionInfoProvider: NetworkConnectionInfoProviderMock(networkConnectionInfo: nil),
             carrierInfoProvider: CarrierInfoProviderMock(carrierInfo: nil)

Tests/DatadogTests/Datadog/RUM/RUMMonitor/Scopes/RUMViewScopeTests.swift

@@ -66,12 +66,13 @@ class RUMViewScopeTests: XCTestCase {
     }
 
     func testWhenInitialViewReceivesAnyCommand_itSendsApplicationStartAction() throws {
+        // Given
         let currentTime: Date = .mockDecember15th2019At10AMUTC()
         let scope = RUMViewScope(
             isInitialView: true,
             parent: parent,
             dependencies: dependencies.replacing(
-                launchTimeProvider: LaunchTimeProviderMock(launchTime: 2) // 2 seconds
+                launchTimeProvider: LaunchTimeProviderMock.mockWith(launchTime: 2) // 2 seconds
             ),
             identity: mockView,
             path: "UIViewController",
@@ -81,8 +82,10 @@ class RUMViewScopeTests: XCTestCase {
             startTime: currentTime
         )
 
+        // When
         _ = scope.process(command: RUMCommandMock(time: currentTime))
 
+        // Then
         let event = try XCTUnwrap(output.recordedEvents(ofType: RUMActionEvent.self).first)
         XCTAssertEqual(event.date, Date.mockDecember15th2019At10AMUTC().timeIntervalSince1970.toInt64Milliseconds)
         XCTAssertEqual(event.application.id, scope.context.rumApplicationID)
@@ -97,6 +100,32 @@ class RUMViewScopeTests: XCTestCase {
         XCTAssertEqual(event.dd.session?.plan, .plan1, "All RUM events should use RUM Lite plan")
         XCTAssertEqual(event.source, .ios)
         XCTAssertEqual(event.service, randomServiceName)
+        XCTAssertNil(event.context?.contextInfo[RUMViewScope.Constants.activePrewarm])
+    }
+
+    func testWhenActivePrewarm_itSendsApplicationStartAction_withoutLoadingTime() throws {
+        // Given
+        let scope: RUMViewScope = .mockWith(
+            isInitialView: true,
+            parent: parent,
+            dependencies: dependencies.replacing(
+                launchTimeProvider: LaunchTimeProviderMock.mockWith(
+                    launchTime: 2, // 2 seconds
+                    isActivePrewarm: true
+                )
+            ),
+            identity: mockView
+        )
+
+        // When
+        _ = scope.process(command: RUMCommandMock())
+
+        // Then
+        let event = try XCTUnwrap(output.recordedEvents(ofType: RUMActionEvent.self).first)
+        let isActivePrewarm = try XCTUnwrap(event.context?.contextInfo[RUMViewScope.Constants.activePrewarm] as? Bool)
+        XCTAssertEqual(event.action.type, .applicationStart)
+        XCTAssertNil(event.action.loadingTime)
+        XCTAssertTrue(isActivePrewarm)
     }
 
     func testWhenInitialViewReceivesAnyCommand_itSendsViewUpdateEvent() throws {

Tests/DatadogTests/Datadog/TracerTests.swift

@@ -319,7 +319,7 @@ class TracerTests: XCTestCase {
         Datadog.instance = Datadog(
             consentProvider: ConsentProvider(initialConsent: .granted),
             userInfoProvider: UserInfoProvider(),
-            launchTimeProvider: LaunchTimeProviderMock()
+            launchTimeProvider: LaunchTimeProviderMock.mockAny()
         )
         defer { Datadog.flushAndDeinitialize() }