This afternoon, I had to debug an issue that involved performSelectorOnMainThread:. This method is a great way to get a background thread to safely interact with the user interface. But when you set a breakpoint or crash nested down in one of these method calls, sometimes it’s useful to get a backtrace of who called performSelectorOnMainThread:. Unfortunately, by the time our method gets called, we don’t have that information. The same goes for performSelector:withObject:afterDelay:.

After some good suggestions on Twitter, and a bit of casual recreational coding, I’ve come up with a general purpose solution that involves, of course, method swizzling.

Take this code in an application delegate as an example:

- (void)applicationDidFinishLaunching:(NSNotification *)aNotification
    dispatch_async(dispatch_get_global_queue(0, 0), ^{
        [self performSelectorOnMainThread:@selector(echo:) withObject:@"foo" waitUntilDone:NO];
    [self performSelector:@selector(echo:) withObject:@"bar" afterDelay:3.0];

- (void)echo:(id)object
    NSLog(@"echo: %@", object);

If you set a breakpoint in the echo: method, you’ll see a backtrace like:

(gdb) bt
#0  -[PerformDebugAppDelegate echo:] (self=0x10012c480, _cmd=0x100002462, object=0x1000030e8) at /Users/dave/Desktop/PerformDebug/PerformDebugAppDelegate.m:42
#1  0x00007fff83500647 in __NSThreadPerformPerform ()
#2  0x00007fff80477271 in __CFRunLoopDoSources0 ()
#3  0x00007fff80475469 in __CFRunLoopRun ()
#4  0x00007fff80474c2f in CFRunLoopRunSpecific ()
#5  0x00007fff8101ea4e in RunCurrentEventLoopInMode ()
#6  0x00007fff8101e7b1 in ReceiveNextEventCommon ()
#7  0x00007fff8101e70c in BlockUntilNextEventMatchingListInMode ()
#8  0x00007fff870b21f2 in _DPSNextEvent ()
#9  0x00007fff870b1b41 in -[NSApplication nextEventMatchingMask:untilDate:inMode:dequeue:] ()
#10 0x00007fff87077747 in -[NSApplication run] ()
#11 0x00007fff87070468 in NSApplicationMain ()
#12 0x0000000100001a09 in main (argc=1, argv=0x7fff5fbff1f0) at /Users/dave/Desktop/PerformDebug/main.m:29

This really isn’t all that helpful. Yes, echo: was called, but we don’t know who called it. If echo: is a method that tends to get called from a number of places with a performSelector... variant, we don’t know which one it is.

This afternoon, I took the easy way out, and set an auto-continuing breakpoint on -[NSObject performSelector:onThread:withObject:waitUntilDone:modes:] with a bt action. This isn’t ideal, though. First, this method gets called quite a bit, so hitting the breakpoint can slow things down a lot. Plus, it dumps the stack trace for each call, cluttering the gdb console with mostly useless garbage.

The breakpoint actually helped me debug the issue today, but I’ve run into this situation a number of times in the past and never had a good way to debug it. Until now.

Swizzling for Fun and Profit

The key is to swizzle the NSObject implementations of these two methods:

  • performSelector:withObject:afterDelay:inModes:
  • performSelector:onThread:withObject:waitUntilDone:modes:

In our swizzled implementations, we’d like to capture the backtrace at time they are called. Later, we can dump out the backtrace for debugging, if we want to. To do this, we’ll create an intermediate object to hold the backtrace: DDPerformDebugger. Here are its two most important methods:

- (id)initWithTarget:(id)target selector:(SEL)selector argument:(id)argument;
    self = [super init];
    if (self == nil)
        return nil;
    _target = [target retain];
    _selector = selector;
    _argument = [argument retain];
    // Capture a backtrace at the time we're created
    _frames = backtrace(_callstack, sizeof(_callstack)/sizeof(*_callstack));
    return self;

- (void)perform;
    [_target performSelector:_selector withObject:_argument];

In the initializer, we capture the target, selector, and argument. But we also capture a backtrace using the very handy backtrace(3) function.

In our swizzled performSelector..., we create an instance of DDPerformDebugger, but instead of passing the target and selector to the original implementation, we use this instance as the target and perform as the selector. As you can see above, this just forwards it on to the passed in target and selector. However, as I demonstrate below, we’ll have access to the saved backtrace. Here’s what the swizzled method looks like:

- (void)dd_performSelector:(SEL)selector withObject:(id)argument afterDelay:(NSTimeInterval)delay inModes:(NSArray *)modes;
    DDPerformDebugger * debugger = [[DDPerformDebugger alloc] initWithTarget:self
    [debugger autorelease];
    // This calls the original implementation.  It's not recursing.
    [debugger dd_performSelector:@selector(perform)

The swizzled dd_performSelectorOnMainThread:... looks similar. Now, when we stop on our breakpoint in echo:, we get the following backtrace:

(gdb) bt 5
#0  -[PerformDebugAppDelegate echo:] (self=0x10012b170, _cmd=0x100002462, object=0x1000030e8) at /Users/dave/Desktop/PerformDebug/PerformDebugAppDelegate.m:42
#1  0x000000010000207c in -[DDPerformDebugger perform] (self=0x10101ae00, _cmd=0x7fff85a42a1a) at /Users/dave/Desktop/PerformDebug/DDPerformDebugger.m:157
#2  0x00007fff83500647 in __NSThreadPerformPerform ()
#3  0x00007fff80477271 in __CFRunLoopDoSources0 ()
#4  0x00007fff80475469 in __CFRunLoopRun ()
(More stack frames follow...)

This isn’t much help on it’s own. But if we jump to frame 1, where we’re inside the perform method of our intermediate object, we have access to the backtrace of the original calling point. I’ve rigged up the description method to show the backtrace, so it’s easy to get:

(gdb) po self
<DDPerformDebugger 0x10101ae00: target: <PerformDebugAppDelegate 0x10012b170>, selector: <echo:>, argument: <NSCFString 0x1000030e8>
0   PerformDebug                        0x0000000100001f45 -[DDPerformDebugger initWithTarget:selector:argument:] + 268
1   PerformDebug                        0x0000000100001d3c -[NSObject(DDPerformDebugger) dd_performSelector:onThread:withObject:waitUntilDone:modes:] + 99
2   Foundation                          0x00007fff83512d54 -[NSObject(NSThreadPerformAdditions) performSelectorOnMainThread:withObject:waitUntilDone:] + 143
3   PerformDebug                        0x0000000100001b42 __-[PerformDebugAppDelegate applicationDidFinishLaunching:]_block_invoke_1 + 66
4   libSystem.B.dylib                   0x00007fff86eebce8 _dispatch_call_block_and_release + 15
5   libSystem.B.dylib                   0x00007fff86eca279 _dispatch_worker_thread2 + 231
6   libSystem.B.dylib                   0x00007fff86ec9bb8 _pthread_wqthread + 353
7   libSystem.B.dylib                   0x00007fff86ec9a55 start_wqthread + 13

We can see we’re on on a GCD thread inside applicationDidFinishLaunching:. The only downside to the backtrace_symbols(3) function is that it does not utilize debugging information to show line numbers. We just get an offset into the method.

Fortunately, a command line tool called atos(1) can provide us with this information. Given an address, it’ll decode the symbol and line number information. We can even invoke this right from inside gdb:

(gdb) info pid
Inferior has process ID 11017.
(gdb) shell atos -p 11017 0x0000000100001b42
__-[PerformDebugAppDelegate applicationDidFinishLaunching:]_block_invoke_1 (in PerformDebug) (PerformDebugAppDelegate.m:35)

And know we know that performSelectorOnMainThread: was originally called from line 35 of PerformDebugAppDelegate.m. Very helpul!

The full code for DDPerformDebugger is part of my DDFoundation project on BitBucket, but you can grab just the one file on its own and and included it with your project. By default, it does not swizzle anything, so you can compile it in for every build and not worry about taking a performance hit creating those intermediate objects. To enable the swizzling, just set the DDPerformDebug environment variable to YES. Grab a sample project, PerformDebug.tgz, and try it out for yourself.