Don't collect useless stack frames; do demangle C++ symbols.

Previously, we'd collect every stack frame and then throw some away
when we came to log them. This meant that stack traces were effectively
shorter than the buffers that had been allocated for them. This patch
only stores frames we'll actually output.

Also dynamically call the C++ demangler so we don't have to try to
read mangled names. Because no one knows the mangling of operator new[]
for int arrays off the top of their head.

Bug: 7291287
Change-Id: I42b022fd7cd61675d05171de4c3b2704d058ef2a
This commit is contained in:
Elliott Hughes 2013-01-28 16:27:36 -08:00
parent a0151cbfba
commit 35b621c5f4
6 changed files with 107 additions and 97 deletions

@ -57,7 +57,7 @@ static mapinfo_t* parse_maps_line(char* line) {
return mi;
}
__LIBC_HIDDEN__ mapinfo_t* mapinfo_create(int pid) {
__LIBC_HIDDEN__ mapinfo_t* mapinfo_create(pid_t pid) {
struct mapinfo_t* milist = NULL;
char data[1024]; // Used to read lines as well as to construct the filename.
snprintf(data, sizeof(data), "/proc/%d/maps", pid);
@ -76,7 +76,7 @@ __LIBC_HIDDEN__ mapinfo_t* mapinfo_create(int pid) {
}
__LIBC_HIDDEN__ void mapinfo_destroy(mapinfo_t* mi) {
while (mi) {
while (mi != NULL) {
mapinfo_t* del = mi;
mi = mi->next;
dlfree(del);
@ -84,13 +84,13 @@ __LIBC_HIDDEN__ void mapinfo_destroy(mapinfo_t* mi) {
}
// Find the containing map info for the PC.
__LIBC_HIDDEN__ const mapinfo_t* mapinfo_find(mapinfo_t* mi, unsigned pc, unsigned* rel_pc) {
*rel_pc = pc;
__LIBC_HIDDEN__ const mapinfo_t* mapinfo_find(mapinfo_t* mi, uintptr_t pc, uintptr_t* rel_pc) {
for (; mi != NULL; mi = mi->next) {
if ((pc >= mi->start) && (pc < mi->end)) {
*rel_pc -= mi->start;
*rel_pc = pc - mi->start;
return mi;
}
}
*rel_pc = pc;
return NULL;
}

@ -38,8 +38,8 @@ struct mapinfo_t {
char name[];
};
__LIBC_HIDDEN__ mapinfo_t* mapinfo_create(int pid);
__LIBC_HIDDEN__ mapinfo_t* mapinfo_create(pid_t pid);
__LIBC_HIDDEN__ void mapinfo_destroy(mapinfo_t* mi);
__LIBC_HIDDEN__ const mapinfo_t* mapinfo_find(mapinfo_t* mi, unsigned pc, unsigned* rel_pc);
__LIBC_HIDDEN__ const mapinfo_t* mapinfo_find(mapinfo_t* mi, uintptr_t pc, uintptr_t* rel_pc);
#endif /* DEBUG_MAPINFO_H */

@ -44,69 +44,102 @@ typedef struct _Unwind_Context __unwind_context;
typedef _Unwind_Context __unwind_context;
#endif
static mapinfo_t* gMapInfo = NULL;
static void* gDemangler;
typedef char* (*DemanglerFn)(const char*, char*, size_t*, int*);
static DemanglerFn gDemanglerFn = NULL;
__LIBC_HIDDEN__ void backtrace_startup() {
gMapInfo = mapinfo_create(getpid());
gDemangler = dlopen("libgccdemangle.so", RTLD_NOW);
if (gDemangler != NULL) {
void* sym = dlsym(gDemangler, "__cxa_demangle");
gDemanglerFn = reinterpret_cast<DemanglerFn>(sym);
}
}
__LIBC_HIDDEN__ void backtrace_shutdown() {
mapinfo_destroy(gMapInfo);
dlclose(gDemangler);
}
static char* demangle(const char* symbol) {
if (gDemanglerFn == NULL) {
return NULL;
}
return (*gDemanglerFn)(symbol, NULL, NULL, NULL);
}
struct stack_crawl_state_t {
uintptr_t* frames;
size_t frame_count;
size_t max_depth;
bool have_skipped_self;
stack_crawl_state_t(uintptr_t* frames, size_t max_depth)
: frames(frames), frame_count(0), max_depth(max_depth), have_skipped_self(false) {
}
};
static _Unwind_Reason_Code trace_function(__unwind_context* context, void* arg) {
stack_crawl_state_t* state = static_cast<stack_crawl_state_t*>(arg);
if (state->count) {
uintptr_t ip = _Unwind_GetIP(context);
if (ip) {
state->addrs[0] = ip;
state->addrs++;
state->count--;
return _URC_NO_REASON;
}
uintptr_t ip = _Unwind_GetIP(context);
// The first stack frame is get_backtrace itself. Skip it.
if (ip != 0 && !state->have_skipped_self) {
state->have_skipped_self = true;
return _URC_NO_REASON;
}
// If we run out of space to record the address or 0 has been seen, stop
// unwinding the stack.
return _URC_END_OF_STACK;
state->frames[state->frame_count++] = ip;
return (state->frame_count >= state->max_depth) ? _URC_END_OF_STACK : _URC_NO_REASON;
}
__LIBC_HIDDEN__ int get_backtrace(uintptr_t* addrs, size_t max_entries) {
stack_crawl_state_t state;
state.count = max_entries;
state.addrs = addrs;
__LIBC_HIDDEN__ int get_backtrace(uintptr_t* frames, size_t max_depth) {
stack_crawl_state_t state(frames, max_depth);
_Unwind_Backtrace(trace_function, &state);
return max_entries - state.count;
return state.frame_count;
}
__LIBC_HIDDEN__ void log_backtrace(mapinfo_t* map_info, uintptr_t* addrs, size_t c) {
__LIBC_HIDDEN__ void log_backtrace(uintptr_t* frames, size_t frame_count) {
uintptr_t self_bt[16];
if (addrs == NULL) {
c = get_backtrace(self_bt, 16);
addrs = self_bt;
if (frames == NULL) {
frame_count = get_backtrace(self_bt, 16);
frames = self_bt;
}
__libc_format_log(ANDROID_LOG_ERROR, "libc",
"*** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***\n");
int index = 0;
for (size_t i = 0 ; i < c; ++i) {
for (size_t i = 0 ; i < frame_count; ++i) {
void* offset = 0;
const char* symbol = NULL;
Dl_info info;
if (dladdr((void*) addrs[i], &info) != 0) {
if (dladdr((void*) frames[i], &info) != 0) {
offset = info.dli_saddr;
symbol = info.dli_sname;
}
// This test is a bit sketchy, but it allows us to skip the
// stack trace entries due to this debugging code. it works
// because those don't have a symbol (they're not exported).
if (symbol != NULL || index > 0) {
unsigned int rel_pc;
const mapinfo_t* mi = mapinfo_find(map_info, addrs[i], &rel_pc);
const char* soname = mi ? mi->name : info.dli_fname;
if (soname == NULL) {
soname = "unknown";
}
if (symbol) {
__libc_format_log(ANDROID_LOG_ERROR, "libc", " #%02d pc %08x %s (%s+0x%x)",
index, rel_pc, soname, symbol, addrs[i] - (uintptr_t) offset);
} else {
__libc_format_log(ANDROID_LOG_ERROR, "libc", " #%02d pc %08x %s",
index, rel_pc, soname);
}
++index;
uintptr_t rel_pc;
const mapinfo_t* mi = (gMapInfo != NULL) ? mapinfo_find(gMapInfo, frames[i], &rel_pc) : NULL;
const char* soname = (mi != NULL) ? mi->name : info.dli_fname;
if (soname == NULL) {
soname = "<unknown>";
}
if (symbol != NULL) {
// TODO: we might need a flag to say whether it's safe to allocate (demangling allocates).
char* demangled_symbol = demangle(symbol);
const char* best_name = (demangled_symbol != NULL) ? demangled_symbol : symbol;
__libc_format_log(ANDROID_LOG_ERROR, "libc", " #%02d pc %08x %s (%s+0x%x)",
i, rel_pc, soname, best_name, frames[i] - (uintptr_t) offset);
free(demangled_symbol);
} else {
__libc_format_log(ANDROID_LOG_ERROR, "libc", " #%02d pc %08x %s",
i, rel_pc, soname);
}
}
}

@ -32,14 +32,9 @@
#include <stdint.h>
#include <sys/cdefs.h>
struct stack_crawl_state_t {
size_t count;
uintptr_t* addrs;
};
struct mapinfo_t;
__LIBC_HIDDEN__ int get_backtrace(uintptr_t* stack_frames, size_t max_entries);
__LIBC_HIDDEN__ void log_backtrace(mapinfo_t* map_info, uintptr_t* stack_frames, size_t frame_count);
__LIBC_HIDDEN__ void backtrace_startup();
__LIBC_HIDDEN__ void backtrace_shutdown();
__LIBC_HIDDEN__ int get_backtrace(uintptr_t* stack_frames, size_t max_depth);
__LIBC_HIDDEN__ void log_backtrace(uintptr_t* stack_frames, size_t frame_count);
#endif /* DEBUG_STACKTRACE_H */

@ -52,8 +52,6 @@
#include "malloc_debug_common.h"
#include "ScopedPthreadMutexLocker.h"
static mapinfo_t* gMapInfo;
/* libc.debug.malloc.backlog */
extern unsigned int malloc_double_free_backlog;
@ -261,11 +259,11 @@ static inline int check_allocation_locked(hdr_t *hdr, int *safe) {
if (!valid && *safe) {
log_message("+++ ALLOCATION %p SIZE %d ALLOCATED HERE:\n",
user(hdr), hdr->size);
log_backtrace(gMapInfo, hdr->bt, hdr->bt_depth);
log_backtrace(hdr->bt, hdr->bt_depth);
if (hdr->tag == BACKLOG_TAG) {
log_message("+++ ALLOCATION %p SIZE %d FREED HERE:\n",
user(hdr), hdr->size);
log_backtrace(gMapInfo, hdr->freed_bt, hdr->freed_bt_depth);
log_backtrace(hdr->freed_bt, hdr->freed_bt_depth);
}
}
@ -343,29 +341,27 @@ extern "C" void chk_free(void *ptr) {
if (del(hdr) < 0) {
uintptr_t bt[MAX_BACKTRACE_DEPTH];
int depth;
depth = get_backtrace(bt, MAX_BACKTRACE_DEPTH);
int depth = get_backtrace(bt, MAX_BACKTRACE_DEPTH);
if (hdr->tag == BACKLOG_TAG) {
log_message("+++ ALLOCATION %p SIZE %d BYTES MULTIPLY FREED!\n",
user(hdr), hdr->size);
log_message("+++ ALLOCATION %p SIZE %d ALLOCATED HERE:\n",
user(hdr), hdr->size);
log_backtrace(gMapInfo, hdr->bt, hdr->bt_depth);
log_backtrace(hdr->bt, hdr->bt_depth);
/* hdr->freed_bt_depth should be nonzero here */
log_message("+++ ALLOCATION %p SIZE %d FIRST FREED HERE:\n",
user(hdr), hdr->size);
log_backtrace(gMapInfo, hdr->freed_bt, hdr->freed_bt_depth);
log_backtrace(hdr->freed_bt, hdr->freed_bt_depth);
log_message("+++ ALLOCATION %p SIZE %d NOW BEING FREED HERE:\n",
user(hdr), hdr->size);
log_backtrace(gMapInfo, bt, depth);
log_backtrace(bt, depth);
} else {
log_message("+++ ALLOCATION %p IS CORRUPTED OR NOT ALLOCATED VIA TRACKER!\n",
user(hdr));
log_backtrace(gMapInfo, bt, depth);
log_backtrace(bt, depth);
}
} else {
hdr->freed_bt_depth = get_backtrace(hdr->freed_bt,
MAX_BACKTRACE_DEPTH);
hdr->freed_bt_depth = get_backtrace(hdr->freed_bt, MAX_BACKTRACE_DEPTH);
add_to_backlog(hdr);
}
}
@ -388,21 +384,20 @@ extern "C" void *chk_realloc(void *ptr, size_t size) {
if (del(hdr) < 0) {
uintptr_t bt[MAX_BACKTRACE_DEPTH];
int depth;
depth = get_backtrace(bt, MAX_BACKTRACE_DEPTH);
int depth = get_backtrace(bt, MAX_BACKTRACE_DEPTH);
if (hdr->tag == BACKLOG_TAG) {
log_message("+++ REALLOCATION %p SIZE %d OF FREED MEMORY!\n",
user(hdr), size, hdr->size);
log_message("+++ ALLOCATION %p SIZE %d ALLOCATED HERE:\n",
user(hdr), hdr->size);
log_backtrace(gMapInfo, hdr->bt, hdr->bt_depth);
log_backtrace(hdr->bt, hdr->bt_depth);
/* hdr->freed_bt_depth should be nonzero here */
log_message("+++ ALLOCATION %p SIZE %d FIRST FREED HERE:\n",
user(hdr), hdr->size);
log_backtrace(gMapInfo, hdr->freed_bt, hdr->freed_bt_depth);
log_backtrace(hdr->freed_bt, hdr->freed_bt_depth);
log_message("+++ ALLOCATION %p SIZE %d NOW BEING REALLOCATED HERE:\n",
user(hdr), hdr->size);
log_backtrace(gMapInfo, bt, depth);
log_backtrace(bt, depth);
/* We take the memory out of the backlog and fall through so the
* reallocation below succeeds. Since we didn't really free it, we
@ -412,7 +407,7 @@ extern "C" void *chk_realloc(void *ptr, size_t size) {
} else {
log_message("+++ REALLOCATION %p SIZE %d IS CORRUPTED OR NOT ALLOCATED VIA TRACKER!\n",
user(hdr), size);
log_backtrace(gMapInfo, bt, depth);
log_backtrace(bt, depth);
// just get a whole new allocation and leak the old one
return dlrealloc(0, size);
// return dlrealloc(user(hdr), size); // assuming it was allocated externally
@ -465,7 +460,7 @@ static void heaptracker_free_leaked_memory() {
exe, block->size, user(block), index++, total);
if (del_leak(block, &safe)) {
/* safe == 1, because the allocation is valid */
log_backtrace(gMapInfo, block->bt, block->bt_depth);
log_backtrace(block->bt, block->bt_depth);
}
}
@ -474,18 +469,15 @@ static void heaptracker_free_leaked_memory() {
}
}
/* Initializes malloc debugging framework.
* See comments on MallocDebugInit in malloc_debug_common.h
*/
extern "C" int malloc_debug_initialize() {
if (!malloc_double_free_backlog) {
malloc_double_free_backlog = BACKLOG_DEFAULT_LEN;
}
gMapInfo = mapinfo_create(getpid());
backtrace_startup();
return 0;
}
extern "C" void malloc_debug_finalize() {
heaptracker_free_leaked_memory();
mapinfo_destroy(gMapInfo);
backtrace_shutdown();
}

@ -120,8 +120,6 @@ extern char* __progname;
#define STACK_TRACE_DEPTH 16
static mapinfo_t* gMapInfo;
/****************************************************************************/
/*
@ -370,17 +368,14 @@ static int traverseTree(MutexInfo* obj, MutexInfo const* objParent)
/* Turn off prediction temporarily in this thread while logging */
sPthreadDebugDisabledThread = gettid();
if (gMapInfo == NULL) {
// note: we're protected by sDbgLock.
gMapInfo = mapinfo_create(getpid());
}
backtrace_startup();
LOGW("%s\n", kStartBanner);
LOGW("pid: %d, tid: %d >>> %s <<<", getpid(), gettid(), __progname);
LOGW("Illegal lock attempt:\n");
LOGW("--- pthread_mutex_t at %p\n", obj->mutex);
stackDepth = get_backtrace(addrs, STACK_TRACE_DEPTH);
log_backtrace(gMapInfo, addrs, stackDepth);
log_backtrace(addrs, stackDepth);
LOGW("+++ Currently held locks in this thread (in reverse order):");
MutexInfo* cur = obj;
@ -391,7 +386,7 @@ static int traverseTree(MutexInfo* obj, MutexInfo const* objParent)
if (parent->owner == ourtid) {
LOGW("--- pthread_mutex_t at %p\n", parent->mutex);
if (sPthreadDebugLevel >= CAPTURE_CALLSTACK) {
log_backtrace(gMapInfo, parent->stackTrace, parent->stackDepth);
log_backtrace(parent->stackTrace, parent->stackDepth);
}
cur = parent;
break;
@ -414,13 +409,9 @@ static int traverseTree(MutexInfo* obj, MutexInfo const* objParent)
if (sPthreadDebugLevel >= CAPTURE_CALLSTACK) {
int index = historyListHas(&obj->parents, objParent);
if ((size_t)index < (size_t)obj->stacks.count) {
log_backtrace(gMapInfo,
obj->stacks.stack[index].addrs,
obj->stacks.stack[index].depth);
log_backtrace(obj->stacks.stack[index].addrs, obj->stacks.stack[index].depth);
} else {
log_backtrace(gMapInfo,
obj->stackTrace,
obj->stackDepth);
log_backtrace(obj->stackTrace, obj->stackDepth);
}
}
result = 0;
@ -465,8 +456,7 @@ static void mutex_lock_checked(MutexInfo* mrl, MutexInfo* object)
linkParentToChild(mrl, object);
if (!traverseTree(object, mrl)) {
mapinfo_destroy(gMapInfo);
gMapInfo = NULL;
backtrace_shutdown();
LOGW("%s\n", kEndBanner);
unlinkParentFromChild(mrl, object);
// reenable pthread debugging for this thread