fix: Wrong Frame Delay when becoming active

philipphofmann · philipphofmann · commit 33d75f93bcd1 · 2025-10-08T06:43:12.000+02:00
The SDK reported false frame delay statistics when it moved from the background to the foreground, which also led to falsely reported app hangs. Fixes GH-6345
diff --git a/CHANGELOG.md b/CHANGELOG.md
@@ -18,6 +18,7 @@
 
 - Fixes warnings about minimum OS version being lower than Xcode supported version (#5591)
 - Fix rendering method for fast view rendering (#6360)
+- Fix wrong Frame Delay when becoming active, which lead to false reported app hangs when the app moves to the foreground after being in the background (#6381)
 
 ## 8.56.2
 
diff --git a/Sources/Sentry/SentryDelayedFramesTracker.m b/Sources/Sentry/SentryDelayedFramesTracker.m
@@ -28,11 +28,22 @@ - (instancetype)initWithKeepDelayedFramesDuration:(CFTimeInterval)keepDelayedFra
     if (self = [super init]) {
         _keepDelayedFramesDuration = keepDelayedFramesDuration;
         _dateProvider = dateProvider;
-        [self resetDelayedFramesTimeStamps];
+        [self reset];
     }
     return self;
 }
 
+- (void)reset
+{
+    _delayedFrames = [NSMutableArray array];
+    _previousFrameSystemTimestamp = 0;
+    SentryDelayedFrame *initialFrame =
+        [[SentryDelayedFrame alloc] initWithStartTimestamp:[self.dateProvider systemTime]
+                                          expectedDuration:0
+                                            actualDuration:0];
+    [_delayedFrames addObject:initialFrame];
+}
+
 - (void)setPreviousFrameSystemTimestamp:(uint64_t)previousFrameSystemTimestamp
     SENTRY_DISABLE_THREAD_SANITIZER("We don't want to synchronize the access to this property to "
                                     "avoid slowing down the main thread.")
@@ -47,16 +58,6 @@ - (uint64_t)getPreviousFrameSystemTimestamp SENTRY_DISABLE_THREAD_SANITIZER(
     return _previousFrameSystemTimestamp;
 }
 
-- (void)resetDelayedFramesTimeStamps
-{
-    _delayedFrames = [NSMutableArray array];
-    SentryDelayedFrame *initialFrame =
-        [[SentryDelayedFrame alloc] initWithStartTimestamp:[self.dateProvider systemTime]
-                                          expectedDuration:0
-                                            actualDuration:0];
-    [_delayedFrames addObject:initialFrame];
-}
-
 - (void)recordDelayedFrame:(uint64_t)startSystemTimestamp
     thisFrameSystemTimestamp:(uint64_t)thisFrameSystemTimestamp
             expectedDuration:(CFTimeInterval)expectedDuration
diff --git a/Sources/Sentry/SentryFramesTracker.m b/Sources/Sentry/SentryFramesTracker.m
@@ -104,7 +104,7 @@ - (void)resetFrames
     [self resetProfilingTimestampsInternal];
 #    endif // SENTRY_TARGET_PROFILING_SUPPORTED
 
-    [self.delayedFramesTracker resetDelayedFramesTimeStamps];
+    [self.delayedFramesTracker reset];
 }
 
 #    if SENTRY_TARGET_PROFILING_SUPPORTED
@@ -164,6 +164,7 @@ - (void)unpause
     }
 
     _isRunning = YES;
+
     // Reset the previous frame timestamp to avoid wrong metrics being collected
     self.previousFrameTimestamp = SentryPreviousFrameInitialValue;
     [_displayLinkWrapper linkWithTarget:self selector:@selector(displayLinkCallback)];
