[Mac] Capture -dealloc backtrace to log with CrZombie messages.

chrome/browser/ui/cocoa/objc_zombie.mm

Index: chrome/browser/ui/cocoa/objc_zombie.mm
diff --git a/chrome/browser/ui/cocoa/objc_zombie.mm b/chrome/browser/ui/cocoa/objc_zombie.mm
index 3e097363e031ed24c1ce2f58e37655ba15e56c52..ff759364bde1b95189050e15df68dd98920fd554 100644
--- a/chrome/browser/ui/cocoa/objc_zombie.mm
+++ b/chrome/browser/ui/cocoa/objc_zombie.mm
@@ -5,11 +5,13 @@
 #import "chrome/browser/ui/cocoa/objc_zombie.h"
 
 #include <dlfcn.h>
+#include <execinfo.h>
 #include <mach-o/dyld.h>
 #include <mach-o/nlist.h>
 
 #import <objc/objc-class.h>
 
+#include "base/debug/stack_trace.h"
 #include "base/logging.h"
 #include "base/mac/mac_util.h"
 #include "base/metrics/histogram.h"
@@ -35,6 +37,12 @@
 
 namespace {
 
+// The depth of backtrace to store with zombies.  This directly influences
+// the amount of memory required to track zombies, so should be kept as
+// small as is useful.  Unfortunately, too small and it won't poke through
+// deep autorelease and event loop stacks.
+static const int kBacktraceDepth = 20;

[Mark Mentovai, 2011/08/27 00:29:02]

Since you’re in an anonymous namespace, the |static| is extraneous.

[Scott Hess - ex-Googler, 2011/08/27 05:15:40]

Done.  Doh.

+
 // Function which destroys the contents of an object without freeing
 // the object.  On 10.5 this is |object_cxxDestruct()|, which
 // traverses the class hierarchy to run the C++ destructors.  On 10.6
@@ -71,6 +79,7 @@ size_t g_zombieIndex = 0;
 typedef struct {
   id object;   // The zombied object.
   Class wasa;  // Value of |object->isa| before we replaced it.
+  void* trace[kBacktraceDepth];  // Backtrace at point of deallocation.

[Mark Mentovai, 2011/08/27 00:29:02]

Wow, zombie memory explosion! How many zombies do we let hang around, again?

[Scott Hess - ex-Googler, 2011/08/27 05:15:40]

10,000 at this time.  From past instrumentation of things, this seems to wire
down about 3M.  This change will add a bit under 1M additional, but the constant
can easily be tuned down if we find that the extra frames aren't providing solid
benefits.  The current depth was chosen by intuition from triaging crashes - 5
is too small, 10 feels borderline, 20 is probably too much, but not way too
much.

 } ZombieRecord;
 
 ZombieRecord* g_zombies = NULL;
@@ -191,7 +200,8 @@ void ZombieDealloc(id self, SEL _cmd) {
 
   // The new record to swap into |g_zombies|.  If |g_zombieCount| is
   // zero, then |self| will be freed immediately.
-  ZombieRecord zombieToFree = {self, wasa};
+  ZombieRecord zombieToFree = {self, wasa, {0}};

[Mark Mentovai, 2011/08/27 00:29:02]

This zeroes the whole trace array out. Do we need that?

[Scott Hess - ex-Googler, 2011/08/27 05:15:40]

We did if I wasn't keeping the count :-).

+  backtrace(zombieToFree.trace, kBacktraceDepth);

[Mark Mentovai, 2011/08/27 00:29:02]

I’d feel much more comfortable if you stored the return value of backtrace (the
number of frames) rather than guessing at it elsewhere. You’re already using 80
extra bytes (32-bit) for the backtrace, what’s 4 more?

[Scott Hess - ex-Googler, 2011/08/27 05:15:40]

OK.  I was mainly thinking in terms of whether we might set the depth to 5 (or
0), but it's reasonable to worry about that when it happens.  I had also
considered whether we might store the backtraces as a separate circular buffer
from the objects, so that it could contain info for fewer zombies, but that
feels kind of scary for now.

 
   // Don't involve the lock when creating zombies without a treadmill.
   if (g_zombieCount > 0) {
@@ -213,23 +223,32 @@ void ZombieDealloc(id self, SEL _cmd) {
     object_dispose(zombieToFree.object);
 }
 
-// Attempt to determine the original class of zombie |object|.
-Class ZombieWasa(id object) {
-  // Fat zombies can hold onto their |wasa| past the point where the
-  // object was actually freed.  Note that to arrive here at all,
-  // |object|'s memory must still be accessible.
-  if (object_getClass(object) == g_fatZombieClass)
-    return static_cast<CrFatZombie*>(object)->wasa;
-
-  // For instances which weren't big enough to store |wasa|, check if
-  // the object is still on the treadmill.
+// Search the treadmill for |object| and fill in |*record| if found.
+// Returns YES if found.
+BOOL GetZombieRecord(id object, ZombieRecord* record) {
+  // Holding the lock is reasonable because this should be fast, and
+  // the process is going to crash presently anyhow.
   base::AutoLock pin(lock_);
   for (size_t i=0; i < g_zombieCount; ++i) {
-    if (g_zombies[i].object == object)
-      return g_zombies[i].wasa;
+    if (g_zombies[i].object == object) {
+      *record = g_zombies[i];
+      return YES;
+    }
   }
+  return NO;
+}
 
-  return Nil;
+// Dump the symbols.  This is pulled out into a function to make it
+// easy to dump only in debug builds.
+BOOL DumpDeallocTrace(const void* const* array, int size) {
+  if (size > 0) {
+    LOG(ERROR) << "Backtrace from -dealloc:";
+    base::debug::StackTrace(array, size).PrintBacktrace();
+  } else {
+    LOG(ERROR) << "Unable to generate backtrace from -dealloc.";
+  }
+
+  return YES;
 }
 
 // Log a message to a freed object.  |wasa| is the object's original
@@ -238,8 +257,19 @@ Class ZombieWasa(id object) {
 // dispatch-related method which is being invoked to send |aSelector|
 // (for instance, -respondsToSelector:).
 void ZombieObjectCrash(id object, SEL aSelector, SEL viaSelector) {
-  Class wasa = ZombieWasa(object);
+  ZombieRecord record;
+  BOOL found = GetZombieRecord(object, &record);
+
+  // The object's class can be in the zombie record, but if that is
+  // not available it can also be in the object itself (in most cases).
+  Class wasa = Nil;
+  if (found) {
+    wasa = record.wasa;
+  } else if (object_getClass(object) == g_fatZombieClass) {
+    wasa = static_cast<CrFatZombie*>(object)->wasa;
+  }
   const char* wasaName = (wasa ? class_getName(wasa) : "<unknown>");
+
   NSString* aString =
       [NSString stringWithFormat:@"Zombie <%s: %p> received -%s",
                                  wasaName, object, sel_getName(aSelector)];
@@ -248,12 +278,37 @@ void ZombieObjectCrash(id object, SEL aSelector, SEL viaSelector) {
     aString = [aString stringByAppendingFormat:@" (via -%s)", viaName];
   }
 
-  // Set a value for breakpad to report, then crash.
+  // Set a value for breakpad to report.
   SetCrashKeyValue(@"zombie", aString);
-  LOG(ERROR) << [aString UTF8String];
+
+  // Hex-encode the backtrace and tuck it into a breakpad key.
+  NSString* deallocTrace = @"<unknown>";

[Mark Mentovai, 2011/08/27 00:29:02]

Nit: remember to use this_style names because you’re not in an Objective-C
@implementation or @interface or @protocol.

[Scott Hess - ex-Googler, 2011/08/27 05:15:40]

OK ... as-is, the file is pretty much Objc-style.  The _ are from the runtime
API and g_.  Not sure where to take that.

+  int realDepth = kBacktraceDepth;
+  if (found) {
+    // Back out items beyond the end of the stack.
+    while (realDepth > 0 && !record.trace[realDepth - 1]) {

[Mark Mentovai, 2011/08/27 00:29:02]

This is what I was talking about before. It’s kind of cheesey.

[Scott Hess - ex-Googler, 2011/08/27 05:15:40]

It's totally cheesy!  Be happy I didn't try to delta-encode the EIP values :-).

+      --realDepth;
+    }
+
+    if (realDepth > 0) {
+      NSMutableArray* hexBacktrace =
+          [NSMutableArray arrayWithCapacity:realDepth];
+      for (int i = 0; i < realDepth; ++i) {
+        NSString* s = [NSString stringWithFormat:@"%p", record.trace[i]];
+        [hexBacktrace addObject:s];
+      }
+      deallocTrace = [hexBacktrace componentsJoinedByString:@" "];
+    }
+  }
+  SetCrashKeyValue(@"zombie_dealloc_bt", deallocTrace);

[Mark Mentovai, 2011/08/27 00:29:02]

Might we also want to record the thread that did the -dealloc?

[Scott Hess - ex-Googler, 2011/08/27 05:15:40]

Hmm.  Hmmmmmmm.  I think I'm willing to leave that for later.  There are some
cases of zombies on other threads, but I can't remember a case where crossing
threads was really relevant to the problem.  That said, pretty much all the
problems we've seen were on the UI thread.

+
+  // Log -dealloc backtrace in debug builds then crash with a useful
+  // stack trace.
+  DCHECK(DumpDeallocTrace(record.trace, realDepth));
+  DLOG(FATAL) << [aString UTF8String];

[Mark Mentovai, 2011/08/27 00:29:02]

This won’t get a chance to DLOG(FATAL) because the DCHECK is already fatal. (Or
am I wrong?)

[Scott Hess - ex-Googler, 2011/08/27 05:15:40]

DumpDeallocTrace() returns YES.  What I want is to say "Do this in debug build,
but get rid of it all in production build" without having to replicate the logic
to do that (and take the chance that the logic would not match the reality). 
This way I'm relying on people who change the logging code consistently changing
everything.

 
   // This is how about:crash is implemented.  Using instead of
-  // |baes::debug::BreakDebugger()| or |LOG(FATAL)| to make the top of
+  // |base::debug::BreakDebugger()| or |LOG(FATAL)| to make the top of
   // stack more immediately obvious in crash dumps.
   int* zero = NULL;
   *zero = 0;