Dan Wood: The Eponymous Weblog (Archives)

Dan Wood Dan Wood is co-owner of Karelia Software, creating programs for the Macintosh computer. He is the father of two kids, lives in the Bay Area of California USA, and prefers bicycles to cars. This site is his older weblog, which mostly covers geeky topics like Macs and Mac Programming. Go visit the current blog here.

Useful Tidbits and Egotistical Musings from Dan Wood

Categories: Business · Mac OS X · Cocoa Programming · General · All Categories

Fri, 22 Dec 2006

Class Posing as a useful Debugging Technique

Third past today! Since I just posted a "gripe" entry, I thought I would also post something constructive. I wanted to talk about how cool class posing is for debugging.

We have used class posing quite a few times just to insert some extra warnings for our debug builds. A lot of times, you can catch a nasty condition before it happens and provide some information about what's happening. For instance, if you are only supposed to call a particular method from the main thread, a posed subclass could define your entry points to log an error message if it's being called from a background thread.

For example, I wanted to log some information whenever an NSThread got detached, so I could see where all my application's threads were coming from. So I created a subclass of NSThread called, unimaginatively, MyThread:

@interface MyThread : NSThread
@end

This class has two methods (in an @implementation block, of course). The first is used to force the subclass to be used in place of its parent class:

+ (void) load
{
    [self poseAsClass:[NSThread class]];
}

The second is a redefinition of +[NSThread detachNewThreadSelector: toTarget: withObject:]. It logs some useful information and then calls the "super" implementation to actually do the work. I've simplified my code a bit here but you should get the idea:

+ (void)detachNewThreadSelector:(SEL)selector
                       toTarget:(id)target
                     withObject:(id)argument;
{
    LOG((@"Detach -[%@ %@%@]", target, NSStringFromSelector(selector),
        argument));
    [super detachNewThreadSelector:selector
                          toTarget:target
                        withObject:argument];
}

Generally I don't need this logging to happen, so the code is normally commented out with #ifdef 0. But when I need to know what's going on with threads, this is very helpful.

I've also use this technique to debug my bindings and log each instance of -[NSObject bind:toObject: withKeyPath: options:] and -[NSObject unbind:], all the initialization methods on QTMovie to make sure that the movies are created on the main thread, and so forth.

Things that make it hard to debug

I'm going to channel Andy Rooney for this post. The difference is, you as a reader get to comment, so if I've been living in my debugging cave for so long that I've failed to learn the appropriate debugging techniques, feel free to enlighten me!

Gripe #1: For some reason, Apple's crash catcher isn't noticing crashes in the app I'm working on, if I launch it normally (without XCode). If you don't get the "unexpectedly quit" dialog, then you don't get a crash report. And yet other applications get the crash report and log just fine — Safari crashed on me yesterday and I got the dialog and the log.

Gripe #2:Some crash logs come back with an application version of '???'. They must be launched improperly so that the info.plist is not readable. It's hard to know what version I'm examining in that case!

Gripe #3:Exceptions that were helpfully caught for me without giving me enough context information are really annoying. for instance, check out this thing in a log:

*** NSRunLoop ignoring exception '*** -[NSCFDictionary setObject:
forKey:]: attempt to insert nil value' that raised during posting of
delayed perform with target 181d2ce0 and selector 'processTasks'

.... or ...

Exception raised during posting of notification.  Ignored.  exception:
*** -[NSCFDictionary setHidden:]: selector not recognized
[self = 0x6b95f90]

Yeah, I see that it's somewhere downstream from my method 'processTasks'. But I don't know the dictionary or where it got set.

Gripe #4:Sometimes, symbols in a backtrace are returned to us, and when we look them up on our symbols build with atos, the resulting strings make absolutely no sense. Sometimes.

OK, I'm done griping for now. Back to happy, shiny thoughts of Christmas cheer!

Better description of data

One thing that drives me crazy about debugging in XCode is how the default print-object command invokes debugDescription on an object. Normally this is the same as description, but for certain data objects, it's much less readable than plain old description. OK, it has a bit more information, but it's generally not what I'm looking for and it's formatted so poorly.

What I do in our application is to redefine debugDescription in terms of description for debug builds. (I bracket this code within and #ifdef so it's not built for the release version.) Here's NSDictionary:

@implementation NSDictionary ( OverrideDebug )

- (NSString *)debugDescription
{
    return [self description];
}

@end

I do something similar for NSSet.

Easy enough, right? For NSArray, I've gone a step further by only printing the first 20 or so items in the array. That way an array with thousands of items won't fill up my terminal!

@implementation NSArray ( OverrideDebug )

- (NSString *)debugDescription
{
    #define MAXARRAYSHOW 20
    if ([self count] > MAXARRAYSHOW)
    {
        NSArray *subArray = [self subarrayWithRange:
            NSMakeRange(0,MAXARRAYSHOW)];
        return [NSString stringWithFormat:@"%@ [... %d items]",
                    [subArray description], [self count]];
    }
    else
    {
        return [self description];
    }
}
@end

For NSDictionary, I've gone all out and made a much more useable description. This implementation shows the data in a nicely formatted Hex/ASCII dump that's much more scannable. I also cut it off at 1024 bytes since I don't really want to see much more than this, and I hate to have to wait for a megabyte-long chunk of data to finish displaying.

Note that I've also gone ahead and re-implemented description, not debugDescription, so I always get this new style of display.

@implementation NSData ( description )

- (NSString *)description
{
#define MAXDATABYTES 1024
    unsigned char *bytes = (unsigned char *)[self bytes];
    unsigned length = [self length];
    NSMutableString *buf = [NSMutableString stringWithFormat:
        @"NSData %d bytes:\n", length];
    int i, j;

    for ( i = 0 ; i < length ; i += 16 )
    {
        if (i > MAXDATABYTES)       // don't print too much!
        {
            [buf appendString:@"\n...\n"];
            break;
        }
        for ( j = 0 ; j < 16 ; j++ )    // Show the row in Hex
        {
            int offset = i+j;
            if (offset < length)
            {
                [buf appendFormat:@"%02X ",bytes[offset]];
            }
            else
            {
                [buf appendFormat:@"   "];
            }
        }
        [buf appendString:@"| "];   // now show in ASCII
        for ( j = 0 ; j < 16 ; j++ )
        {
            int offset = i+j;
            if (offset < length)
            {
                unsigned char theChar = bytes[offset];
                if (theChar < 32 || theChar > 127)
                {
                    theChar ='.';
                }
                [buf appendFormat:@"%c", theChar];
            }
        }
        [buf appendString:@"\n"];
    }
    [buf deleteCharactersInRange:NSMakeRange([buf length]-1, 1)];
    return buf;
}
@end

Can anybody think of more improvements to the standard ways out describing objects?