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.
getsentry · Aug 16, 2024 · 279351b · 279351b
1 parent 8c4ac55
commit 279351b
Show file tree

Hide file tree

Showing 10 changed files with 510 additions and 211 deletions.
diff --git 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 <stdatomic.h>
+
+#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 <stdatomic.h>
 
 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<id<SentryANRTrackerV2Delegate>> *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,11 +247,13 @@ - (void)clear
 - (void)stop
 {
     @synchronized(threadLock) {
-        SENTRY_LOG_INFO(@"Stopping ANR detection");
+        SENTRY_LOG_INFO(@"Stopping App Hang detection");
         state = kSentryANRTrackerStopping;
     }
 }
 
 @end
 
 NS_ASSUME_NONNULL_END
+
+#endif // SENTRY_HAS_UIKIT
diff --git 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 <SentryOptions+Private.h>
 
 #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 <SentryOptions+Private.h>
 #    import <UIKit/UIKit.h>
-#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<SentryThread *> *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
@@ -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
@@ -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
@@ -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
@@ -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<SentryANRTrackerV2Delegate>)listener;
 
@@ -23,6 +29,9 @@ SENTRY_NO_INIT
 
 @end
 
+/**
+ * The ``SentryANRTrackerV2`` calls the methods from background threads.
+ */
 @protocol SentryANRTrackerV2Delegate <NSObject>
 
 - (void)anrDetected;
@@ -32,3 +41,5 @@ SENTRY_NO_INIT
 @end
 
 NS_ASSUME_NONNULL_END
+
+#endif // SENTRY_HAS_UIKIT