Skip to content

Instantly share code, notes, and snippets.

@jspahrsummers
Created January 28, 2015 20:50
Show Gist options
  • Save jspahrsummers/419266f5231832602bec to your computer and use it in GitHub Desktop.
Save jspahrsummers/419266f5231832602bec to your computer and use it in GitHub Desktop.
A class for logging excessive blocking on the main thread
/// Observes a run loop to detect any stalling or blocking that occurs.
///
/// This class is thread-safe.
@interface GHRunLoopWatchdog : NSObject
/// Initializes the receiver to watch the specified run loop, using a default
/// stalling threshold.
- (id)initWithRunLoop:(CFRunLoopRef)runLoop;
/// Initializes the receiver to detect when the specified run loop blocks for
/// more than `threshold` seconds.
///
/// This is the designated initializer for this class.
- (id)initWithRunLoop:(CFRunLoopRef)runLoop stallingThreshold:(NSTimeInterval)threshold;
/// Begins watching the receiver's run loop for stalling in the given mode.
///
/// The receiver will automatically stop watching the run loop upon deallocation.
///
/// mode - The mode in which to monitor the specified run loop. Use
/// kCFRunLoopCommonModes to watch all common run loop modes. This should
/// not be NULL.
- (void)startWatchingMode:(CFStringRef)mode;
/// Stops watching the receiver's run loop for stalling in the given mode.
///
/// There is generally no need to invoke this method explicitly.
///
/// mode - The mode in which to monitor the specified run loop. Use
/// kCFRunLoopCommonModes to watch all common run loop modes. This should
/// not be NULL.
- (void)stopWatchingMode:(CFStringRef)mode;
/// A block to invoke any time the run loop stalls.
///
/// duration - The number of seconds that elapsed in the run loop iteration.
@property (copy) void (^didStallWithDuration)(NSTimeInterval duration);
@end
#import "GHRunLoopWatchdog.h"
#include <mach/mach_time.h>
// The default number of seconds that must pass to consider a run loop stalled.
static const NSTimeInterval GHRunLoopWatchdogDefaultStallingThreshold = 0.2;
@interface GHRunLoopWatchdog ()
// The run loop to watch.
//
// Despite being marked `assign`, this property is retained.
@property (nonatomic, assign, readonly) CFRunLoopRef runLoop;
// The observer used to watch the run loop.
//
// Despite being marked `assign`, this property is retained.
@property (nonatomic, assign, readonly) CFRunLoopObserverRef observer;
// The number of seconds that must pass to consider the run loop stalled.
@property (nonatomic, assign, readonly) NSTimeInterval threshold;
// The mach_absolute_time() at which the current run loop iteration was started,
// or 0 if there is no current iteration in progress.
//
// This property is not thread-safe, and must only be accessed from the thread
// that the run loop is associated with.
@property (nonatomic, assign) uint64_t startTime;
// Invoked any time the run loop stalls.
//
// duration - The number of seconds that elapsed in the run loop iteration.
- (void)iterationStalledWithDuration:(NSTimeInterval)duration;
@end
@implementation GHRunLoopWatchdog
#pragma mark Lifecycle
- (id)initWithRunLoop:(CFRunLoopRef)runLoop {
return [self initWithRunLoop:runLoop stallingThreshold:GHRunLoopWatchdogDefaultStallingThreshold];
}
- (id)initWithRunLoop:(CFRunLoopRef)runLoop stallingThreshold:(NSTimeInterval)threshold {
NSParameterAssert(runLoop != NULL);
NSParameterAssert(threshold > 0);
self = [super init];
if (self == nil) return nil;
_runLoop = (CFRunLoopRef)CFRetain(runLoop);
_threshold = threshold;
// Precalculate timebase information.
mach_timebase_info_data_t timebase;
mach_timebase_info(&timebase);
NSTimeInterval secondsPerMachTime = timebase.numer / timebase.denom / 1e9;
@weakify(self);
// Observe at an extremely low order so that we can catch stalling even in
// high-priority operations (like UI redrawing or animation).
_observer = CFRunLoopObserverCreateWithHandler(NULL, kCFRunLoopAllActivities, YES, INT_MIN, ^(CFRunLoopObserverRef observer, CFRunLoopActivity activity) {
@strongify(self);
switch (activity) {
// What we consider one "iteration" might start with any one of
// these events.
case kCFRunLoopEntry:
case kCFRunLoopBeforeTimers:
case kCFRunLoopAfterWaiting:
case kCFRunLoopBeforeSources:
if (self.startTime == 0) self.startTime = mach_absolute_time();
break;
case kCFRunLoopBeforeWaiting:
case kCFRunLoopExit: {
uint64_t endTime = mach_absolute_time();
if (self.startTime <= 0) {
break;
}
uint64_t elapsed = endTime - self.startTime;
NSTimeInterval duration = elapsed * secondsPerMachTime;
if (duration > self.threshold) [self iterationStalledWithDuration:duration];
self.startTime = 0;
break;
}
default:
NSAssert(NO, @"Observer should not have been triggered for activity %i", (int)activity);
}
});
if (_observer == NULL) return nil;
return self;
}
- (void)dealloc {
if (_observer != NULL) {
CFRunLoopObserverInvalidate(_observer);
CFRelease(_observer);
_observer = NULL;
}
if (_runLoop != NULL) {
CFRelease(_runLoop);
_runLoop = NULL;
}
}
#pragma mark Starting and Stopping
- (void)startWatchingMode:(CFStringRef)mode {
NSParameterAssert(mode != NULL);
CFRunLoopAddObserver(self.runLoop, self.observer, mode);
}
- (void)stopWatchingMode:(CFStringRef)mode {
NSParameterAssert(mode != NULL);
CFRunLoopRemoveObserver(self.runLoop, self.observer, mode);
}
#pragma mark Timing
- (void)iterationStalledWithDuration:(NSTimeInterval)duration {
#if DEBUG
NSLog(@"%@: iteration of run loop %p took %.f ms to execute", self, self.runLoop, (double)duration * 1000);
#endif
void (^didStall)(NSTimeInterval) = self.didStallWithDuration;
if (didStall != nil) didStall(duration);
}
@end
@jspahrsummers
Copy link
Author

