backtrace: Refactor ast_bt_get_symbols so it doesn't crash

We've been seeing crashes in libbfd when we attempt to generate
a stack trace from multiple threads.  It turns out that libbfd
is NOT thread-safe.  It can cache the bfd structure and give it to
multiple threads without protecting itself.  To get around this,
we've added a global mutex around the bfd functions and also have
refactored the use of those functions to be more efficient and
to provide more information about inlined functions.

Also added a few more tests to test_pbx.c.  One just calls
ast_assert() and the other calls ast_log_backtrace().  Neither are
run by default.

WARNING:  This change necessitated changing the return value of
ast_bt_get_symbols() from an array of strings to a VECTOR of
strings.  However, the use of this function outside Asterisk is not
likely.

ASTERISK-28140

Change-Id: I79d02862ddaa2423a0809caa4b3b85c128131621
This commit is contained in:
George Joseph 2018-11-08 08:53:44 -07:00
parent fa048183aa
commit ece5f8015f
10 changed files with 318 additions and 183 deletions

View File

@ -34,6 +34,11 @@ chan_pjsip
* New dialplan function PJSIP_PARSE_URI added to parse an URI and return
a specified part of the URI.
Core
------------------
* ast_bt_get_symbols() now returns a vector of strings instead of an
array of strings. This must be freed with ast_bt_free_symbols.
res_pjsip
------------------
* New options 'trust_connected_line' and 'send_connected_line' have been

View File

@ -33,11 +33,13 @@
#define ast_bt_create() __ast_bt_create()
#define ast_bt_destroy(bt) __ast_bt_destroy((bt))
#define ast_bt_get_symbols(addresses, num_frames) __ast_bt_get_symbols((addresses), (num_frames))
#define ast_bt_free_symbols(string_vector) __ast_bt_free_symbols((string_vector))
#else
#define ast_bt_get_addresses(bt) 0
#define ast_bt_create() NULL
#define ast_bt_destroy(bt) NULL
#define ast_bt_get_symbols(addresses, num_frames) NULL
#define ast_bt_free_symbols(string_vector) NULL
#endif
/* \brief
@ -86,11 +88,24 @@ void *__ast_bt_destroy(struct ast_bt *bt);
*
* \param addresses A list of addresses, such as the ->addresses structure element of struct ast_bt.
* \param num_frames Number of addresses in the addresses list
*
* \retval NULL Unable to allocate memory
* \return List of strings. Free the entire list with a single ast_std_free call.
* \return Vector of strings. Free with ast_bt_free_symbols
*
* \note The first frame in the addresses array will usually point to __ast_bt_create
* so when printing the symbols you may wish to start at position 1 rather than 0.
*
* \since 1.6.2.16
*/
char **__ast_bt_get_symbols(void **addresses, size_t num_frames);
struct ast_vector_string *__ast_bt_get_symbols(void **addresses, size_t num_frames);
/* \brief Free symbols returned from ast_bt_get_symbols
*
* \param symbols The symbol string vector
*
* \since 13.24.0
*/
void __ast_bt_free_symbols(struct ast_vector_string *symbols);
#endif /* HAVE_BKTR */

View File