@@ -320,6 +321,11 @@ - (void)removeListener:(id<SentryFramesTrackerListener>)listener
 - (void)pause
 {
     _isRunning = NO;
+
+    // When the frames tracker is paused, we must reset the delayed frames tracker since accurate
+    // frame delay statistics cannot be provided, as we can't account for events during the pause.
+    [self.delayedFramesTracker reset];
+
     [self.displayLinkWrapper invalidate];
 }
 
@@ -332,7 +338,6 @@ - (void)stop
     _isStarted = NO;
 
     [self pause];
-    [self.delayedFramesTracker resetDelayedFramesTimeStamps];
 
     // Remove the observers with the most specific detail possible, see
     // https://developer.apple.com/documentation/foundation/nsnotificationcenter/1413994-removeobserver
diff --git a/Sources/Sentry/include/SentryDelayedFramesTracker.h b/Sources/Sentry/include/SentryDelayedFramesTracker.h
@@ -21,15 +21,15 @@ SENTRY_NO_INIT
 - (instancetype)initWithKeepDelayedFramesDuration:(CFTimeInterval)keepDelayedFramesDuration
                                      dateProvider:(id<SentryCurrentDateProvider>)dateProvider;
 
-- (void)resetDelayedFramesTimeStamps;
-
 - (void)recordDelayedFrame:(uint64_t)startSystemTimestamp
     thisFrameSystemTimestamp:(uint64_t)thisFrameSystemTimestamp
             expectedDuration:(CFTimeInterval)expectedDuration
               actualDuration:(CFTimeInterval)actualDuration;
 
 - (void)setPreviousFrameSystemTimestamp:(uint64_t)previousFrameSystemTimestamp;
 
