Skip to content

Commit c228d62

Browse files
Merge 33d75f9 into fa9a4bb
2 parents fa9a4bb + 33d75f9 commit c228d62

File tree

5 files changed

+189
-46
lines changed

5 files changed

+189
-46
lines changed

CHANGELOG.md

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -18,6 +18,7 @@
1818

1919
- Fixes warnings about minimum OS version being lower than Xcode supported version (#5591)
2020
- Fix rendering method for fast view rendering (#6360)
21+
- 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)
2122

2223
## 8.56.2
2324

Sources/Sentry/SentryDelayedFramesTracker.m

Lines changed: 12 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -28,11 +28,22 @@ - (instancetype)initWithKeepDelayedFramesDuration:(CFTimeInterval)keepDelayedFra
2828
if (self = [super init]) {
2929
_keepDelayedFramesDuration = keepDelayedFramesDuration;
3030
_dateProvider = dateProvider;
31-
[self resetDelayedFramesTimeStamps];
31+
[self reset];
3232
}
3333
return self;
3434
}
3535

36+
- (void)reset
37+
{
38+
_delayedFrames = [NSMutableArray array];
39+
_previousFrameSystemTimestamp = 0;
40+
SentryDelayedFrame *initialFrame =
41+
[[SentryDelayedFrame alloc] initWithStartTimestamp:[self.dateProvider systemTime]
42+
expectedDuration:0
43+
actualDuration:0];
44+
[_delayedFrames addObject:initialFrame];
45+
}
46+
3647
- (void)setPreviousFrameSystemTimestamp:(uint64_t)previousFrameSystemTimestamp
3748
SENTRY_DISABLE_THREAD_SANITIZER("We don't want to synchronize the access to this property to "
3849
"avoid slowing down the main thread.")
@@ -47,16 +58,6 @@ - (uint64_t)getPreviousFrameSystemTimestamp SENTRY_DISABLE_THREAD_SANITIZER(
4758
return _previousFrameSystemTimestamp;
4859
}
4960

50-
- (void)resetDelayedFramesTimeStamps
51-
{
52-
_delayedFrames = [NSMutableArray array];
53-
SentryDelayedFrame *initialFrame =
54-
[[SentryDelayedFrame alloc] initWithStartTimestamp:[self.dateProvider systemTime]
55-
expectedDuration:0
56-
actualDuration:0];
57-
[_delayedFrames addObject:initialFrame];
58-
}
59-
6061
- (void)recordDelayedFrame:(uint64_t)startSystemTimestamp
6162
thisFrameSystemTimestamp:(uint64_t)thisFrameSystemTimestamp
6263
expectedDuration:(CFTimeInterval)expectedDuration

Sources/Sentry/SentryFramesTracker.m

Lines changed: 7 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -104,7 +104,7 @@ - (void)resetFrames
104104
[self resetProfilingTimestampsInternal];
105105
# endif // SENTRY_TARGET_PROFILING_SUPPORTED
106106

107-
[self.delayedFramesTracker resetDelayedFramesTimeStamps];
107+
[self.delayedFramesTracker reset];
108108
}
109109

110110
# if SENTRY_TARGET_PROFILING_SUPPORTED
@@ -164,6 +164,7 @@ - (void)unpause
164164
}
165165

166166
_isRunning = YES;
167+
167168
// Reset the previous frame timestamp to avoid wrong metrics being collected
168169
self.previousFrameTimestamp = SentryPreviousFrameInitialValue;
169170
[_displayLinkWrapper linkWithTarget:self selector:@selector(displayLinkCallback)];
@@ -320,6 +321,11 @@ - (void)removeListener:(id<SentryFramesTrackerListener>)listener
320321
- (void)pause
321322
{
322323
_isRunning = NO;
324+
325+
// When the frames tracker is paused, we must reset the delayed frames tracker since accurate
326+
// frame delay statistics cannot be provided, as we can't account for events during the pause.
327+
[self.delayedFramesTracker reset];
328+
323329
[self.displayLinkWrapper invalidate];
324330
}
325331