@ -191,7 +191,7 @@ AST_MUTEX_DEFINE_STATIC_NOTRACKING(reglock);
static void print_backtrace(struct ast_bt *bt)
{
int i = 0;
char **strings;
struct ast_vector_string *strings;
if (!bt) {
return;
@ -199,10 +199,10 @@ static void print_backtrace(struct ast_bt *bt)
if ((strings = ast_bt_get_symbols(bt->addresses, bt->num_frames))) {
astmm_log("Memory allocation backtrace:\n");
for (i = 3; i < bt->num_frames - 2; i++) {
astmm_log("#%d: [%p] %s\n", i - 3, bt->addresses[i], strings[i]);
for (i = 3; i < AST_VECTOR_SIZE(strings) - 2; i++) {
astmm_log("#%d: %s\n", i - 3, AST_VECTOR_GET(strings, i));
}
ast_std_free(strings);
ast_bt_free_symbols(strings);
}
}

View File

@ -26,11 +26,33 @@
<support_level>core</support_level>
***/
#include "asterisk.h"
/*
* Block automatic include of asterisk/lock.h to allow use of pthread_mutex
* functions directly. We don't need or want the lock.h overhead.
*/
#define _ASTERISK_LOCK_H
/*
* The astmm ast_ memory management functions can cause ast_bt_get_symbols
* to be invoked so we must not use them.
*/
#define ASTMM_LIBC ASTMM_IGNORE
#include "asterisk.h"
#include "asterisk/backtrace.h"
#include "asterisk/utils.h"
#include "asterisk/strings.h"
/*
* As stated above, the vector macros call the ast_ functions so
* we need to remap those back to the libc ones.
*/
#undef ast_free
#undef ast_calloc
#undef ast_malloc
#define ast_free(x) free(x)
#define ast_calloc(n, x) calloc(n, x)
#define ast_malloc(x) malloc(x)
#include "asterisk/vector.h"
#ifdef HAVE_BKTR
#include <execinfo.h>
@ -39,9 +61,14 @@
#include <bfd.h>
#endif
#include <pthread.h>
/* simple definition of S_OR so we don't have include strings.h */
#define S_OR(a, b) (a && a[0] != '\0') ? a : b
struct ast_bt *__ast_bt_create(void)
{
struct ast_bt *bt = ast_std_calloc(1, sizeof(*bt));
struct ast_bt *bt = calloc(1, sizeof(*bt));
if (!bt) {
return NULL;
@ -62,164 +89,217 @@ int __ast_bt_get_addresses(struct ast_bt *bt)
void *__ast_bt_destroy(struct ast_bt *bt)
{
if (bt && bt->alloced) {
ast_std_free(bt);
free(bt);
}
return NULL;
}
char **__ast_bt_get_symbols(void **addresses, size_t num_frames)
{
char **strings;
#if defined(BETTER_BACKTRACES)
int stackfr;
bfd *bfdobj; /* bfd.h */
#ifdef BETTER_BACKTRACES
struct bfd_data {
struct ast_vector_string *return_strings;
bfd_vma pc; /* bfd.h */
asymbol **syms; /* bfd.h */
Dl_info dli; /* dlfcn.h */
long allocsize;
asymbol **syms = NULL; /* bfd.h */
bfd_vma offset; /* bfd.h */
const char *lastslash;
asection *section;
const char *libname;
int dynamic;
int has_syms;
char *msg;
int found;
};
#define MSG_BUFF_LEN 1024
static void process_section(bfd *bfdobj, asection *section, void *obj)
{
struct bfd_data *data = obj;
const char *file, *func;
unsigned int line;
char address_str[128];
char msg[1024];
size_t strings_size;
size_t *eachlen;
#endif
bfd_vma offset;
bfd_vma vma;
bfd_size_type size;
bfd_boolean line_found = 0;
char *fn;
int inlined = 0;
#if defined(BETTER_BACKTRACES)
strings_size = num_frames * sizeof(*strings);
offset = data->pc - (data->dynamic ? (bfd_vma) data->dli.dli_fbase : 0);
eachlen = ast_std_calloc(num_frames, sizeof(*eachlen));
strings = ast_std_calloc(num_frames, sizeof(*strings));
if (!eachlen || !strings) {
ast_std_free(eachlen);
ast_std_free(strings);
if (!(bfd_get_section_flags(bfdobj, section) & SEC_ALLOC)) {
return;
}
vma = bfd_get_section_vma(bfdobj, section);
size = bfd_get_section_size(section);
if (offset < vma || offset >= vma + size) {
/* Not in this section */
return;
}
line_found = bfd_find_nearest_line(bfdobj, section, data->syms, offset - vma, &file,
&func, &line);
if (!line_found) {
return;
}
/*
* If we find a line, we will want to continue calling bfd_find_inliner_info
* to capture any inlined functions that don't have their own stack frames.
*/
do {
data->found++;
/* file can possibly be null even with a success result from bfd_find_nearest_line */
file = file ? file : "";
fn = strrchr(file, '/');
#define FMT_INLINED "[%s] %s %s:%u %s()"
#define FMT_NOT_INLINED "[%p] %s %s:%u %s()"
snprintf(data->msg, MSG_BUFF_LEN, inlined ? FMT_INLINED : FMT_NOT_INLINED,
inlined ? "inlined" : (char *)data->pc,
data->libname,
fn ? fn + 1 : file,
line, S_OR(func, "???"));
if (AST_VECTOR_APPEND(data->return_strings, strdup(data->msg))) {
return;
}
inlined++;
/* Let's see if there are any inlined functions */
} while (bfd_find_inliner_info(bfdobj, &file, &func, &line));
}
struct ast_vector_string *__ast_bt_get_symbols(void **addresses, size_t num_frames)
{
struct ast_vector_string *return_strings;
int stackfr;
bfd *bfdobj;
long allocsize;
char msg[MSG_BUFF_LEN];
static pthread_mutex_t bfd_mutex = PTHREAD_MUTEX_INITIALIZER;
return_strings = malloc(sizeof(struct ast_vector_string));
if (!return_strings) {
return NULL;
}
if (AST_VECTOR_INIT(return_strings, num_frames)) {
free(return_strings);
return NULL;
}
for (stackfr = 0; stackfr < num_frames; stackfr++) {
int found = 0, symbolcount;
int symbolcount;
struct bfd_data data = {
.return_strings = return_strings,
.msg = msg,
.pc = (bfd_vma)addresses[stackfr],
.found = 0,
.dynamic = 0,
};
msg[0] = '\0';
if (!dladdr(addresses[stackfr], &dli)) {
if (!dladdr((void *)data.pc, &data.dli)) {
continue;
}
if (strcmp(dli.dli_fname, "asterisk") == 0) {
char asteriskpath[256];
if (!(dli.dli_fname = ast_utils_which("asterisk", asteriskpath, sizeof(asteriskpath)))) {
/* This will fail to find symbols */
dli.dli_fname = "asterisk";
}
data.libname = strrchr(data.dli.dli_fname, '/');
if (!data.libname) {
data.libname = data.dli.dli_fname;
} else {
data.libname++;
}
lastslash = strrchr(dli.dli_fname, '/');
if ((bfdobj = bfd_openr(dli.dli_fname, NULL)) &&
bfd_check_format(bfdobj, bfd_object) &&
(allocsize = bfd_get_symtab_upper_bound(bfdobj)) > 0 &&
(syms = ast_std_malloc(allocsize)) &&
(symbolcount = bfd_canonicalize_symtab(bfdobj, syms))) {
if (bfdobj->flags & DYNAMIC) {
offset = addresses[stackfr] - dli.dli_fbase;
} else {
offset = addresses[stackfr] - (void *) 0;
pthread_mutex_lock(&bfd_mutex);
/* Using do while(0) here makes it easier to escape and clean up */
do {
bfdobj = bfd_openr(data.dli.dli_fname, NULL);
if (!bfdobj) {
break;
}
for (section = bfdobj->sections; section; section = section->next) {
if (!(bfd_get_section_flags(bfdobj, section) & SEC_ALLOC) ||
section->vma > offset ||
section->size + section->vma < offset) {
continue;
}
if (!bfd_find_nearest_line(bfdobj, section, syms, offset - section->vma, &file, &func, &line)) {
continue;
}
/* file can possibly be null even with a success result from bfd_find_nearest_line */
file = file ? file : "";
/* Stack trace output */
found++;
if ((lastslash = strrchr(file, '/'))) {
const char *prevslash;
for (prevslash = lastslash - 1; *prevslash != '/' && prevslash >= file; prevslash--) {
}
if (prevslash >= file) {
lastslash = prevslash;
}
}
if (dli.dli_saddr == NULL) {
address_str[0] = '\0';
} else {
snprintf(address_str, sizeof(address_str), " (%p+%lX)",
dli.dli_saddr,
(unsigned long) (addresses[stackfr] - dli.dli_saddr));
}
snprintf(msg, sizeof(msg), "%s:%u %s()%s",
lastslash ? lastslash + 1 : file, line,
S_OR(func, "???"),
address_str);
break; /* out of section iteration */
/* bfd_check_format does more than check. It HAS to be called */
if (!bfd_check_format(bfdobj, bfd_object)) {
break;
}
}
data.has_syms = !!(bfd_get_file_flags(bfdobj) & HAS_SYMS);
data.dynamic = !!(bfd_get_file_flags(bfdobj) & DYNAMIC);
if (!data.has_syms) {
break;
}
allocsize = data.dynamic ?
bfd_get_dynamic_symtab_upper_bound(bfdobj) : bfd_get_symtab_upper_bound(bfdobj);
if (allocsize < 0) {
break;
}
data.syms = malloc(allocsize);
if (!data.syms) {
break;
}
symbolcount = data.dynamic ?
bfd_canonicalize_dynamic_symtab(bfdobj, data.syms) : bfd_canonicalize_symtab(bfdobj, data.syms);
if (symbolcount < 0) {
break;
}
bfd_map_over_sections(bfdobj, process_section, &data);
} while(0);
if (bfdobj) {
bfd_close(bfdobj);
ast_std_free(syms);
syms = NULL;
free(data.syms);
data.syms = NULL;
}
pthread_mutex_unlock(&bfd_mutex);
/* Default output, if we cannot find the information within BFD */
if (!found) {
if (dli.dli_saddr == NULL) {
address_str[0] = '\0';
} else {
snprintf(address_str, sizeof(address_str), " (%p+%lX)",
dli.dli_saddr,
(unsigned long) (addresses[stackfr] - dli.dli_saddr));
}
snprintf(msg, sizeof(msg), "%s %s()%s",
lastslash ? lastslash + 1 : dli.dli_fname,
S_OR(dli.dli_sname, "<unknown>"),
address_str);
}
if (!ast_strlen_zero(msg)) {
char **tmp;
eachlen[stackfr] = strlen(msg) + 1;
if (!(tmp = ast_std_realloc(strings, strings_size + eachlen[stackfr]))) {
ast_std_free(strings);
strings = NULL;
break; /* out of stack frame iteration */
}
strings = tmp;
strings[stackfr] = (char *) strings + strings_size;
strcpy(strings[stackfr], msg);/* Safe since we just allocated the room. */
strings_size += eachlen[stackfr];
if (!data.found) {
snprintf(msg, sizeof(msg), "%s %s()",
data.libname,
S_OR(data.dli.dli_sname, "<unknown>"));
AST_VECTOR_APPEND(return_strings, strdup(msg));
}
}
if (strings) {
/* Recalculate the offset pointers because of the reallocs. */
strings[0] = (char *) strings + num_frames * sizeof(*strings);
for (stackfr = 1; stackfr < num_frames; stackfr++) {
strings[stackfr] = strings[stackfr - 1] + eachlen[stackfr - 1];
}
}
ast_std_free(eachlen);
return return_strings;
}
#else /* !defined(BETTER_BACKTRACES) */
#else
struct ast_vector_string *__ast_bt_get_symbols(void **addresses, size_t num_frames)
{
char **strings;
struct ast_vector_string *return_strings;
int i;
return_strings = malloc(sizeof(struct ast_vector_string));
if (!return_strings) {
return NULL;
}
if (AST_VECTOR_INIT(return_strings, num_frames)) {
free(return_strings);
return NULL;
}
strings = backtrace_symbols(addresses, num_frames);
#endif /* defined(BETTER_BACKTRACES) */
return strings;
if (strings) {
for (i = 0; i < num_frames; i++) {
AST_VECTOR_APPEND(return_strings, strdup(strings[i]));
}
free(strings);
}
return return_strings;
}
#endif /* BETTER_BACKTRACES */
void __ast_bt_free_symbols(struct ast_vector_string *symbols)
{
AST_VECTOR_CALLBACK_VOID(symbols, free);
AST_VECTOR_PTR_FREE(symbols);
}
#endif /* HAVE_BKTR */

View File

@ -385,6 +385,9 @@ static int format_log_default(struct logchannel *chan, struct logmsg *msg, char
case LOGTYPE_CONSOLE:
{
char linestr[32];
int has_file = !ast_strlen_zero(msg->file);
int has_line = (msg->line > 0);
int has_func = !ast_strlen_zero(msg->function);
/*
* Verbose messages are interpreted by console channels in their own
@ -394,18 +397,20 @@ static int format_log_default(struct logchannel *chan, struct logmsg *msg, char
return logger_add_verbose_magic(msg, buf, size);
}
/* Turn the numeric line number into a string for colorization */
/* Turn the numerical line number into a string */
snprintf(linestr, sizeof(linestr), "%d", msg->line);
snprintf(buf, size, "[%s] " COLORIZE_FMT "[%d]%s: " COLORIZE_FMT ":" COLORIZE_FMT " " COLORIZE_FMT ": %s",
msg->date,
COLORIZE(colors[msg->level], 0, msg->level_name),
msg->lwp,
call_identifier_str,
COLORIZE(COLOR_BRWHITE, 0, msg->file),
COLORIZE(COLOR_BRWHITE, 0, linestr),
COLORIZE(COLOR_BRWHITE, 0, msg->function),
msg->message);
/* Build string to print out */
snprintf(buf, size, "[%s] " COLORIZE_FMT "[%d]%s: " COLORIZE_FMT "%s" COLORIZE_FMT " " COLORIZE_FMT "%s %s",
msg->date,
COLORIZE(colors[msg->level], 0, msg->level_name),
msg->lwp,
call_identifier_str,
COLORIZE(COLOR_BRWHITE, 0, has_file ? msg->file : ""),
has_file ? ":" : "",
COLORIZE(COLOR_BRWHITE, 0, has_line ? linestr : ""),
COLORIZE(COLOR_BRWHITE, 0, has_func ? msg->function : ""),
has_func ? ":" : "",
msg->message);
}
break;
}
@ -2063,7 +2068,7 @@ void ast_log_backtrace(void)
#ifdef HAVE_BKTR
struct ast_bt *bt;
int i = 0;
char **strings;
struct ast_vector_string *strings;
if (!(bt = ast_bt_create())) {
ast_log(LOG_WARNING, "Unable to allocate space for backtrace structure\n");
@ -2071,14 +2076,21 @@ void ast_log_backtrace(void)
}
if ((strings = ast_bt_get_symbols(bt->addresses, bt->num_frames))) {
ast_verbose("Got %d backtrace record%c\n", bt->num_frames, bt->num_frames != 1 ? 's' : ' ');
for (i = 3; i < bt->num_frames - 2; i++) {
ast_verbose("#%d: [%p] %s\n", i - 3, bt->addresses[i], strings[i]);
int count = AST_VECTOR_SIZE(strings);
struct ast_str *buf = ast_str_create(bt->num_frames * 64);
if (buf) {
ast_str_append(&buf, 0, "Got %d backtrace record%c\n", count - 3, count - 3 != 1 ? 's' : ' ');
for (i = 3; i < AST_VECTOR_SIZE(strings); i++) {
ast_str_append(&buf, 0, "#%2d: %s\n", i - 3, AST_VECTOR_GET(strings, i));
}
ast_log_safe(__LOG_ERROR, NULL, 0, NULL, "%s\n", ast_str_buffer(buf));
ast_free(buf);
}
ast_std_free(strings);
ast_bt_free_symbols(strings);
} else {
ast_verbose("Could not allocate memory for backtrace\n");
ast_log(LOG_ERROR, "Could not allocate memory for backtrace\n");
}
ast_bt_destroy(bt);
#else

View File

@ -967,7 +967,7 @@ static const char *locktype2str(enum ast_lock_type type)
#ifdef HAVE_BKTR
static void append_backtrace_information(struct ast_str **str, struct ast_bt *bt)
{
char **symbols;
struct ast_vector_string *symbols;
int num_frames;
if (!bt) {
@ -981,11 +981,11 @@ static void append_backtrace_information(struct ast_str **str, struct ast_bt *bt
if ((symbols = ast_bt_get_symbols(bt->addresses, num_frames))) {
int frame_iterator;
for (frame_iterator = 0; frame_iterator < num_frames; ++frame_iterator) {
ast_str_append(str, 0, "\t%s\n", symbols[frame_iterator]);
for (frame_iterator = 1; frame_iterator < AST_VECTOR_SIZE(symbols); ++frame_iterator) {
ast_str_append(str, 0, "\t%s\n", AST_VECTOR_GET(symbols, frame_iterator));
}
ast_std_free(symbols);
ast_bt_free_symbols(symbols);
} else {
ast_str_append(str, 0, "\tCouldn't retrieve backtrace symbols\n");
}

View File

@ -343,8 +343,50 @@ AST_TEST_DEFINE(segv)
return AST_TEST_FAIL;
}
AST_TEST_DEFINE(call_assert)
{
switch (cmd) {
case TEST_INIT:
info->name = "CALL_ASSERT";
info->category = "/DO_NOT_RUN/";
info->summary = "Calls ast_asert()!!! (will only be run if explicitly called)";
info->description = "Calls ast_asert()!!! (will only be run if explicitly called). "
"This test is mainly used for testing CI and tool failure scenarios.";
info->explicit_only = 1;
return AST_TEST_NOT_RUN;
case TEST_EXECUTE:
break;
}
ast_assert(0);
return AST_TEST_PASS;
}
AST_TEST_DEFINE(call_backtrace)
{
switch (cmd) {
case TEST_INIT:
info->name = "CALL_BACKTRACE";
info->category = "/DO_NOT_RUN/";
info->summary = "Calls ast_log_backtrace()!!! (will only be run if explicitly called)";
info->description = "Calls ast_log_backtrace()!!! (will only be run if explicitly called). "
"This test is mainly used for testing CI and tool failure scenarios.";
info->explicit_only = 1;
return AST_TEST_NOT_RUN;
case TEST_EXECUTE:
break;
}
ast_log_backtrace();
return AST_TEST_PASS;
}
static int unload_module(void)
{
AST_TEST_UNREGISTER(call_backtrace);
AST_TEST_UNREGISTER(call_assert);
AST_TEST_UNREGISTER(segv);
AST_TEST_UNREGISTER(pattern_match_test);
return 0;
@ -354,6 +396,8 @@ static int load_module(void)
{
AST_TEST_REGISTER(pattern_match_test);
AST_TEST_REGISTER(segv);
AST_TEST_REGISTER(call_assert);
AST_TEST_REGISTER(call_backtrace);
return AST_MODULE_LOAD_SUCCESS;
}

View File

@ -617,16 +617,9 @@ int __ast_bt_get_addresses(struct ast_bt *bt)
return 0;
}
char **__ast_bt_get_symbols(void **addresses, size_t num_frames)
struct ast_vector_string *__ast_bt_get_symbols(void **addresses, size_t num_frames)
{
char **foo = calloc(num_frames, sizeof(char *) + 1);
if (foo) {
int i;
for (i = 0; i < num_frames; i++) {
foo[i] = (char *) foo + sizeof(char *) * num_frames;
}
}
return foo;
return NULL;
}
#endif /* HAVE_BKTR */
void ast_suspend_lock_info(void *lock_addr)

View File

@ -77,17 +77,10 @@ int __ast_bt_get_addresses(struct ast_bt *bt)
/* Suck it, you stupid utils directory! */
return 0;
}
char **__ast_bt_get_symbols(void **addresses, size_t num_frames);
char **__ast_bt_get_symbols(void **addresses, size_t num_frames)
struct ast_vector_string *__ast_bt_get_symbols(void **addresses, size_t num_frames);
struct ast_vector_string *__ast_bt_get_symbols(void **addresses, size_t num_frames)
{
char **foo = calloc(num_frames, sizeof(char *) + 1);
if (foo) {
int i;
for (i = 0; i < num_frames; i++) {
foo[i] = (char *) foo + sizeof(char *) * num_frames;
}
}
return foo;
return NULL;
}
#endif /* HAVE_BKTR */

View File

@ -715,16 +715,9 @@ int __ast_bt_get_addresses(struct ast_bt *bt)
return 0;
}
char **__ast_bt_get_symbols(void **addresses, size_t num_frames)
struct ast_vector_string *__ast_bt_get_symbols(void **addresses, size_t num_frames)
{
char **foo = calloc(num_frames, sizeof(char *) + 1);
if (foo) {
int i;
for (i = 0; i < num_frames; i++) {
foo[i] = (char *) foo + sizeof(char *) * num_frames;
}
}
return foo;
return NULL;
}
#endif /* HAVE_BKTR */
void ast_suspend_lock_info(void *lock_addr)