From 279351bd71f50977087481bb753230dad8353cc0 Mon Sep 17 00:00:00 2001 From: Philipp Hofmann Date: Fri, 16 Aug 2024 08:00:24 +0200 Subject: [PATCH] chore: Logic for full blocking app hangs (#4282) Add SentryFramesDelayResult containing framesContributingToDelayCount, which is the count for the frames that contributed to the frames delay count. This is required for GH-3492. --- Sources/Sentry/SentryANRTrackerV2.m | 131 +++-- .../Sentry/SentryANRTrackingIntegrationV2.m | 43 +- Sources/Sentry/SentryDelayedFramesTracker.m | 6 +- Sources/Sentry/SentryDependencyContainer.m | 44 +- .../HybridPublic/SentryDependencyContainer.h | 2 + Sources/Sentry/include/SentryANRTrackerV2.h | 15 +- .../include/SentryANRTrackingIntegrationV2.h | 11 +- .../SentryFramesDelayResult.swift | 4 +- .../ANR/SentryANRTrackerV2Tests.swift | 462 +++++++++++++----- .../SentryANRTrackingIntegrationV2Tests.swift | 3 + 10 files changed, 510 insertions(+), 211 deletions(-) diff --git a/Sources/Sentry/SentryANRTrackerV2.m b/Sources/Sentry/SentryANRTrackerV2.m index 10a6c75bdac..8526b87a221 100644 --- a/Sources/Sentry/SentryANRTrackerV2.m +++ b/Sources/Sentry/SentryANRTrackerV2.m @@ -1,11 +1,16 @@ #import "SentryANRTrackerV2.h" -#import "SentryCrashWrapper.h" -#import "SentryDependencyContainer.h" -#import "SentryDispatchQueueWrapper.h" -#import "SentryLog.h" -#import "SentrySwift.h" -#import "SentryThreadWrapper.h" -#import + +#if SENTRY_HAS_UIKIT + +# import "SentryCrashWrapper.h" +# import "SentryDependencyContainer.h" +# import "SentryDispatchQueueWrapper.h" +# import "SentryFramesTracker.h" +# import "SentryLog.h" +# import "SentrySwift.h" +# import "SentryThreadWrapper.h" +# import "SentryTime.h" +# import NS_ASSUME_NONNULL_BEGIN @@ -23,6 +28,7 @@ typedef NS_ENUM(NSInteger, SentryANRTrackerState) { @property (nonatomic, strong) SentryDispatchQueueWrapper *dispatchQueueWrapper; @property (nonatomic, strong) SentryThreadWrapper *threadWrapper; @property (nonatomic, strong) NSHashTable> *listeners; +@property (nonatomic, strong) SentryFramesTracker *framesTracker; @property (nonatomic, assign) NSTimeInterval timeoutInterval; @end @@ -36,12 +42,14 @@ - (instancetype)initWithTimeoutInterval:(NSTimeInterval)timeoutInterval crashWrapper:(SentryCrashWrapper *)crashWrapper dispatchQueueWrapper:(SentryDispatchQueueWrapper *)dispatchQueueWrapper threadWrapper:(SentryThreadWrapper *)threadWrapper + framesTracker:(SentryFramesTracker *)framesTracker { if (self = [super init]) { self.timeoutInterval = timeoutInterval; self.crashWrapper = crashWrapper; self.dispatchQueueWrapper = dispatchQueueWrapper; self.threadWrapper = threadWrapper; + self.framesTracker = framesTracker; self.listeners = [NSHashTable weakObjectsHashTable]; threadLock = [[NSObject alloc] init]; state = kSentryANRTrackerNotRunning; @@ -65,13 +73,19 @@ - (void)detectANRs state = kSentryANRTrackerRunning; } - __block atomic_int ticksSinceUiUpdate = 0; - __block BOOL reported = NO; + SentryCurrentDateProvider *dateProvider = SentryDependencyContainer.sharedInstance.dateProvider; + + BOOL reported = NO; NSInteger reportThreshold = 5; NSTimeInterval sleepInterval = self.timeoutInterval / reportThreshold; + uint64_t timeoutIntervalInNanos = timeIntervalToNanoseconds(self.timeoutInterval); - SentryCurrentDateProvider *dateProvider = SentryDependencyContainer.sharedInstance.dateProvider; + uint64_t appHangStoppedInterval = timeIntervalToNanoseconds(sleepInterval * 2); + CFTimeInterval appHangStoppedFrameDelayThreshold + = nanosecondsToTimeInterval(appHangStoppedInterval) * 0.2; + + uint64_t lastAppHangStoppedSystemTime = dateProvider.systemTime - timeoutIntervalInNanos; // Canceling the thread can take up to sleepInterval. while (YES) { @@ -81,51 +95,84 @@ - (void)detectANRs } } - NSDate *blockDeadline = [[dateProvider date] dateByAddingTimeInterval:self.timeoutInterval]; + NSDate *sleepDeadline = [[dateProvider date] dateByAddingTimeInterval:self.timeoutInterval]; + + [self.threadWrapper sleepForTimeInterval:sleepInterval]; + + if (![self.crashWrapper isApplicationInForeground]) { + SENTRY_LOG_DEBUG(@"Ignoring potential app hangs because the app is in the background"); + continue; + } + + // The sleepDeadline should be roughly executed after the timeoutInterval even if there is + // an AppHang. If the app gets suspended this thread could sleep and wake up again. To avoid + // false positives, we don't report AppHangs if the delta is too big. + NSTimeInterval deltaFromNowToSleepDeadline = + [[dateProvider date] timeIntervalSinceDate:sleepDeadline]; - atomic_fetch_add_explicit(&ticksSinceUiUpdate, 1, memory_order_relaxed); + if (deltaFromNowToSleepDeadline >= self.timeoutInterval) { + SENTRY_LOG_DEBUG(@"Ignoring App Hang because the delta is too big: %f.", + deltaFromNowToSleepDeadline); + continue; + } - [self.dispatchQueueWrapper dispatchAsyncOnMainQueue:^{ - atomic_store_explicit(&ticksSinceUiUpdate, 0, memory_order_relaxed); + uint64_t nowSystemTime = dateProvider.systemTime; - if (reported) { - SENTRY_LOG_WARN(@"ANR stopped."); + if (reported) { - // The ANR stopped, don't block the main thread with calling ANRStopped listeners. - // While the ANR code reports an ANR and collects the stack trace, the ANR might - // stop simultaneously. In that case, the ANRs stack trace would contain the - // following code running on the main thread. To avoid this, we offload work to a - // background thread. + uint64_t framesDelayStartSystemTime = nowSystemTime - appHangStoppedInterval; + + SentryFramesDelayResult *framesDelay = + [self.framesTracker getFramesDelay:framesDelayStartSystemTime + endSystemTimestamp:nowSystemTime]; + + if (framesDelay.delayDuration == -1) { + continue; + } + + BOOL appHangStopped = framesDelay.delayDuration < appHangStoppedFrameDelayThreshold; + + if (appHangStopped) { + SENTRY_LOG_DEBUG(@"App hang stopped."); + + // The App Hang stopped, don't block the App Hangs thread or the main thread with + // calling ANRStopped listeners. [self.dispatchQueueWrapper dispatchAsyncWithBlock:^{ [self ANRStopped]; }]; + + lastAppHangStoppedSystemTime = dateProvider.systemTime; + reported = NO; } - reported = NO; - }]; + continue; + } - [self.threadWrapper sleepForTimeInterval:sleepInterval]; + uint64_t lastAppHangLongEnoughInPastThreshold + = lastAppHangStoppedSystemTime + timeoutIntervalInNanos; - // The blockDeadline should be roughly executed after the timeoutInterval even if there is - // an ANR. If the app gets suspended this thread could sleep and wake up again. To avoid - // false positives, we don't report ANRs if the delta is too big. - NSTimeInterval deltaFromNowToBlockDeadline = - [[dateProvider date] timeIntervalSinceDate:blockDeadline]; + if (dateProvider.systemTime < lastAppHangLongEnoughInPastThreshold) { + SENTRY_LOG_DEBUG(@"Ignoring app hang cause one happened recently."); + continue; + } - if (deltaFromNowToBlockDeadline >= self.timeoutInterval) { - SENTRY_LOG_DEBUG( - @"Ignoring ANR because the delta is too big: %f.", deltaFromNowToBlockDeadline); + uint64_t frameDelayStartSystemTime = nowSystemTime - timeoutIntervalInNanos; + + SentryFramesDelayResult *framesDelayForTimeInterval = + [self.framesTracker getFramesDelay:frameDelayStartSystemTime + endSystemTimestamp:nowSystemTime]; + + if (framesDelayForTimeInterval.delayDuration == -1) { continue; } - if (atomic_load_explicit(&ticksSinceUiUpdate, memory_order_relaxed) >= reportThreshold - && !reported) { - reported = YES; + uint64_t framesDelayForTimeIntervalInNanos + = timeIntervalToNanoseconds(framesDelayForTimeInterval.delayDuration); - if (![self.crashWrapper isApplicationInForeground]) { - SENTRY_LOG_DEBUG(@"Ignoring ANR because the app is in the background"); - continue; - } + BOOL isFullyBlocking = framesDelayForTimeInterval.framesContributingToDelayCount == 1; + + if (isFullyBlocking && framesDelayForTimeIntervalInNanos >= timeoutIntervalInNanos) { + SENTRY_LOG_WARN(@"App Hang detected: fully-blocking."); - SENTRY_LOG_WARN(@"ANR detected."); + reported = YES; [self ANRDetected]; } } @@ -200,7 +247,7 @@ - (void)clear - (void)stop { @synchronized(threadLock) { - SENTRY_LOG_INFO(@"Stopping ANR detection"); + SENTRY_LOG_INFO(@"Stopping App Hang detection"); state = kSentryANRTrackerStopping; } } @@ -208,3 +255,5 @@ - (void)stop @end NS_ASSUME_NONNULL_END + +#endif // SENTRY_HAS_UIKIT diff --git a/Sources/Sentry/SentryANRTrackingIntegrationV2.m b/Sources/Sentry/SentryANRTrackingIntegrationV2.m index f738729e328..f1411613a9e 100644 --- a/Sources/Sentry/SentryANRTrackingIntegrationV2.m +++ b/Sources/Sentry/SentryANRTrackingIntegrationV2.m @@ -1,26 +1,26 @@ #import "SentryANRTrackingIntegrationV2.h" -#import "SentryANRTrackerV2.h" -#import "SentryClient+Private.h" -#import "SentryCrashMachineContext.h" -#import "SentryCrashWrapper.h" -#import "SentryDependencyContainer.h" -#import "SentryDispatchQueueWrapper.h" -#import "SentryEvent.h" -#import "SentryException.h" -#import "SentryHub+Private.h" -#import "SentryLog.h" -#import "SentryMechanism.h" -#import "SentrySDK+Private.h" -#import "SentryStacktrace.h" -#import "SentryThread.h" -#import "SentryThreadInspector.h" -#import "SentryThreadWrapper.h" -#import "SentryUIApplication.h" -#import #if SENTRY_HAS_UIKIT + +# import "SentryANRTrackerV2.h" +# import "SentryClient+Private.h" +# import "SentryCrashMachineContext.h" +# import "SentryCrashWrapper.h" +# import "SentryDependencyContainer.h" +# import "SentryDispatchQueueWrapper.h" +# import "SentryEvent.h" +# import "SentryException.h" +# import "SentryHub+Private.h" +# import "SentryLog.h" +# import "SentryMechanism.h" +# import "SentrySDK+Private.h" +# import "SentryStacktrace.h" +# import "SentryThread.h" +# import "SentryThreadInspector.h" +# import "SentryThreadWrapper.h" +# import "SentryUIApplication.h" +# import # import -#endif NS_ASSUME_NONNULL_BEGIN @@ -83,14 +83,13 @@ - (void)anrDetected return; } -#if SENTRY_HAS_UIKIT // If the app is not active, the main thread may be blocked or too busy. // Since there is no UI for the user to interact, there is no need to report app hang. if (SentryDependencyContainer.sharedInstance.application.applicationState != UIApplicationStateActive) { return; } -#endif + SentryThreadInspector *threadInspector = SentrySDK.currentHub.getClient.threadInspector; NSArray *threads = [threadInspector getCurrentThreadsWithStackTrace]; @@ -128,3 +127,5 @@ - (void)anrStopped @end NS_ASSUME_NONNULL_END + +#endif // SENTRY_HAS_UIKIT diff --git a/Sources/Sentry/SentryDelayedFramesTracker.m b/Sources/Sentry/SentryDelayedFramesTracker.m index 52a0a9b436f..d52ed0b7b3a 100644 --- a/Sources/Sentry/SentryDelayedFramesTracker.m +++ b/Sources/Sentry/SentryDelayedFramesTracker.m @@ -118,7 +118,8 @@ - (SentryFramesDelayResult *)getFramesDelay:(uint64_t)startSystemTimestamp slowFrameThreshold:(CFTimeInterval)slowFrameThreshold { SentryFramesDelayResult *cantCalculateFrameDelayReturnValue = - [[SentryFramesDelayResult alloc] initWithDelayDuration:-1.0 framesCount:0]; + [[SentryFramesDelayResult alloc] initWithDelayDuration:-1.0 + framesContributingToDelayCount:0]; if (isRunning == NO) { SENTRY_LOG_DEBUG(@"Not calculating frames delay because frames tracker isn't running."); @@ -207,7 +208,8 @@ - (SentryFramesDelayResult *)getFramesDelay:(uint64_t)startSystemTimestamp } SentryFramesDelayResult *data = - [[SentryFramesDelayResult alloc] initWithDelayDuration:delay framesCount:framesCount]; + [[SentryFramesDelayResult alloc] initWithDelayDuration:delay + framesContributingToDelayCount:framesCount]; return data; } diff --git a/Sources/Sentry/SentryDependencyContainer.m b/Sources/Sentry/SentryDependencyContainer.m index 337d3236533..50256a2ac33 100644 --- a/Sources/Sentry/SentryDependencyContainer.m +++ b/Sources/Sentry/SentryDependencyContainer.m @@ -301,6 +301,32 @@ - (SentryFramesTracker *)framesTracker SENTRY_DISABLE_THREAD_SANITIZER( # endif // SENTRY_HAS_UIKIT } +- (SentryANRTrackerV2 *)getANRTrackerV2:(NSTimeInterval)timeout + SENTRY_DISABLE_THREAD_SANITIZER("double-checked lock produce false alarms") +{ +# if SENTRY_HAS_UIKIT + if (_anrTrackerV2 == nil) { + @synchronized(sentryDependencyContainerLock) { + if (_anrTrackerV2 == nil) { + _anrTrackerV2 = + [[SentryANRTrackerV2 alloc] initWithTimeoutInterval:timeout + crashWrapper:self.crashWrapper + dispatchQueueWrapper:self.dispatchQueueWrapper + threadWrapper:self.threadWrapper + framesTracker:self.framesTracker]; + } + } + } + + return _anrTrackerV2; +# else + SENTRY_LOG_DEBUG( + @"SentryDependencyContainer.getANRTrackerV2 only works with UIKit enabled. Ensure you're " + @"using the right configuration of Sentry that links UIKit."); + return nil; +# endif // SENTRY_HAS_UIKIT +} + - (SentrySwizzleWrapper *)swizzleWrapper SENTRY_DISABLE_THREAD_SANITIZER( "double-checked lock produce false alarms") { @@ -340,24 +366,6 @@ - (SentryANRTracker *)getANRTracker:(NSTimeInterval)timeout return _anrTracker; } -- (SentryANRTrackerV2 *)getANRTrackerV2:(NSTimeInterval)timeout - SENTRY_DISABLE_THREAD_SANITIZER("double-checked lock produce false alarms") -{ - if (_anrTrackerV2 == nil) { - @synchronized(sentryDependencyContainerLock) { - if (_anrTrackerV2 == nil) { - _anrTrackerV2 = - [[SentryANRTrackerV2 alloc] initWithTimeoutInterval:timeout - crashWrapper:self.crashWrapper - dispatchQueueWrapper:self.dispatchQueueWrapper - threadWrapper:self.threadWrapper]; - } - } - } - - return _anrTrackerV2; -} - - (SentryNSProcessInfoWrapper *)processInfoWrapper SENTRY_DISABLE_THREAD_SANITIZER( "double-checked lock produce false alarms") { diff --git a/Sources/Sentry/include/HybridPublic/SentryDependencyContainer.h b/Sources/Sentry/include/HybridPublic/SentryDependencyContainer.h index db68e110ca7..f36e8d2e9e0 100644 --- a/Sources/Sentry/include/HybridPublic/SentryDependencyContainer.h +++ b/Sources/Sentry/include/HybridPublic/SentryDependencyContainer.h @@ -91,7 +91,9 @@ SENTRY_NO_INIT #endif // !TARGET_OS_WATCH - (SentryANRTracker *)getANRTracker:(NSTimeInterval)timeout; +#if SENTRY_UIKIT_AVAILABLE - (SentryANRTrackerV2 *)getANRTrackerV2:(NSTimeInterval)timeout; +#endif // SENTRY_UIKIT_AVAILABLE #if SENTRY_HAS_METRIC_KIT @property (nonatomic, strong) SentryMXManager *metricKitManager API_AVAILABLE( diff --git a/Sources/Sentry/include/SentryANRTrackerV2.h b/Sources/Sentry/include/SentryANRTrackerV2.h index b7bb95dfe57..86417a12e2e 100644 --- a/Sources/Sentry/include/SentryANRTrackerV2.h +++ b/Sources/Sentry/include/SentryANRTrackerV2.h @@ -1,6 +1,11 @@ #import "SentryDefines.h" -@class SentryOptions, SentryCrashWrapper, SentryDispatchQueueWrapper, SentryThreadWrapper; +#if SENTRY_HAS_UIKIT + +@class SentryCrashWrapper; +@class SentryDispatchQueueWrapper; +@class SentryThreadWrapper; +@class SentryFramesTracker; NS_ASSUME_NONNULL_BEGIN @@ -12,7 +17,8 @@ SENTRY_NO_INIT - (instancetype)initWithTimeoutInterval:(NSTimeInterval)timeoutInterval crashWrapper:(SentryCrashWrapper *)crashWrapper dispatchQueueWrapper:(SentryDispatchQueueWrapper *)dispatchQueueWrapper - threadWrapper:(SentryThreadWrapper *)threadWrapper; + threadWrapper:(SentryThreadWrapper *)threadWrapper + framesTracker:(SentryFramesTracker *)framesTracker; - (void)addListener:(id)listener; @@ -23,6 +29,9 @@ SENTRY_NO_INIT @end +/** + * The ``SentryANRTrackerV2`` calls the methods from background threads. + */ @protocol SentryANRTrackerV2Delegate - (void)anrDetected; @@ -32,3 +41,5 @@ SENTRY_NO_INIT @end NS_ASSUME_NONNULL_END + +#endif // SENTRY_HAS_UIKIT diff --git a/Sources/Sentry/include/SentryANRTrackingIntegrationV2.h b/Sources/Sentry/include/SentryANRTrackingIntegrationV2.h index 88a27b741ea..cb2afe605e9 100644 --- a/Sources/Sentry/include/SentryANRTrackingIntegrationV2.h +++ b/Sources/Sentry/include/SentryANRTrackingIntegrationV2.h @@ -1,7 +1,10 @@ #import "SentryANRTrackerV2.h" -#import "SentryBaseIntegration.h" -#import "SentrySwift.h" -#import + +#if SENTRY_HAS_UIKIT + +# import "SentryBaseIntegration.h" +# import "SentrySwift.h" +# import NS_ASSUME_NONNULL_BEGIN @@ -16,3 +19,5 @@ static NSString *const SentryANRExceptionTypeV2 = @"App Hanging"; @end NS_ASSUME_NONNULL_END + +#endif // SENTRY_HAS_UIKIT diff --git a/Sources/Swift/Integrations/FramesTracking/SentryFramesDelayResult.swift b/Sources/Swift/Integrations/FramesTracking/SentryFramesDelayResult.swift index e4ace6cacdf..a99fd85a01e 100644 --- a/Sources/Swift/Integrations/FramesTracking/SentryFramesDelayResult.swift +++ b/Sources/Swift/Integrations/FramesTracking/SentryFramesDelayResult.swift @@ -6,8 +6,8 @@ class SentryFramesDelayResult: NSObject { let delayDuration: CFTimeInterval let framesContributingToDelayCount: UInt - init(delayDuration: CFTimeInterval, framesCount: UInt) { + init(delayDuration: CFTimeInterval, framesContributingToDelayCount: UInt) { self.delayDuration = delayDuration - self.framesContributingToDelayCount = framesCount + self.framesContributingToDelayCount = framesContributingToDelayCount } } diff --git a/Tests/SentryTests/Integrations/ANR/SentryANRTrackerV2Tests.swift b/Tests/SentryTests/Integrations/ANR/SentryANRTrackerV2Tests.swift index 57c35133329..bd6bdcabc58 100644 --- a/Tests/SentryTests/Integrations/ANR/SentryANRTrackerV2Tests.swift +++ b/Tests/SentryTests/Integrations/ANR/SentryANRTrackerV2Tests.swift @@ -3,218 +3,427 @@ import SentryTestUtils import XCTest #if os(iOS) || os(tvOS) || targetEnvironment(macCatalyst) -class SentryANRTrackerV2Tests: XCTestCase, SentryANRTrackerV2Delegate { +class SentryANRTrackerV2Tests: XCTestCase { - private var sut: SentryANRTrackerV2! - private var fixture: Fixture! - private var anrDetectedExpectation: XCTestExpectation! - private var anrStoppedExpectation: XCTestExpectation! - private let waitTimeout: TimeInterval = 1.0 - - private class Fixture { - let timeoutInterval: TimeInterval = 5 + private let waitTimeout: TimeInterval = 0.5 + private let timeoutInterval: TimeInterval = 2 + + private func getSut() throws -> (SentryANRTrackerV2, TestCurrentDateProvider, TestDisplayLinkWrapper, TestSentryCrashWrapper, SentryTestThreadWrapper, SentryFramesTracker) { + let currentDate = TestCurrentDateProvider() - let crashWrapper: TestSentryCrashWrapper + let crashWrapper = TestSentryCrashWrapper.sharedInstance() let dispatchQueue = TestSentryDispatchQueueWrapper() let threadWrapper = SentryTestThreadWrapper() - init() { - crashWrapper = TestSentryCrashWrapper.sharedInstance() - SentryDependencyContainer.sharedInstance().dateProvider = currentDate + let displayLinkWrapper = TestDisplayLinkWrapper(dateProvider: currentDate) + + SentryDependencyContainer.sharedInstance().dateProvider = currentDate + + let framesTracker = SentryFramesTracker(displayLinkWrapper: displayLinkWrapper, dateProvider: currentDate, dispatchQueueWrapper: dispatchQueue, notificationCenter: TestNSNotificationCenterWrapper(), keepDelayedFramesDuration: 30) + + framesTracker.start() + + // Add a couple of normal frames, so that querying for frame delay + // has enough data to not return -1. + for _ in 0..<1_000 { + displayLinkWrapper.normalFrame() } + + return (SentryANRTrackerV2( + timeoutInterval: timeoutInterval, + crashWrapper: crashWrapper, + dispatchQueueWrapper: dispatchQueue, + threadWrapper: threadWrapper, + framesTracker: framesTracker), currentDate, displayLinkWrapper, crashWrapper, threadWrapper, framesTracker) } - + override func setUp() { super.setUp() - anrDetectedExpectation = expectation(description: "ANR Detection") - anrStoppedExpectation = expectation(description: "ANR Stopped") - anrStoppedExpectation.isInverted = true - - fixture = Fixture() - - sut = SentryANRTrackerV2( - timeoutInterval: fixture.timeoutInterval, - crashWrapper: fixture.crashWrapper, - dispatchQueueWrapper: fixture.dispatchQueue, - threadWrapper: fixture.threadWrapper) + // To avoid spamming the test logs + SentryLog.configure(true, diagnosticLevel: .warning) } override func tearDown() { super.tearDown() - sut.clear() - wait(for: [fixture.threadWrapper.threadFinishedExpectation], timeout: 5) - XCTAssertEqual(0, fixture.threadWrapper.threads.count) - clearTestState() + SentryLog.setTestDefaultLogLevel() } - func start() { - sut.addListener(self) + /// When no frame gets rendered its a fully blocking app hang. + /// + /// [||||--------------] + /// - means no frame rendered + /// | means a rendered frame + func testFullyBlockingAppHang_Reported() throws { + let (sut, currentDate, displayLinkWrapper, _, _, _) = try getSut() + defer { sut.clear() } + + let listener = SentryANRTrackerV2TestDelegate() + sut.addListener(listener) + + // The app must hang for slightly over the timeoutInterval to report an app hang + var advanced = 0.0 + while advanced < timeoutInterval + 0.1 { + advanced += 0.01 + currentDate.advance(by: 0.01) + } + + wait(for: [listener.anrDetectedExpectation], timeout: timeoutInterval) + + renderNormalFramesToStopAppHang(displayLinkWrapper) + + for _ in 0..<20 { + displayLinkWrapper.normalFrame() + } + + wait(for: [listener.anrStoppedExpectation], timeout: waitTimeout) } - func testContinuousANR_OneReported() { - fixture.dispatchQueue.blockBeforeMainBlock = { - self.advanceTime(bySeconds: self.fixture.timeoutInterval) - return false - } - start() + /// For a non fully blocking app hang at least one frame must be rendered during the hang. + /// + /// [||||------|--------] + /// - means no frame rendered + /// | means a rendered frame + func testNonFullyBlockingAppHang_NotReported() throws { + let (sut, _, displayLinkWrapper, _, _, _) = try getSut() + defer { sut.clear() } - wait(for: [anrDetectedExpectation, anrStoppedExpectation], timeout: waitTimeout) + let listener = SentryANRTrackerV2TestDelegate(shouldANRBeDetected: false, shouldStoppedBeCalled: false) + + sut.addListener(listener) + + displayLinkWrapper.frameWith(delay: 1.0) + displayLinkWrapper.normalFrame() + displayLinkWrapper.frameWith(delay: 0.91) + + wait(for: [listener.anrDetectedExpectation], timeout: waitTimeout) + + renderNormalFramesToStopAppHang(displayLinkWrapper) + + wait(for: [listener.anrStoppedExpectation], timeout: waitTimeout) } - func testMultipleListeners() { - fixture.dispatchQueue.blockBeforeMainBlock = { - self.advanceTime(bySeconds: self.fixture.timeoutInterval) - return false + /// [||||------------] + /// - means no frame rendered + /// | means a rendered frame + func testAlmostFullyBlockingAppHang_NoneReported() throws { + let (sut, dateProvider, displayLinkWrapper, _, _, _) = try getSut() + defer { sut.clear() } + + let listener = SentryANRTrackerV2TestDelegate(shouldANRBeDetected: false, shouldStoppedBeCalled: false) + + sut.addListener(listener) + + for _ in 0..<100 { + displayLinkWrapper.normalFrame() } + // The app must hang for slightly over the timeoutInterval to report an app hang + dateProvider.advance(by: timeoutInterval - 0.1) + + wait(for: [listener.anrDetectedExpectation], timeout: waitTimeout) + + renderNormalFramesToStopAppHang(displayLinkWrapper) + + wait(for: [listener.anrStoppedExpectation], timeout: waitTimeout) + } + + /// One fully blocking app hang followed by non fully blocking + /// + /// [||||-----------------|--------] + /// - means no frame rendered + /// | means a rendered frame + func testFullyBlockingFollowedByNonFullyBlocking_OnlyFirstReported() throws { + let (sut, dateProvider, displayLinkWrapper, _, _, _) = try getSut() + defer { sut.clear() } + + let listener = SentryANRTrackerV2TestDelegate() + + sut.addListener(listener) + + dateProvider.advance(by: 2.1) + + wait(for: [listener.anrDetectedExpectation], timeout: waitTimeout) + + displayLinkWrapper.normalFrame() + dateProvider.advance(by: 1.0) + displayLinkWrapper.normalFrame() + dateProvider.advance(by: 1.0) + + renderNormalFramesToStopAppHang(displayLinkWrapper) + + wait(for: [listener.anrStoppedExpectation], timeout: waitTimeout) + } + + /// Fully blocking app hang, app hang stops, again fully blocking app hang + /// + /// [||||-----------------||||||||---------------] + /// - means no frame rendered + /// | means a rendered frame + func testFullyBlockingFollowedByFullyBlocking_BothReported() throws { + let (sut, currentDate, displayLinkWrapper, _, _, _) = try getSut() + defer { sut.clear() } + + // We use multiple listeners here, because we can't reset the XCTestExpectation + let firstListener = SentryANRTrackerV2TestDelegate() + firstListener.anrDetectedExpectation.expectedFulfillmentCount = 2 + firstListener.anrStoppedExpectation.expectedFulfillmentCount = 2 + sut.addListener(firstListener) let secondListener = SentryANRTrackerV2TestDelegate() + secondListener.anrDetectedExpectation.assertForOverFulfill = false + secondListener.anrStoppedExpectation.assertForOverFulfill = false sut.addListener(secondListener) - start() + triggerFullyBlockingAppHang(currentDate) - wait(for: [anrDetectedExpectation, anrStoppedExpectation, secondListener.anrStoppedExpectation, secondListener.anrDetectedExpectation], timeout: waitTimeout) + wait(for: [secondListener.anrDetectedExpectation], timeout: waitTimeout) + + renderNormalFramesToStopAppHang(displayLinkWrapper) + + wait(for: [secondListener.anrStoppedExpectation], timeout: waitTimeout) + + let thirdListener = SentryANRTrackerV2TestDelegate() + sut.addListener(thirdListener) + + triggerFullyBlockingAppHang(currentDate) + + wait(for: [thirdListener.anrDetectedExpectation], timeout: waitTimeout) + + renderNormalFramesToStopAppHang(displayLinkWrapper) + + wait(for: [thirdListener.anrStoppedExpectation], timeout: waitTimeout) + + wait(for: [firstListener.anrDetectedExpectation, firstListener.anrStoppedExpectation], timeout: waitTimeout) } - func testANRButAppInBackground_NoANR() { - anrDetectedExpectation.isInverted = true - fixture.crashWrapper.internalIsApplicationInForeground = false + /// Long fully blocking app hang, app hang stops, no non fully blocking gets falsely reported + /// + /// [||||--------------------------------------|||||||] + /// - means no frame rendered + /// | means a rendered frame + func testFullyBlockingFollowedByNormalFrames_OneReported() throws { + let (sut, currentDate, displayLinkWrapper, _, _, _) = try getSut() + defer { sut.clear() } - fixture.dispatchQueue.blockBeforeMainBlock = { - self.advanceTime(bySeconds: self.fixture.timeoutInterval) - return false - } - start() + let firstListener = SentryANRTrackerV2TestDelegate() + sut.addListener(firstListener) + + let secondListener = SentryANRTrackerV2TestDelegate() + sut.addListener(secondListener) + + triggerFullyBlockingAppHang(currentDate) + triggerFullyBlockingAppHang(currentDate) + triggerFullyBlockingAppHang(currentDate) + + wait(for: [secondListener.anrDetectedExpectation], timeout: waitTimeout) + + let thirdListener = SentryANRTrackerV2TestDelegate(shouldANRBeDetected: false) + sut.addListener(thirdListener) - wait(for: [anrDetectedExpectation, anrStoppedExpectation], timeout: waitTimeout) + renderNormalFramesToStopAppHang(displayLinkWrapper) + + wait(for: [firstListener.anrDetectedExpectation, firstListener.anrStoppedExpectation, thirdListener.anrStoppedExpectation, thirdListener.anrDetectedExpectation], timeout: waitTimeout) } - func testMultipleANRs_MultipleReported() { - anrDetectedExpectation.expectedFulfillmentCount = 3 - let expectedANRStoppedInvocations = 2 - anrStoppedExpectation.isInverted = false - anrStoppedExpectation.expectedFulfillmentCount = expectedANRStoppedInvocations + func testTwoListeners_FullyBlocking_ReportedToBothListeners() throws { + let (sut, currentDate, displayLinkWrapper, _, _, _) = try getSut() + defer { sut.clear() } - fixture.dispatchQueue.blockBeforeMainBlock = { - self.advanceTime(bySeconds: self.fixture.timeoutInterval) - let invocations = self.fixture.dispatchQueue.blockOnMainInvocations.count - if [0, 10, 15, 25].contains(invocations) { - return true - } - - return false - } - start() + let firstListener = SentryANRTrackerV2TestDelegate() + + sut.addListener(firstListener) + + let secondListener = SentryANRTrackerV2TestDelegate() + sut.addListener(secondListener) - wait(for: [anrDetectedExpectation, anrStoppedExpectation], timeout: waitTimeout) - XCTAssertEqual(expectedANRStoppedInvocations, fixture.dispatchQueue.dispatchAsyncInvocations.count) + triggerFullyBlockingAppHang(currentDate) + + wait(for: [firstListener.anrDetectedExpectation, secondListener.anrDetectedExpectation], timeout: waitTimeout) + + renderNormalFramesToStopAppHang(displayLinkWrapper) + + wait(for: [firstListener.anrStoppedExpectation, secondListener.anrStoppedExpectation], timeout: waitTimeout) } - func testAppSuspended_NoANR() { - // To avoid spamming the test logs - SentryLog.configure(true, diagnosticLevel: .error) + func testFullyBlockingAppHang_ButAppInBackground_NoneReported() throws { + let (sut, currentDate, displayLinkWrapper, crashWrapper, _, _) = try getSut() + defer { sut.clear() } + + crashWrapper.internalIsApplicationInForeground = false + + let listener = SentryANRTrackerV2TestDelegate(shouldANRBeDetected: false, shouldStoppedBeCalled: false) + + sut.addListener(listener) + + triggerFullyBlockingAppHang(currentDate) - anrDetectedExpectation.isInverted = true - fixture.dispatchQueue.blockBeforeMainBlock = { - let delta = self.fixture.timeoutInterval * 2 - self.advanceTime(bySeconds: delta) - return false + renderNormalFramesToStopAppHang(displayLinkWrapper) + + wait(for: [listener.anrDetectedExpectation, listener.anrStoppedExpectation], timeout: waitTimeout) + } + + func testAppSuspended_NoAppHang() throws { + let (sut, currentDate, _, _, threadWrapper, _) = try getSut() + defer { sut.clear() } + + let listener = SentryANRTrackerV2TestDelegate(shouldANRBeDetected: false, shouldStoppedBeCalled: false) + + // When the app is suspended the thread sleep can take way longer + // than expected. + threadWrapper.blockWhenSleeping = { + let delta = self.timeoutInterval * 2 + + currentDate.setDate(date: currentDate.date().addingTimeInterval(delta)) } - start() - wait(for: [anrDetectedExpectation, anrStoppedExpectation], timeout: waitTimeout) + sut.addListener(listener) - SentryLog.setTestDefaultLogLevel() + triggerFullyBlockingAppHang(currentDate) + + wait(for: [listener.anrDetectedExpectation, listener.anrStoppedExpectation], timeout: waitTimeout) } - func testRemoveListener_StopsReportingANRs() { - anrDetectedExpectation.isInverted = true + func testRemoveListener_StopsReporting() throws { + let (sut, currentDate, _, _, threadWrapper, _) = try getSut() + defer { sut.clear() } + + let listener = SentryANRTrackerV2TestDelegate(shouldANRBeDetected: false, shouldStoppedBeCalled: false) let mainBlockExpectation = expectation(description: "Main Block") - - fixture.dispatchQueue.blockBeforeMainBlock = { - self.sut.removeListener(self) + + threadWrapper.blockWhenSleeping = { + sut.removeListener(listener) mainBlockExpectation.fulfill() - return true } - start() + triggerFullyBlockingAppHang(currentDate) - wait(for: [anrDetectedExpectation, anrStoppedExpectation, mainBlockExpectation], timeout: waitTimeout) + sut.addListener(listener) + + wait(for: [listener.anrDetectedExpectation, listener.anrStoppedExpectation, mainBlockExpectation], timeout: waitTimeout) } - func testClear_StopsReportingANRs() { - let secondListener = SentryANRTrackerV2TestDelegate() - secondListener.anrDetectedExpectation.isInverted = true - anrDetectedExpectation.isInverted = true + func testClear_StopsReporting() throws { + let (sut, currentDate, _, _, threadWrapper, _) = try getSut() + defer { sut.clear() } + + let firstListener = SentryANRTrackerV2TestDelegate(shouldANRBeDetected: false, shouldStoppedBeCalled: false) + let secondListener = SentryANRTrackerV2TestDelegate(shouldANRBeDetected: false, shouldStoppedBeCalled: false) let mainBlockExpectation = expectation(description: "Main Block") //Having a second Listener may cause the tracker to execute more than once before the end of the test mainBlockExpectation.assertForOverFulfill = false - - fixture.dispatchQueue.blockBeforeMainBlock = { - self.sut.clear() + + threadWrapper.blockWhenSleeping = { + sut.clear() mainBlockExpectation.fulfill() - return true } sut.addListener(secondListener) - start() - wait(for: [anrDetectedExpectation, anrStoppedExpectation, mainBlockExpectation, secondListener.anrStoppedExpectation, secondListener.anrDetectedExpectation], timeout: waitTimeout) - + sut.addListener(firstListener) + + triggerFullyBlockingAppHang(currentDate) + + wait(for: [firstListener.anrDetectedExpectation, firstListener.anrStoppedExpectation, mainBlockExpectation, secondListener.anrStoppedExpectation, secondListener.anrDetectedExpectation], timeout: waitTimeout) } - func testNotRemovingDeallocatedListener_DoesNotRetainListener_AndStopsTracking() { - anrDetectedExpectation.isInverted = true - anrStoppedExpectation.isInverted = true + func testNotRemovingDeallocatedListener_DoesNotRetainListener_AndStopsTracking() throws { + let (sut, currentDate, _, _, _, _) = try getSut() + defer { sut.clear() } + + let listener = SentryANRTrackerV2TestDelegate(shouldANRBeDetected: false, shouldStoppedBeCalled: false) // So ARC deallocates SentryANRTrackerTestDelegate let addListenersCount = 10 func addListeners() { for _ in 0.. XCTAssertGreaterThan(addListenersCount, listeners?.count ?? addListenersCount) - wait(for: [anrDetectedExpectation, anrStoppedExpectation], timeout: 0.0) + wait(for: [listener.anrDetectedExpectation, listener.anrStoppedExpectation], timeout: self.waitTimeout) } - func testClearDirectlyAfterStart() { - anrDetectedExpectation.isInverted = true + func testClearStopsThread() throws { + let (sut, _, _, _, threadWrapper, _) = try getSut() + + sut.addListener(SentryANRTrackerV2TestDelegate()) + + sut.clear() + + wait(for: [threadWrapper.threadFinishedExpectation], timeout: 5) + XCTAssertEqual(0, threadWrapper.threads.count) + } + + func testClearDirectlyAfterStart_FullyBlocking_NotReported() throws { + let (sut, currentDate, _, _, threadWrapper, _) = try getSut() + defer { sut.clear() } + + let listener = SentryANRTrackerV2TestDelegate(shouldANRBeDetected: false, shouldStoppedBeCalled: false) let invocations = 10 for _ in 0..