[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.
+const int kBacktraceDepth = 20;
+
 // 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.
+  int traceDepth;                // Actual depth of trace[].
 } 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 101 matching lines @@
   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};
+  zombieToFree.traceDepth = backtrace(zombieToFree.trace, kBacktraceDepth);

[Mark Mentovai, 2011/08/28 15:40:01]

Caution!

backtrace may not be implemented in a way that’s able to walk through stack
frames created by code built with -fomit-frame-pointer. We’re not currently
using -fomit-frame-pointer because performance testing showed no real advantage
last time I tried it, but given the short-term compiler switch and other plans
that may come together in the medium or long term, if ongoing testing showed a
performance advantage from -fomit-frame-pointer, I wouldn’t consider this use of
backtrace something that would block turning -fomit-frame-pointer on for release
builds.

This isn’t worth worrying about now and probably isn’t worth worrying about in
the future either, but it is worth being aware of.

[Scott Hess - ex-Googler, 2011/08/29 20:13:36]

Hmm.  That perhaps argues for taking the overhead of declaring a StackTrace()
instance and calling it's API to grab a subset of the backtrace.

[Later]  Unscientific profiling indicates that at 40000 zombies straight
backtrace() adds 13ms of overhead, while a StackTrace() instance adds 20ms. 
Those are in release mode (debug mode was 17ms and 30ms).  So I'll include a
version using StackTrace(), as a separate patch in case you want to question it.

 
   // 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]);

[Mark Mentovai, 2011/08/28 15:40:01]

As ZombieRecord grows, it may begin to make sense to build it in the g_zombies
array rather than building it separately and having to do all of these copies to
effect a swap.

[Scott Hess - ex-Googler, 2011/08/29 20:13:36]

To my mind thread-safety argues against that.  Or at least sets the bar higher
for where the transition makes sense.  As-is, since it's POD, the swap should be
pretty cheap.  Also note that the swap isn't only getting the new zombie onto
the treadmill, it's pulling an old zombie out for disposal.

 
       // 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) {

[Mark Mentovai, 2011/08/28 15:40:01]

Style nit (existing code): spaces around the =.

[Scott Hess - ex-Googler, 2011/08/29 20:13:36]

Done.

-    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 use DCHECK to dump only in debug builds.
+BOOL DumpDeallocTrace(const void* const* array, int size) {
+  DLOG(INFO) << "Backtrace from -dealloc:";

[Mark Mentovai, 2011/08/28 15:40:01]

base::debug::StackTrace::PrintBacktrace outputs to std::cerr. Since this message
will identify the trace that follows, maybe it should go to std::cerr (or
fprintf(stderr)) instead of DLOG(INFO) as well.

[Scott Hess - ex-Googler, 2011/08/29 20:13:36]

Done.  But it feels funny.

+  base::debug::StackTrace(array, size).PrintBacktrace();
+
+  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>";
+  if (found && record.traceDepth > 0) {
+    NSMutableArray* hexBacktrace =
+        [NSMutableArray arrayWithCapacity:record.traceDepth];
+    for (int i = 0; i < record.traceDepth; ++i) {
+      NSString* s = [NSString stringWithFormat:@"%p", record.trace[i]];
+      [hexBacktrace addObject:s];
+    }
+    deallocTrace = [hexBacktrace componentsJoinedByString:@" "];
+  }
+  SetCrashKeyValue(@"zombie_dealloc_bt", deallocTrace);

[Mark Mentovai, 2011/08/28 15:40:01]

Looks like Breakpad keys and values have a maximum byte length of 255 with the
current implementation. For 32-bit pointers, this string will have a maximum
length of 219. This is 100% fine. I’m just pointing it out because:

1. If we do a 64-bit thing, the string’s maximum length of 379 would pose a
problem here.

2. If we want kBacktraceDepth to be more than 23, we’d need to be aware of this
problem too.

It’s possible to do a better job with a more compact encoding, or letting the
trace string spill out across multiple Breakpad key-value pairs. None of this is
necessary at this point. In fact, please don’t. But it’s probably worth
commenting on. The comment may be better placed up where we define
kBacktraceDepth than being hidden here.

[Scott Hess - ex-Googler, 2011/08/29 20:13:36]

I added some documentation around this to the kBacktraceDepth declaraction.  I
agree that we can worry about this later - perhaps after we determine if this is
even useful :-).

+
+  // Log -dealloc backtrace in debug builds then crash with a useful
+  // stack trace.
+  if (found && record.traceDepth) {

[Mark Mentovai, 2011/08/28 15:40:01]

For consistency’s sake, you checked |traceDepth > 0| on line 283 but just
|traceDepth| here. They should match.

|>0| is correct. traceDepth contains the result of the backtrace call. I don’t
see any way for it to return negative right now based on the read of the current
implementation, but it is a (signed) int, so the possibility technically exists,
and using a >0 check here wont’t harm anything.

[Scott Hess - ex-Googler, 2011/08/29 20:13:36]

Done.

+    DCHECK(DumpDeallocTrace(record.trace, record.traceDepth));
+  } else {
+    DLOG(INFO) << "Unable to generate backtrace from -dealloc.";
+  }
+  DLOG(FATAL) << [aString UTF8String];
 
   // 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