fix: Use correct rendered frames timestamp (#3531)

Use the timestamp of the DisplayLink wrapper when a new frame is reported for TTID/TTFD and the app start.
getsentry · Jan 4, 2024 · f74904f · f74904f
1 parent ce54c6a
commit f74904f
Show file tree

Hide file tree

Showing 8 changed files with 51 additions and 34 deletions.
diff --git a/CHANGELOG.md b/CHANGELOG.md
@@ -14,6 +14,8 @@
 - Crash when adding a crumb for a timezone change (#3524)
 - Fix a race condition in SentryTracer (#3523)
 - App start ends when first frame is drawn when performanceV2 is enabled (#3530)
+- Use correct rendered frames timestamp for TTID/TTFD and app start (#3531)
+
 - Missing transactions when not calling `reportFullyDisplayed` (#3477)
 
 ## 8.17.2

diff --git a/SentryTestUtils/TestCurrentDateProvider.swift b/SentryTestUtils/TestCurrentDateProvider.swift
@@ -6,12 +6,13 @@ public class TestCurrentDateProvider: CurrentDateProvider {
     private var internalDate = defaultStartingDate
     private var internalSystemTime: UInt64 = 0
     public var driftTimeForEveryRead = false
+    public var driftTimeInterval = 0.1
 
     public override func date() -> Date {
 
         defer {
             if driftTimeForEveryRead {
-                internalDate = internalDate.addingTimeInterval(0.1)
+                internalDate = internalDate.addingTimeInterval(driftTimeInterval)
             }
         }
 

diff --git a/Sources/Sentry/SentryAppStartTracker.m b/Sources/Sentry/SentryAppStartTracker.m
@@ -120,7 +120,8 @@ - (void)start
                                              object:nil];
 
     if (PrivateSentrySDKOnly.appStartMeasurementHybridSDKMode) {
-        [self buildAppStartMeasurement];
+        [self
+            buildAppStartMeasurement:[SentryDependencyContainer.sharedInstance.dateProvider date]];
     }
 
 #    if SENTRY_HAS_UIKIT
@@ -130,7 +131,7 @@ - (void)start
     self.isRunning = YES;
 }
 
-- (void)buildAppStartMeasurement
+- (void)buildAppStartMeasurement:(NSDate *)appStartEnd
 {
     void (^block)(void) = ^(void) {
         [self stop];
@@ -181,12 +182,11 @@ - (void)buildAppStartMeasurement
         NSDate *appStartTimestamp;
         SentrySysctl *sysctl = SentryDependencyContainer.sharedInstance.sysctlWrapper;
         if (isPreWarmed) {
-            appStartDuration = [[SentryDependencyContainer.sharedInstance.dateProvider date]
-                timeIntervalSinceDate:sysctl.moduleInitializationTimestamp];
+            appStartDuration =
+                [appStartEnd timeIntervalSinceDate:sysctl.moduleInitializationTimestamp];
             appStartTimestamp = sysctl.moduleInitializationTimestamp;
         } else {
-            appStartDuration = [[SentryDependencyContainer.sharedInstance.dateProvider date]
-                timeIntervalSinceDate:sysctl.processStartTimestamp];
+            appStartDuration = [appStartEnd timeIntervalSinceDate:sysctl.processStartTimestamp];
             appStartTimestamp = sysctl.processStartTimestamp;
         }
 
@@ -240,16 +240,17 @@ - (void)buildAppStartMeasurement
 - (void)didBecomeVisible
 {
     if (!_enablePerformanceV2) {
-        [self buildAppStartMeasurement];
+        [self
+            buildAppStartMeasurement:[SentryDependencyContainer.sharedInstance.dateProvider date]];
     }
 }
 
 /**
  * This is when the first frame is drawn.
  */
-- (void)framesTrackerHasNewFrame
+- (void)framesTrackerHasNewFrame:(NSDate *)newFrameDate
 {
-    [self buildAppStartMeasurement];
+    [self buildAppStartMeasurement:newFrameDate];
 }
 
 - (SentryAppStartType)getStartType

diff --git a/Sources/Sentry/SentryFramesTracker.m b/Sources/Sentry/SentryFramesTracker.m
@@ -200,8 +200,10 @@ - (void)reportNewFrame
         localListeners = [self.listeners allObjects];
     }
 
+    NSDate *newFrameDate = [self.dateProvider date];
+
     for (id<SentryFramesTrackerListener> listener in localListeners) {
-        [listener framesTrackerHasNewFrame];
+        [listener framesTrackerHasNewFrame:newFrameDate];
     }
 }
 

diff --git a/Sources/Sentry/SentryTimeToDisplayTracker.m b/Sources/Sentry/SentryTimeToDisplayTracker.m
@@ -2,7 +2,6 @@
 
 #if SENTRY_HAS_UIKIT
 
-#    import "SentryCurrentDateProvider.h"
 #    import "SentryDependencyContainer.h"
 #    import "SentryFramesTracker.h"
 #    import "SentryMeasurementValue.h"
@@ -99,15 +98,13 @@ - (void)reportFullyDisplayed
     _fullyDisplayedReported = YES;
 }
 
-- (void)framesTrackerHasNewFrame
+- (void)framesTrackerHasNewFrame:(NSDate *)newFrameDate
 {
-    NSDate *finishTime = [SentryDependencyContainer.sharedInstance.dateProvider date];
-
     // The purpose of TTID and TTFD is to measure how long
     // takes to the content of the screen to change.
     // Thats why we need to wait for the next frame to be drawn.
     if (_initialDisplayReported && self.initialDisplaySpan.isFinished == NO) {
-        self.initialDisplaySpan.timestamp = finishTime;
+        self.initialDisplaySpan.timestamp = newFrameDate;
 
         [self.initialDisplaySpan finish];
 
@@ -117,7 +114,7 @@ - (void)framesTrackerHasNewFrame
     }
     if (_waitForFullDisplay && _fullyDisplayedReported && self.fullDisplaySpan.isFinished == NO
         && self.initialDisplaySpan.isFinished == YES) {
-        self.fullDisplaySpan.timestamp = finishTime;
+        self.fullDisplaySpan.timestamp = newFrameDate;
 
         [self.fullDisplaySpan finish];
     }

diff --git a/Sources/Sentry/include/SentryFramesTracker.h b/Sources/Sentry/include/SentryFramesTracker.h
@@ -13,7 +13,7 @@ NS_ASSUME_NONNULL_BEGIN
 
 @protocol SentryFramesTrackerListener
 
-- (void)framesTrackerHasNewFrame;
+- (void)framesTrackerHasNewFrame:(NSDate *)newFrameDate;
 
 @end
 

diff --git a/Tests/SentryTests/Integrations/Performance/AppStartTracking/SentryAppStartTrackerTests.swift b/Tests/SentryTests/Integrations/Performance/AppStartTracking/SentryAppStartTrackerTests.swift
@@ -16,7 +16,7 @@ class SentryAppStartTrackerTests: NotificationCenterTestCase {
         let crashWrapper = TestSentryCrashWrapper.sharedInstance()
         let appStateManager: SentryAppStateManager
         var displayLinkWrapper = TestDisplayLinkWrapper()
-        var framesTracker: SentryFramesTracker
+        private let framesTracker: SentryFramesTracker
         let dispatchQueue = TestSentryDispatchQueueWrapper()
         var enablePreWarmedAppStartTracing = true
         var enablePerformanceV2 = false
@@ -46,7 +46,6 @@ class SentryAppStartTrackerTests: NotificationCenterTestCase {
             )
 
             framesTracker = SentryFramesTracker(displayLinkWrapper: displayLinkWrapper, dateProvider: currentDate, keepDelayedFramesDuration: 0)
-            SentryDependencyContainer.sharedInstance().framesTracker = framesTracker
             framesTracker.start()
 
             runtimeInitTimestamp = SentryDependencyContainer.sharedInstance().dateProvider.date().addingTimeInterval(0.2)
@@ -93,15 +92,15 @@ class SentryAppStartTrackerTests: NotificationCenterTestCase {
     func testPerformanceV2_UsesRenderedFrameAsEndTimeStamp() {
         fixture.enablePerformanceV2 = true
 
-        startApp()
+        startApp(callDisplayLink: true)
 
         assertValidStart(type: .cold, expectedDuration: 0.45)
     }
 
     func testPerformanceV2_RemovesFramesTrackerListener() {
         fixture.enablePerformanceV2 = true
 
-        startApp()
+        startApp(callDisplayLink: true)
 
         advanceTime(bySeconds: 0.05)
         fixture.displayLinkWrapper.normalFrame()
@@ -358,7 +357,7 @@ class SentryAppStartTrackerTests: NotificationCenterTestCase {
         advanceTime(bySeconds: 0.3)
     }
 
-    private func startApp(processStartTimeStamp: Date? = nil, runtimeInitTimestamp: Date? = nil, moduleInitializationTimestamp: Date? = nil) {
+    private func startApp(processStartTimeStamp: Date? = nil, runtimeInitTimestamp: Date? = nil, moduleInitializationTimestamp: Date? = nil, callDisplayLink: Bool = false) {
         givenProcessStartTimestamp(processStartTimestamp: processStartTimeStamp)
 
         sut = fixture.sut
@@ -375,8 +374,12 @@ class SentryAppStartTrackerTests: NotificationCenterTestCase {
         uiWindowDidBecomeVisible()
         didBecomeActive()
 
-        advanceTime(bySeconds: 0.05)
-        fixture.displayLinkWrapper.normalFrame()
+        if callDisplayLink {
+            advanceTime(bySeconds: 0.05)
+            fixture.currentDate.driftTimeForEveryRead = true
+            fixture.displayLinkWrapper.normalFrame()
+            fixture.currentDate.driftTimeForEveryRead = false
+        }
     }
 
     private func hybridAppStart() {

diff --git a/Tests/SentryTests/Integrations/Performance/FramesTracking/SentryFramesTrackerTests.swift b/Tests/SentryTests/Integrations/Performance/FramesTracking/SentryFramesTrackerTests.swift
@@ -517,16 +517,26 @@ class SentryFramesTrackerTests: XCTestCase {
 
         wait(for: [expectation], timeout: 3.0)
     }
-
-    func testAddListener() {
+    
+    func testAddMultipleListeners_AllCalledWithSameDate() {
         let sut = fixture.sut
-        let listener = FrameTrackerListener()
+        let listener1 = FrameTrackerListener()
+        let listener2 = FrameTrackerListener()
         sut.start()
-        sut.add(listener)
+        sut.add(listener1)
+        sut.add(listener2)
+
+        fixture.dateProvider.driftTimeForEveryRead = true
 
         fixture.displayLinkWrapper.normalFrame()
+        var expectedFrameDate = fixture.dateProvider.date()
+        expectedFrameDate.addTimeInterval(-fixture.dateProvider.driftTimeInterval)
 
-        XCTAssertTrue(listener.newFrameReported)
+        expect(listener1.newFrameInvocations.count) == 1
+        expect(listener1.newFrameInvocations.first?.timeIntervalSince1970) == expectedFrameDate.timeIntervalSince1970
+
+        expect(listener2.newFrameInvocations.count) == 1
+        expect(listener2.newFrameInvocations.first?.timeIntervalSince1970) == expectedFrameDate.timeIntervalSince1970
     }
 
     func testRemoveListener() {
@@ -538,7 +548,7 @@ class SentryFramesTrackerTests: XCTestCase {
 
         fixture.displayLinkWrapper.normalFrame()
 
-        XCTAssertFalse(listener.newFrameReported)
+        expect(listener.newFrameInvocations.count) == 0
     }
 
     func testReleasedListener() {
@@ -594,10 +604,11 @@ class SentryFramesTrackerTests: XCTestCase {
 }
 
 private class FrameTrackerListener: NSObject, SentryFramesTrackerListener {
-    var newFrameReported = false
+
+    var newFrameInvocations = Invocations<Date>()
     var callback: (() -> Void)?
-    func framesTrackerHasNewFrame() {
-        newFrameReported = true
+    func framesTrackerHasNewFrame(_ newFrameDate: Date) {
+        newFrameInvocations.record(newFrameDate)
         callback?()
     }
 }