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

chrome/browser/ui/cocoa/objc_zombie.mm

 // Copyright (c) 2011 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #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"
 #include "base/synchronization/lock.h"
 #import "chrome/app/breakpad_mac.h"
 #import "chrome/browser/ui/cocoa/objc_method_swizzle.h"
 
 // Deallocated objects are re-classed as |CrZombie|.  No superclass
 // because then the class would have to override many/most of the
 // inherited methods (|NSObject| is like a category magnet!).
 @interface CrZombie {
   Class isa;
 }
 @end
 
 // Objects with enough space are made into "fat" zombies, which
 // directly remember which class they were until reallocated.
 @interface CrFatZombie : CrZombie {
  @public
   Class wasa;
 }
 @end
 
 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
 // this is |objc_destructInstance()| which calls
 // |object_cxxDestruct()| and removes associative references.
 // |objc_destructInstance()| returns |void*| but pretending it has no
 // return value makes the code simpler.
 typedef void DestructFn(id obj);
 DestructFn* g_objectDestruct = NULL;
 
@@ skipping 16 matching lines @@
 base::Lock lock_;
 
 // How many zombies to keep before freeing, and the current head of
 // the circular buffer.
 size_t g_zombieCount = 0;
 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;
 
 const char* LookupObjcRuntimePath() {
   const void* addr = reinterpret_cast<void*>(&object_getClass);
   Dl_info info;
 
   // |dladdr()| doesn't document how long |info| will stay valid...
   if (dladdr(addr, &info))
@@ skipping 100 matching lines @@
   // be thread-safe in the first place).
   if (size >= g_fatZombieSize) {
     self->isa = g_fatZombieClass;
     static_cast<CrFatZombie*>(self)->wasa = wasa;
   } else {
     self->isa = g_zombieClass;
   }
 
   // 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) {
     base::AutoLock pin(lock_);
 
     // Check the count again in a thread-safe manner.
     if (g_zombieCount > 0) {
       // Put the current object on the treadmill and keep the previous
       // occupant.
       std::swap(zombieToFree, g_zombies[g_zombieIndex]);
 
       // Bump the index forward.
       g_zombieIndex = (g_zombieIndex + 1) % g_zombieCount;
     }
   }
 
   // Do the free out here to prevent any chance of deadlock.
   if (zombieToFree.object)
     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;
+}
+
+// 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 Nil;
+  return YES;
 }
 
 // Log a message to a freed object.  |wasa| is the object's original
 // class.  |aSelector| is the selector which the calling code was
 // attempting to send.  |viaSelector| is the selector of the
 // 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)];
   if (viaSelector != NULL) {
     const char* viaName = sel_getName(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;
 }
 
 // For monitoring failures in |ZombieInit()|.
 enum ZombieFailure {
   FAILED_10_5,
   FAILED_10_6,
 
@@ skipping 226 matching lines @@
   if (oldZombies) {
     for (size_t i = 0; i < oldCount; ++i) {
       if (oldZombies[i].object)
         object_dispose(oldZombies[i].object);
     }
     free(oldZombies);
   }
 }
 
 }  // namespace ObjcEvilDoers