Instantly share code, notes, and snippets.

Embed
What would you like to do?
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

This comment has been minimized.

Owner

jspahrsummers commented Jan 28, 2015

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

This comment has been minimized.

dbachrach commented Jan 30, 2015

@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

This comment has been minimized.

yaozhuoyu commented Jan 31, 2015

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

@derpoliuk

This comment has been minimized.

derpoliuk commented Jan 31, 2015

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

@fabb

This comment has been minimized.

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

This comment has been minimized.

derpoliuk commented Jan 31, 2015

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

@hossein1448

This comment has been minimized.

hossein1448 commented Feb 1, 2015

@dbachrach did you solve the problem?

@dbachrach

This comment has been minimized.

dbachrach commented Feb 1, 2015

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

@hossein1448

This comment has been minimized.

hossein1448 commented Feb 2, 2015

@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

This comment has been minimized.

fabb commented Feb 3, 2015

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

@johnboiles

This comment has been minimized.

johnboiles commented Feb 3, 2015

@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

This comment has been minimized.

dbachrach commented Feb 3, 2015

(doh) Thanks @johnboiles

@openaphid

This comment has been minimized.

openaphid commented Feb 4, 2015

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

This comment has been minimized.

hossein1448 commented Feb 5, 2015

@johnboiles thanks

@wisonlin

This comment has been minimized.

wisonlin commented Mar 10, 2015

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

@YogevSitton

This comment has been minimized.

YogevSitton commented Apr 1, 2015

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