This was written before CFTypes got managed correctly by ARC, so that's why the property attributes are weird. If it were updated today, it'd use strong properties.

@dbachrach
Copy link

@jspahrsummers what is the intended way to initialize this. I have done:

GHRunLoopWatchdog* watchdog = [[GHRunLoopWatchdog alloc] initWithRunLoop:CFRunLoopGetMain()];
[watchdog startWatchingMode:kCFRunLoopCommonModes];

I put a breakpoint inside the observer and it never is executed. Let me know if you need more info. Thanks.

@yaozhuoyu
Copy link

At 94 line,NSAssert can retain self, so this is a retain cycle.

@derpoliuk
Copy link

@yaozhuoyu How NSAssert(NO, @"Observer should not have been triggered for activity %i", (int)activity); will retain self?

@fabb
Copy link

fabb commented Jan 31, 2015

@derpoliuk NSAssert really captures self, just look at the macro definition. I searched for hours to find that retain cycle in one of my projects.

@derpoliuk
Copy link

@fabb Thank you for response. I should've check NSAssert definition before asking.

@hossein1448
Copy link

@dbachrach did you solve the problem?

@dbachrach
Copy link

@hossein1448 no not yet. Will take a look again tomorrow.

@hossein1448
Copy link

@jspahrsummers:
i try to use and initial GHRunLoopWatchdog in AppDelegate like @dbachrach use it
do i use this right?
I put a breakpoint inside the observer and it never is executed.

@fabb
Copy link

fabb commented Feb 3, 2015

@hossein1448 I put a breakpoint under case kCFRunLoopExit and it breaks fine.

@johnboiles
Copy link

@dbachrach, @hossein1448: don't forget to retain the GHRunLoopWatchdog somewhere or it will get released when it goes out of scope. If you initialize your watchdog in application:didFinishLaunchingWithOptions:, then you might want to create a property on your AppDelegate @property GHRunLoopWatchdog *runLoopWatchdog then initialize it like this:

    self.runLoopWatchdog = [[GHRunLoopWatchdog alloc] initWithRunLoop:CFRunLoopGetMain()];
    [self.runLoopWatchdog startWatchingMode:kCFRunLoopCommonModes];

You can then do this to test that it fires:

    dispatch_after(dispatch_time(DISPATCH_TIME_NOW, (int64_t)(1.0 * NSEC_PER_SEC)), dispatch_get_main_queue(), ^{
        sleep(3);
    });

@dbachrach
Copy link

(doh) Thanks @johnboiles

@openaphid
Copy link

I'm wondering if there's a lightweight way to log what methods are stalling in UI thread. It would be very helpful for occasional stalling issues.

@hossein1448
Copy link

@johnboiles thanks

@wisonlin
Copy link

You may observe kCFRunLoopAfterWaiting and kCFRunLoopBeforeWaiting but not kCFRunLoopBeforeSources and kCFRunLoopExit to detect the blocking.

@YogevSitton-zz
Copy link

This is a great idea - thank you.
I added this to my app and from time to time I see something like:
"<GHRunLoopWatchdog: 0x7faf6343d340>: iteration of run loop 0x7faf6394d230 took 1866 ms to execute"

There are a lot of things going on with the app.
How can I tell which chunk of code (or object) causes this delay?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment