views:

242

answers:

2

Here's the call stack from a user's crash report:

Thread 0 Crashed:  Dispatch queue: com.apple.main-thread
0   com.growl.GrowlSafari           0x179d383c writeWithFormat + 25
1   com.growl.GrowlSafari           0x179d388e writeWithFormat + 107
2   com.growl.GrowlSafari           0x179d388e writeWithFormat + 107
3   com.growl.GrowlSafari           0x179d388e writeWithFormat + 107
4   com.growl.GrowlSafari           0x179d388e writeWithFormat + 107
5   com.growl.GrowlSafari           0x179d388e writeWithFormat + 107

The trace cuts off at frame 511.

Here's writeWithFormat:

int writeWithFormat(FILE *file, NSString *format, ...) {
    va_list args;
    va_start(args, format);
    int written = writeWithFormatAndArgs(file, format, args);
    va_end(args);
    return written;
}

As you can see, it doesn't call itself.

Here's the function it does call:

int writeWithFormatAndArgs(FILE *file, NSString *format, va_list args) {
    return 0;
    return fprintf(file, "%s\n", [[[[NSString alloc] initWithFormat:format arguments:args] autorelease] UTF8String]);
}

(As you can guess, this is logging code that's inactivated.)

So, how does this code result in that stack trace?


Disassembly using otx:

_writeWithFormatAndArgs:
    +0  00000f68  55                    pushl       %ebp
    +1  00000f69  89e5                  movl        %esp,%ebp
    +3  00000f6b  31c0                  xorl        %eax,%eax
    +5  00000f6d  c9                    leave
    +6  00000f6e  c3                    ret

_writeWithFormat:
    +0  00001823  55                    pushl       %ebp
    +1  00001824  89e5                  movl        %esp,%ebp
    +3  00001826  83ec10                subl        $0x10,%esp
    +6  00001829  31c0                  xorl        %eax,%eax
    +8  0000182b  c9                    leave
    +9  0000182c  c3                    ret
+1  A: 

A tail call somewhere in there could be causing one or more functions to disappear from the stack trace which, of course, makes debugging a load of fun.

Off the top of my head, I could think of two possible scenarios that could cause this:

  • the format string is a subclass of NSString or there is a category somewhere that is causing a call through to writeWithFormat() during that writeWithFormat(). Custom logging code will do that sometimes -- it is quite frighteningly easy to write some generic custom logging code that'll happily call back into itself. Been there, done that. Many times, sadly.

  • a perversity in memory is causing the recursion; corrupted object or something.

Both a bit of a grasp at straws. Post the entire crash report.


Two versions of the bundle swizzling the runtime... all bets are off until the crash is reproduced in the face of only one of those bundles. I'd bet that is the problem.

I also bet that there is some related console spew.

bbum
Link to crash report added in first paragraph.
Peter Hosey
+3  A: 

In the full crash report, you can see in the binaries section that the user has two copies of GrowlSafari loaded:

 0x140c000 -  0x140efff +com.growl.GrowlSafari 1.1.6 (1.1.6) <1E774BDF-5CC5-4876-7C66-380EBFEAF190> /Library/InputManagers/GrowlSafari/GrowlSafariLoader.bundle/Contents/PlugIns/GrowlSafari.bundle/Contents/MacOS/GrowlSafari
0x179d2000 - 0x179d4ff7 +com.growl.GrowlSafari 1.2.1 (1.2.1) <10F1EF69-D655-CCEE-DF3A-1F6C0CF541D3> /Applications/GrowlSafari.app/Contents/Resources/GrowlSafari.bundle/Contents/MacOS/GrowlSafari

The code I showed in the question is from 1.2.1 (but there's a good chance it hasn't changed since 1.1.6) and the disassembly is of 1.2.1.

This probably is the cause of the problem, especially as the recursion appears to actually be in a swizzled method (thanks to @_karsten_ on Twitter for pointing this out).

Peter Hosey
@_karsten_ now has this blog post: http://briksoftware.com/blog/?p=130
Yuji
and also Michael Tsai: http://mjtsai.com/blog/2010/07/21/interpreting-crash-logs-with-otx/
Yuji