Improve app hang event accuracy

Bugsnag/Breadcrumbs/BugsnagBreadcrumbs.h

@@ -39,6 +39,8 @@ NS_ASSUME_NONNULL_BEGIN
  */
 - (void)addBreadcrumbWithBlock:(BSGBreadcrumbConfiguration)block;
 
+- (NSArray<BugsnagBreadcrumb *> *)breadcrumbsBeforeDate:(NSDate *)date;
+
 /**
  * Returns the breadcrumb JSON dictionaries stored on disk.
  */

Bugsnag/Breadcrumbs/BugsnagBreadcrumbs.m

@@ -13,6 +13,7 @@
 #import "BSGJSONSerialization.h"
 #import "BSG_KSCrashReportWriter.h"
 #import "BugsnagBreadcrumb+Private.h"
+#import "BugsnagCollections.h"
 #import "BugsnagConfiguration+Private.h"
 #import "BugsnagLogger.h"
 
@@ -62,6 +63,12 @@ - (instancetype)initWithConfiguration:(BugsnagConfiguration *)config {
     return [self loadBreadcrumbsAsDictionaries:NO] ?: @[];
 }
 
+- (NSArray<BugsnagBreadcrumb *> *)breadcrumbsBeforeDate:(nonnull NSDate *)date {
+    return BSGArrayMap(self.breadcrumbs, ^id _Nullable(BugsnagBreadcrumb *crumb) {
+        return [crumb.timestamp compare:date] == NSOrderedAscending ? crumb : nil;
+    });
+}
+
 - (void)addBreadcrumb:(NSString *)breadcrumbMessage {
     [self addBreadcrumbWithBlock:^(BugsnagBreadcrumb *_Nonnull crumb) {
         crumb.message = breadcrumbMessage;

Bugsnag/Client/BugsnagClient.m

@@ -1224,9 +1224,7 @@ - (void)startAppHangDetector {
     [self.appHangDetector startWithDelegate:self];
 }
 
-- (void)appHangDetectedWithThreads:(nonnull NSArray<BugsnagThread *> *)threads {
-    NSDictionary *systemInfo = [BSG_KSSystemInfo systemInfo];
-
+- (void)appHangDetectedAtDate:(NSDate *)date withThreads:(NSArray<BugsnagThread *> *)threads systemInfo:(NSDictionary *)systemInfo {
     NSString *message = [NSString stringWithFormat:@"The app's main thread failed to respond to an event within %d milliseconds",
                          (int)self.configuration.appHangThresholdMillis];
 
@@ -1243,13 +1241,20 @@ - (void)appHangDetectedWithThreads:(nonnull NSArray<BugsnagThread *> *)threads {
                                     unhandledOverridden:NO
                                               attrValue:nil];
 
+    BugsnagAppWithState *app = [self generateAppWithState:systemInfo];
+
+    BugsnagDeviceWithState *device = [self generateDeviceWithState:systemInfo];
+    device.time = date;
+
+    NSArray<BugsnagBreadcrumb *> *breadcrumbs = [self.breadcrumbs breadcrumbsBeforeDate:date];
+
     self.appHangEvent =
-    [[BugsnagEvent alloc] initWithApp:[self generateAppWithState:systemInfo]
-                               device:[self generateDeviceWithState:systemInfo]
+    [[BugsnagEvent alloc] initWithApp:app
+                               device:device
                          handledState:handledState
                                  user:self.configuration.user
                              metadata:[self.metadata deepCopy]
-                          breadcrumbs:self.breadcrumbs.breadcrumbs ?: @[]
+                          breadcrumbs:breadcrumbs
                                errors:@[error]
                               threads:threads
                               session:self.sessionTracker.runningSession];

Bugsnag/Helpers/BSGAppHangDetector.h

@@ -28,7 +28,7 @@ NS_ASSUME_NONNULL_BEGIN
 
 @property (readonly) BugsnagConfiguration *configuration;
 
-- (void)appHangDetectedWithThreads:(NSArray<BugsnagThread *> *)threads;
+- (void)appHangDetectedAtDate:(NSDate *)date withThreads:(NSArray<BugsnagThread *> *)threads systemInfo:(NSDictionary *)systemInfo;
 
 - (void)appHangEnded;
 

Bugsnag/Helpers/BSGAppHangDetector.m

@@ -13,6 +13,7 @@
 
 #import "BSG_KSCrashState.h"
 #import "BSG_KSMach.h"
+#import "BSG_KSSystemInfo.h"
 #import "BugsnagCollections.h"
 #import "BugsnagLogger.h"
 #import "BugsnagThread+Recording.h"
@@ -82,20 +83,26 @@ - (void)startWithDelegate:(id<BSGAppHangDetectorDelegate>)delegate {
             dispatch_time_t timeout = dispatch_time(now, (int64_t)(threshold * NSEC_PER_SEC));
             dispatch_after(after, backgroundQueue, ^{
                 if (dispatch_semaphore_wait(semaphore, timeout) != 0) {
-                    if (!bsg_kscrashstate_currentState()->applicationIsInForeground) {
-                        bsg_log_debug(@"Ignoring app hang because app is in the background");
+                    if (bsg_ksmachisBeingTraced()) {
+                        bsg_log_debug("Ignoring app hang because debugger is attached");
                         dispatch_semaphore_wait(semaphore, DISPATCH_TIME_FOREVER);
                         return;
                     }
 
-                    if (bsg_ksmachisBeingTraced()) {
-                        bsg_log_debug("Ignoring app hang because debugger is attached");
+                    if (!bsg_kscrashstate_currentState()->applicationIsInForeground) {
+                        bsg_log_debug(@"Ignoring app hang because app is in the background");
                         dispatch_semaphore_wait(semaphore, DISPATCH_TIME_FOREVER);
                         return;
                     }
 
                     bsg_log_info("App hang detected");
 
+                    // Record the date and state before performing any operations like symbolication or loading
+                    // breadcrumbs from disk that could introduce delays and lead to misleading event contents.
+
+                    NSDate *date = [NSDate date];
+                    NSDictionary *systemInfo = [BSG_KSSystemInfo systemInfo];
+
                     NSArray<BugsnagThread *> *threads = nil;
                     if (recordAllThreads) {
                         threads = [BugsnagThread allThreads:YES callStackReturnAddresses:NSThread.callStackReturnAddresses];
@@ -110,7 +117,7 @@ - (void)startWithDelegate:(id<BSGAppHangDetectorDelegate>)delegate {
 
                     __strong typeof(weakDelegate) strongDelegate = weakDelegate;
 
-                    [strongDelegate appHangDetectedWithThreads:threads];
+                    [strongDelegate appHangDetectedAtDate:date withThreads:threads systemInfo:systemInfo];
 
                     dispatch_semaphore_wait(semaphore, DISPATCH_TIME_FOREVER);
                     bsg_log_info("App hang has ended");

CHANGELOG.md

@@ -1,6 +1,13 @@
 Changelog
 =========
 
+## TBD
+
+### Bug fixes
+
+* Improve accuracy of app hang event information to better reflect state at time of detection.
+  [#1118](https://github.com/bugsnag/bugsnag-cocoa/pull/1118)
+
 ## 6.9.5 (2021-06-09)
 
 ### Bug fixes

Tests/BugsnagBreadcrumbsTest.m

@@ -264,6 +264,15 @@ - (void)testConvertBreadcrumbTypeFromString {
     XCTAssertEqual(BSGBreadcrumbTypeManual, BSGBreadcrumbTypeFromString(@"4"));
 }
 
+- (void)testBreadcrumbsBeforeDate {
+    [self.crumbs removeAllBreadcrumbs];
+    [self.crumbs addBreadcrumb:@"Crumb 1"];
+    [self.crumbs addBreadcrumb:@"Crumb 2"];
+    [self.crumbs addBreadcrumb:@"Crumb 3"];
+    XCTAssertEqual([self.crumbs breadcrumbsBeforeDate:[NSDate date]].count, 3);
+    XCTAssertEqual([self.crumbs breadcrumbsBeforeDate:[NSDate distantPast]].count, 0);
+}
+
 - (void)testBreadcrumbFromDict {
     XCTAssertNil([BugsnagBreadcrumb breadcrumbFromDict:@{}]);
     XCTAssertNil([BugsnagBreadcrumb breadcrumbFromDict:@{@"metadata": @{}}]);

Tests/BugsnagClientMirrorTest.m

@@ -121,12 +121,14 @@ - (void)setUp {
             @"systemState @16@0:8",
             @"setSystemState: v24@0:8@16",
             @"addAutoBreadcrumbForEvent: v24@0:8@16",
-            @"appHangDetectedWithThreads: v24@0:8@16",
+            @"appHangDetectedAtDate:withThreads:systemInfo: v40@0:8@16@24@32",
             @"appHangDetector @16@0:8",
             @"appHangEnded v16@0:8",
             @"appHangEvent @16@0:8",
             @"appLaunchTimer @16@0:8",
             @"appLaunchTimerFired: v24@0:8@16",
+            @"autoNotify B16@0:8",
+            @"autoNotify c16@0:8",
             @"configMetadataFile @16@0:8",
             @"configMetadataFromLastLaunch @16@0:8",
             @"eventFromLastLaunch @16@0:8",
@@ -141,6 +143,8 @@ - (void)setUp {
             @"setAppHangDetector: v24@0:8@16",
             @"setAppHangEvent: v24@0:8@16",
             @"setAppLaunchTimer: v24@0:8@16",
+            @"setAutoNotify: v20@0:8B16",
+            @"setAutoNotify: v20@0:8c16",
             @"setConfigMetadataFromLastLaunch: v24@0:8@16",
             @"setEventFromLastLaunch: v24@0:8@16",
             @"setEventUploader: v24@0:8@16",
@@ -153,10 +157,6 @@ - (void)setUp {
             @"startAppHangDetector v16@0:8",
             @"stateMetadataFile @16@0:8",
             @"stateMetadataFromLastLaunch @16@0:8",
-            @"autoNotify B16@0:8",
-            @"autoNotify c16@0:8",
-            @"setAutoNotify: v20@0:8B16",
-            @"setAutoNotify: v20@0:8c16"
     ]];
 
     // the following methods are implemented on Bugsnag but do not need to

features/app_hangs.feature

@@ -80,6 +80,11 @@ Feature: App hangs
     And the error payload field "events.0.app.durationInForeground" is a number
     And the error payload field "events.0.app.inForeground" is not null
 
+    # Breadcrumbs
+
+    And the error payload field "events.0.breadcrumbs" is an array with 1 elements
+    And the error payload field "events.0.breadcrumbs.0.name" equals "This breadcrumb was left during the hang, before detection"
+
   Scenario: App hangs below the threshold should not be reported
     When I set the app to "1.8" mode
     And I run "AppHangScenario"

features/fixtures/shared/scenarios/AppHangScenarios.swift

@@ -14,14 +14,22 @@ class AppHangScenario: Scenario {
 
     override func startBugsnag() {
         config.appHangThresholdMillis = 2_000
+        config.enabledBreadcrumbTypes = [.user]
         super.startBugsnag()
     }
 
     override func run() {
         Bugsnag.setContext("App Hang Scenario")
         let timeInterval = TimeInterval(eventMode!)!
         NSLog("Simulating an app hang of \(timeInterval) seconds...")
-        Thread.sleep(forTimeInterval: timeInterval)
+        if timeInterval > 2 {
+            Thread.sleep(forTimeInterval: 1.5)
+            Bugsnag.leaveBreadcrumb(withMessage: "This breadcrumb was left during the hang, before detection")
+            Thread.sleep(forTimeInterval: timeInterval - 1.5)
+        } else {
+            Thread.sleep(forTimeInterval: timeInterval)
+        }
+        Bugsnag.leaveBreadcrumb(withMessage: "This breadcrumb was left after the hang")
         NSLog("Finished sleeping")
     }
 }