Create a gist now

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.

Show comment
Hide comment
@jspahrsummers

jspahrsummers 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.

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.

Show comment
Hide comment
@dbachrach

dbachrach 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.

@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.

Show comment
Hide comment
@yaozhuoyu

yaozhuoyu Jan 31, 2015

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

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

@derpoliuk

This comment has been minimized.

Show comment
Hide comment
@derpoliuk

derpoliuk Jan 31, 2015

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

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

@fabb

This comment has been minimized.

Show comment
Hide comment
@fabb

fabb 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.

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.

Show comment
Hide comment
@derpoliuk

derpoliuk Jan 31, 2015

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

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

@hossein1448

This comment has been minimized.

Show comment
Hide comment
@hossein1448

hossein1448 Feb 1, 2015

@dbachrach did you solve the problem?

@dbachrach did you solve the problem?

@dbachrach

This comment has been minimized.

Show comment
Hide comment
@dbachrach

dbachrach Feb 1, 2015

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

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

@hossein1448

This comment has been minimized.

Show comment
Hide comment
@hossein1448

hossein1448 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.

@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.

Show comment
Hide comment
@fabb

fabb Feb 3, 2015

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

fabb commented Feb 3, 2015

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

@johnboiles

This comment has been minimized.

Show comment
Hide comment
@johnboiles

johnboiles 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, @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.

Show comment
Hide comment

(doh) Thanks @johnboiles

@openaphid

This comment has been minimized.

Show comment
Hide comment
@openaphid

openaphid 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.

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.

Show comment
Hide comment
@wisonlin

This comment has been minimized.

Show comment
Hide comment
@wisonlin

wisonlin Mar 10, 2015

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

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

@YogevSitton

This comment has been minimized.

Show comment
Hide comment
@YogevSitton

YogevSitton 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?

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