+- (void)reset;
+
 /**
  * This method returns the duration of all delayed frames between startSystemTimestamp and
  * endSystemTimestamp.
diff --git a/Tests/SentryTests/Integrations/Performance/FramesTracking/SentryFramesTrackerTests.swift b/Tests/SentryTests/Integrations/Performance/FramesTracking/SentryFramesTrackerTests.swift
@@ -3,6 +3,9 @@
 @_spi(Private) import SentryTestUtils
 import XCTest
 
+// swiftlint:disable file_length
+// This test class also includes tests for delayed frames calculation which is quite complex.
+
 #if os(iOS) || os(tvOS) || targetEnvironment(macCatalyst)
 class SentryFramesTrackerTests: XCTestCase {
     
@@ -518,7 +521,167 @@ class SentryFramesTrackerTests: XCTestCase {
         let actualFrameDelay = sut.getFramesDelay(startSystemTime, endSystemTimestamp: endSystemTime)
         XCTAssertEqual(actualFrameDelay.delayDuration, -1.0)
     }
-    
+
+    func testGetFramesDelay_WhenMovingFromBackgroundToForeground_BeforeDisplayLinkCalled() {
+        // Arrange
+        let sut = fixture.sut
+        sut.start()
+
+        let displayLink = fixture.displayLinkWrapper
+        displayLink.call()
+        _ = displayLink.slowestSlowFrame()
+
+        let startSystemTime = fixture.dateProvider.systemTime()
+
+        fixture.notificationCenter.post(Notification(name: CrossPlatformApplication.willResignActiveNotification))
+
+        // Simulate app staying in background for 2 seconds
+        fixture.dateProvider.advance(by: 2.0)
+
+        fixture.notificationCenter.post(Notification(name: CrossPlatformApplication.didBecomeActiveNotification))
+        let endSystemTime = fixture.dateProvider.systemTime()
+
+        // Act
+        let actualFrameDelay = sut.getFramesDelay(startSystemTime, endSystemTimestamp: endSystemTime)
+
+        // Assert
+
+        // The frames tracer starts subscribing to the display link when an app moves to the foreground. Since
+        // display link callbacks only occur when a new frame is drawn, it can take a couple of milliseconds
+        // for the first display link callback to occur. We can only calculate frame statistics when having at
+        // least one display link callback, as this marks the start of a new frame.
+        XCTAssertEqual(actualFrameDelay.delayDuration, -1.0, accuracy: 0.0001)
+    }
+
+    func testGetFramesDelay_WhenMovingFromBackgroundToForeground_FirstFrameIsDrawing() {
+        // Arrange
+        let sut = fixture.sut
+        sut.start()
+
+        // Simulate some frames to establish system timestamps
+        let displayLink = fixture.displayLinkWrapper
+        displayLink.call()
+        _ = displayLink.slowestSlowFrame()
+
+        fixture.notificationCenter.post(Notification(name: CrossPlatformApplication.willResignActiveNotification))
+
+        // Simulate app staying in background for 2 seconds
+        fixture.dateProvider.advance(by: 2.0)
+
+        fixture.notificationCenter.post(Notification(name: CrossPlatformApplication.didBecomeActiveNotification))
+
+        displayLink.call()
+
+        let startSystemTime = fixture.dateProvider.systemTime()
+        fixture.dateProvider.advance(by: 0.01)
+        let endSystemTime = fixture.dateProvider.systemTime()
+
+        // Act
+        let frameDelay = sut.getFramesDelay(startSystemTime, endSystemTimestamp: endSystemTime)
+
+        // The first is currently drawn, but it's not delayed yet. Therefore, 0 frame delay.
+        XCTAssertEqual(frameDelay.delayDuration, 0.0, accuracy: 0.0001)
+    }
+
+    func testGetFramesDelay_WhenMovingFromBackgroundToForeground_FirstNormalFrameDrawn() {
+        // Arrange
+        let sut = fixture.sut
+        sut.start()
+
+        // Simulate some frames to establish system timestamps
+        let displayLink = fixture.displayLinkWrapper
+        displayLink.call()
+        _ = displayLink.slowestSlowFrame()
+
+        fixture.notificationCenter.post(Notification(name: CrossPlatformApplication.willResignActiveNotification))
+
+        // Simulate app staying in background for 2 seconds
+        fixture.dateProvider.advance(by: 2.0)
+
+        fixture.notificationCenter.post(Notification(name: CrossPlatformApplication.didBecomeActiveNotification))
+
+        displayLink.call()
+
+        // The delayed frames tracker should also have its previous frame system timestamp reset
+        // This prevents false delay calculations after unpausing
+        let startSystemTime = fixture.dateProvider.systemTime()
+        displayLink.normalFrame()
+        let endSystemTime = fixture.dateProvider.systemTime()
+
+        // Act
+        let frameDelay = sut.getFramesDelay(startSystemTime, endSystemTimestamp: endSystemTime)
+
+        // Assert
+        // Normal frame is drawn, no delay
+        XCTAssertEqual(frameDelay.delayDuration, 0.0, accuracy: 0.0001)
+    }
+
+    func testGetFramesDelay_WhenMovingFromBackgroundToForeground_FirstFrameIsSlow() {
+        // Arrange
+        let sut = fixture.sut
+        sut.start()
+
+        // Simulate some frames to establish system timestamps
+        let displayLink = fixture.displayLinkWrapper
+        displayLink.call()
+        _ = displayLink.slowestSlowFrame()
+
+        fixture.notificationCenter.post(Notification(name: CrossPlatformApplication.willResignActiveNotification))
+
+        // Simulate app staying in background for 2 seconds
+        fixture.dateProvider.advance(by: 2.0)
+
+        fixture.notificationCenter.post(Notification(name: CrossPlatformApplication.didBecomeActiveNotification))
+
+        displayLink.call()
+
+        // The delayed frames tracker should also have its previous frame system timestamp reset
+        // This prevents false delay calculations after unpausing
+        let startSystemTime = fixture.dateProvider.systemTime()
+        _ = displayLink.slowestSlowFrame()
+        let endSystemTime = fixture.dateProvider.systemTime()
+
+        // Act
+        let frameDelay = sut.getFramesDelay(startSystemTime, endSystemTimestamp: endSystemTime)
+
+        let expectedDelay = fixture.displayLinkWrapper.slowestSlowFrameDuration - slowFrameThreshold(fixture.displayLinkWrapper.currentFrameRate.rawValue)
+
+        // Assert
+        XCTAssertEqual(frameDelay.delayDuration, expectedDelay, accuracy: 0.0001)
+    }
+
+    func testGetFramesDelay_WhenMovingFromBackgroundToForeground_DelayBeforeBackgroundNotIncluded() {
+        // Arrange
+        let sut = fixture.sut
+        sut.start()
+
+        // Simulate some frames to establish system timestamps
+        let displayLink = fixture.displayLinkWrapper
+        displayLink.call()
+
+        let startSystemTime = fixture.dateProvider.systemTime()
+
+        _ = displayLink.slowestSlowFrame()
+
+        fixture.notificationCenter.post(Notification(name: CrossPlatformApplication.willResignActiveNotification))
+
+        // Simulate app staying in background for 2 seconds
+        fixture.dateProvider.advance(by: 2.0)
+
+        fixture.notificationCenter.post(Notification(name: CrossPlatformApplication.didBecomeActiveNotification))
+
+        displayLink.call()
+
+        _ = displayLink.slowestSlowFrame()
+        let endSystemTime = fixture.dateProvider.systemTime()
+
+        // Act
+        let frameDelay = sut.getFramesDelay(startSystemTime, endSystemTimestamp: endSystemTime)
+
+        // Assert
+        XCTAssertEqual(frameDelay.delayDuration, -1.0, accuracy: 0.0001)
+    }
+
     func testFrameDelay_GetInfoFromBackgroundThreadWhileAdding() {
         let sut = fixture.sut
         sut.start()
@@ -580,7 +743,7 @@ class SentryFramesTrackerTests: XCTestCase {
         
         wait(for: [expectation], timeout: 3.0)
     }
-    
+
     func testAddMultipleListeners_AllCalledWithSameDate() {
         let sut = fixture.sut
         let listener1 = FrameTrackerListener()
@@ -804,35 +967,6 @@ class SentryFramesTrackerTests: XCTestCase {
         // Should not detect any slow or frozen frames from the pauses
         try assert(slow: 0, frozen: 0, total: 4)
     }
-    
-    func testUnpause_WithDelayedFramesTracker_ResetsPreviousFrameSystemTimestamp() {
-        let sut = fixture.sut
-        sut.start()
-        
-        // Simulate some frames to establish system timestamps
-        fixture.displayLinkWrapper.call()
-        fixture.displayLinkWrapper.normalFrame()
-        
-        // Pause the tracker
-        fixture.notificationCenter.post(Notification(name: CrossPlatformApplication.willResignActiveNotification))
-        
-        // Advance time significantly
-        fixture.dateProvider.advance(by: 5.0)
-        
-        // Unpause the tracker
-        fixture.notificationCenter.post(Notification(name: CrossPlatformApplication.didBecomeActiveNotification))
-        
-        // The delayed frames tracker should also have its previous frame system timestamp reset
-        // This prevents false delay calculations after unpausing
-        let startSystemTime = fixture.dateProvider.systemTime()
-        fixture.dateProvider.advance(by: 0.001)
-        let endSystemTime = fixture.dateProvider.systemTime()
-        
-        let frameDelay = sut.getFramesDelay(startSystemTime, endSystemTimestamp: endSystemTime)
-        
-        // Should not report any delay from the pause period
-        XCTAssertEqual(frameDelay.delayDuration, 0.001, accuracy: 0.0001)
-    }
 
 #if os(iOS) || os(macOS) || targetEnvironment(macCatalyst)
     func testResetProfilingTimestamps_FromBackgroundThread() {
@@ -941,3 +1075,5 @@ private extension SentryFramesTrackerTests {
 }
 
 #endif
+
+// swiftlint:enable file_length