@@ -332,7 +338,6 @@ - (void)stop
332338
_isStarted = NO;
333339

334340
[self pause];
335-
[self.delayedFramesTracker resetDelayedFramesTimeStamps];
336341

337342
// Remove the observers with the most specific detail possible, see
338343
// https://developer.apple.com/documentation/foundation/nsnotificationcenter/1413994-removeobserver

Sources/Sentry/include/SentryDelayedFramesTracker.h

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -21,15 +21,15 @@ SENTRY_NO_INIT
2121
- (instancetype)initWithKeepDelayedFramesDuration:(CFTimeInterval)keepDelayedFramesDuration
2222
dateProvider:(id<SentryCurrentDateProvider>)dateProvider;
2323

24-
- (void)resetDelayedFramesTimeStamps;
25-
2624
- (void)recordDelayedFrame:(uint64_t)startSystemTimestamp
2725
thisFrameSystemTimestamp:(uint64_t)thisFrameSystemTimestamp
2826
expectedDuration:(CFTimeInterval)expectedDuration
2927
actualDuration:(CFTimeInterval)actualDuration;
3028

3129
- (void)setPreviousFrameSystemTimestamp:(uint64_t)previousFrameSystemTimestamp;
3230

31+
- (void)reset;
32+
3333
/**
3434
* This method returns the duration of all delayed frames between startSystemTimestamp and
3535
* endSystemTimestamp.

Tests/SentryTests/Integrations/Performance/FramesTracking/SentryFramesTrackerTests.swift

Lines changed: 167 additions & 31 deletions
Original file line numberDiff line numberDiff line change
@@ -3,6 +3,9 @@
33
@_spi(Private) import SentryTestUtils
44
import XCTest
55

6+
// swiftlint:disable file_length
7+
// This test class also includes tests for delayed frames calculation which is quite complex.
8+
69
#if os(iOS) || os(tvOS) || targetEnvironment(macCatalyst)
710
class SentryFramesTrackerTests: XCTestCase {
811

@@ -518,7 +521,167 @@ class SentryFramesTrackerTests: XCTestCase {
518521
let actualFrameDelay = sut.getFramesDelay(startSystemTime, endSystemTimestamp: endSystemTime)
519522
XCTAssertEqual(actualFrameDelay.delayDuration, -1.0)
520523
}
521-
524+
525+
func testGetFramesDelay_WhenMovingFromBackgroundToForeground_BeforeDisplayLinkCalled() {
526+
// Arrange
527+
let sut = fixture.sut
528+
sut.start()
529+
530+
let displayLink = fixture.displayLinkWrapper
531+
displayLink.call()
532+
_ = displayLink.slowestSlowFrame()
533+
534+
let startSystemTime = fixture.dateProvider.systemTime()
535+
536+
fixture.notificationCenter.post(Notification(name: CrossPlatformApplication.willResignActiveNotification))
537+
538+
// Simulate app staying in background for 2 seconds
539+
fixture.dateProvider.advance(by: 2.0)
540+
541+
fixture.notificationCenter.post(Notification(name: CrossPlatformApplication.didBecomeActiveNotification))
542+
let endSystemTime = fixture.dateProvider.systemTime()
543+
544+
// Act
545+
let actualFrameDelay = sut.getFramesDelay(startSystemTime, endSystemTimestamp: endSystemTime)
546+
547+
// Assert
548+
549+
// The frames tracer starts subscribing to the display link when an app moves to the foreground. Since
550+
// display link callbacks only occur when a new frame is drawn, it can take a couple of milliseconds
551+
// for the first display link callback to occur. We can only calculate frame statistics when having at
552+
// least one display link callback, as this marks the start of a new frame.
553+
XCTAssertEqual(actualFrameDelay.delayDuration, -1.0, accuracy: 0.0001)
554+
}
555+
556+
func testGetFramesDelay_WhenMovingFromBackgroundToForeground_FirstFrameIsDrawing() {
557+
// Arrange
558+
let sut = fixture.sut
559+
sut.start()
560+
561+
// Simulate some frames to establish system timestamps
562+
let displayLink = fixture.displayLinkWrapper
563+
displayLink.call()
564+
_ = displayLink.slowestSlowFrame()
565+
566+
fixture.notificationCenter.post(Notification(name: CrossPlatformApplication.willResignActiveNotification))
567+
568+
// Simulate app staying in background for 2 seconds
569+
fixture.dateProvider.advance(by: 2.0)
570+
571+
fixture.notificationCenter.post(Notification(name: CrossPlatformApplication.didBecomeActiveNotification))
572+
573+
displayLink.call()
574+
575+
let startSystemTime = fixture.dateProvider.systemTime()
576+
fixture.dateProvider.advance(by: 0.01)
577+
let endSystemTime = fixture.dateProvider.systemTime()
578+
579+
// Act
580+
let frameDelay = sut.getFramesDelay(startSystemTime, endSystemTimestamp: endSystemTime)
581+
582+
// The first is currently drawn, but it's not delayed yet. Therefore, 0 frame delay.
583+
XCTAssertEqual(frameDelay.delayDuration, 0.0, accuracy: 0.0001)
584+
}
585+
586+
func testGetFramesDelay_WhenMovingFromBackgroundToForeground_FirstNormalFrameDrawn() {
587+
// Arrange
588+
let sut = fixture.sut
589+
sut.start()
590+
591+
// Simulate some frames to establish system timestamps
592+
let displayLink = fixture.displayLinkWrapper
593+
displayLink.call()
594+
_ = displayLink.slowestSlowFrame()
595+
596+
fixture.notificationCenter.post(Notification(name: CrossPlatformApplication.willResignActiveNotification))
597+
598+
// Simulate app staying in background for 2 seconds
599+
fixture.dateProvider.advance(by: 2.0)
600+
601+
fixture.notificationCenter.post(Notification(name: CrossPlatformApplication.didBecomeActiveNotification))
602+
603+
displayLink.call()
604+
605+
// The delayed frames tracker should also have its previous frame system timestamp reset
606+
// This prevents false delay calculations after unpausing
607+
let startSystemTime = fixture.dateProvider.systemTime()
608+
displayLink.normalFrame()
609+
let endSystemTime = fixture.dateProvider.systemTime()
610+
611+
// Act
612+
let frameDelay = sut.getFramesDelay(startSystemTime, endSystemTimestamp: endSystemTime)
613+
614+
// Assert
615+
// Normal frame is drawn, no delay
616+
XCTAssertEqual(frameDelay.delayDuration, 0.0, accuracy: 0.0001)
617+
}
618+
619+
func testGetFramesDelay_WhenMovingFromBackgroundToForeground_FirstFrameIsSlow() {
620+
// Arrange
621+
let sut = fixture.sut
622+
sut.start()
623+
624+
// Simulate some frames to establish system timestamps
625+
let displayLink = fixture.displayLinkWrapper
626+
displayLink.call()
627+
_ = displayLink.slowestSlowFrame()
628+
629+
fixture.notificationCenter.post(Notification(name: CrossPlatformApplication.willResignActiveNotification))
630+
631+
// Simulate app staying in background for 2 seconds
632+
fixture.dateProvider.advance(by: 2.0)
633+
634+
fixture.notificationCenter.post(Notification(name: CrossPlatformApplication.didBecomeActiveNotification))
635+
636+
displayLink.call()
637+
638+
// The delayed frames tracker should also have its previous frame system timestamp reset
639+
// This prevents false delay calculations after unpausing
640+
let startSystemTime = fixture.dateProvider.systemTime()
641+
_ = displayLink.slowestSlowFrame()
642+
let endSystemTime = fixture.dateProvider.systemTime()
643+
644+
// Act
645+
let frameDelay = sut.getFramesDelay(startSystemTime, endSystemTimestamp: endSystemTime)
646+
647+
let expectedDelay = fixture.displayLinkWrapper.slowestSlowFrameDuration - slowFrameThreshold(fixture.displayLinkWrapper.currentFrameRate.rawValue)
648+
649+
// Assert
650+
XCTAssertEqual(frameDelay.delayDuration, expectedDelay, accuracy: 0.0001)
651+
}
652+
653+
func testGetFramesDelay_WhenMovingFromBackgroundToForeground_DelayBeforeBackgroundNotIncluded() {
654+
// Arrange
655+
let sut = fixture.sut
656+
sut.start()
657+
658+
// Simulate some frames to establish system timestamps
659+
let displayLink = fixture.displayLinkWrapper
660+
displayLink.call()
661+
662+
let startSystemTime = fixture.dateProvider.systemTime()
663+
664+
_ = displayLink.slowestSlowFrame()
665+
666+
fixture.notificationCenter.post(Notification(name: CrossPlatformApplication.willResignActiveNotification))
667+
668+
// Simulate app staying in background for 2 seconds
669+
fixture.dateProvider.advance(by: 2.0)
670+
671+
fixture.notificationCenter.post(Notification(name: CrossPlatformApplication.didBecomeActiveNotification))
672+
673+
displayLink.call()
674+
675+
_ = displayLink.slowestSlowFrame()
676+
let endSystemTime = fixture.dateProvider.systemTime()
677+
678+
// Act
679+
let frameDelay = sut.getFramesDelay(startSystemTime, endSystemTimestamp: endSystemTime)
680+
681+
// Assert
682+
XCTAssertEqual(frameDelay.delayDuration, -1.0, accuracy: 0.0001)
683+
}
684+
522685
func testFrameDelay_GetInfoFromBackgroundThreadWhileAdding() {
523686
let sut = fixture.sut
524687
sut.start()
@@ -580,7 +743,7 @@ class SentryFramesTrackerTests: XCTestCase {
580743

581744
wait(for: [expectation], timeout: 3.0)
582745
}
583-
746+
584747
func testAddMultipleListeners_AllCalledWithSameDate() {
585748
let sut = fixture.sut
586749
let listener1 = FrameTrackerListener()
@@ -804,35 +967,6 @@ class SentryFramesTrackerTests: XCTestCase {
804967
// Should not detect any slow or frozen frames from the pauses
805968
try assert(slow: 0, frozen: 0, total: 4)
806969
}
807-
808-
func testUnpause_WithDelayedFramesTracker_ResetsPreviousFrameSystemTimestamp() {
809-
let sut = fixture.sut
810-
sut.start()
811-
812-
// Simulate some frames to establish system timestamps
813-
fixture.displayLinkWrapper.call()
814-
fixture.displayLinkWrapper.normalFrame()
815-
816-
// Pause the tracker
817-
fixture.notificationCenter.post(Notification(name: CrossPlatformApplication.willResignActiveNotification))
818-
819-
// Advance time significantly
820-
fixture.dateProvider.advance(by: 5.0)
821-
822-
// Unpause the tracker
823-
fixture.notificationCenter.post(Notification(name: CrossPlatformApplication.didBecomeActiveNotification))
824-
825-
// The delayed frames tracker should also have its previous frame system timestamp reset
826-
// This prevents false delay calculations after unpausing
827-
let startSystemTime = fixture.dateProvider.systemTime()
828-
fixture.dateProvider.advance(by: 0.001)
829-
let endSystemTime = fixture.dateProvider.systemTime()
830-
831-
let frameDelay = sut.getFramesDelay(startSystemTime, endSystemTimestamp: endSystemTime)
832-
833-
// Should not report any delay from the pause period
834-
XCTAssertEqual(frameDelay.delayDuration, 0.001, accuracy: 0.0001)
835-
}
836970

837971
#if os(iOS) || os(macOS) || targetEnvironment(macCatalyst)
838972
func testResetProfilingTimestamps_FromBackgroundThread() {
@@ -941,3 +1075,5 @@ private extension SentryFramesTrackerTests {
9411075
}
9421076

9431077
#endif
1078+
1079+
// swiftlint:enable file_length

0 commit comments

Comments
 (0)