[Asterisk-code-review] backtrace: Refactor ast bt get symbols so it doesn't crash (asterisk[13])

George Joseph asteriskteam at digium.com
Thu Nov 8 14:20:19 CST 2018


George Joseph has uploaded this change for review. ( https://gerrit.asterisk.org/10602


Change subject: backtrace:  Refactor ast_bt_get_symbols so it doesn't crash
......................................................................

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.

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
---
M CHANGES
M UPGRADE.txt
M include/asterisk/backtrace.h
M main/backtrace.c
M main/logger.c
M main/utils.c
M tests/test_pbx.c
7 files changed, 262 insertions(+), 147 deletions(-)



  git pull ssh://gerrit.asterisk.org:29418/asterisk refs/changes/02/10602/1

diff --git a/CHANGES b/CHANGES
index b191f40..4afe4b1 100644
--- a/CHANGES
+++ b/CHANGES
@@ -12,6 +12,11 @@
 --- Functionality changes from Asterisk 13.23.0 to Asterisk 13.24.0 ----------
 ------------------------------------------------------------------------------
 
+Core
+------------------
+ * ast_bt_get_symbols() now returns a vector of strings instead
+   of an array of strings.
+
 res_pjsip
 ------------------
  * New options 'trust_connected_line' and 'send_connected_line' have been
diff --git a/UPGRADE.txt b/UPGRADE.txt
index 133e8a8..30e9dcc 100644
--- a/UPGRADE.txt
+++ b/UPGRADE.txt
@@ -21,6 +21,13 @@
 === UPGRADE-12.txt  -- Upgrade info for 11 to 12
 ===========================================================
 
+From 13.23.1 to 13.24.0:
+
+Core
+------------------
+ * ast_bt_get_symbols() now returns a vector of strings instead
+   of an array of strings.
+
 From 13.20.0 to 13.21.0:
 
 app_dial
diff --git a/include/asterisk/backtrace.h b/include/asterisk/backtrace.h
index 95358bf..6fb0679 100644
--- a/include/asterisk/backtrace.h
+++ b/include/asterisk/backtrace.h
@@ -86,11 +86,17 @@
  *
  * \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_VECTOR_CALLBACK_VOID(messages, ast_free);
+ *  AST_VECTOR_PTR_FREE(messages);
+ *
+ * \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);
 
 #endif /* HAVE_BKTR */
 
diff --git a/main/backtrace.c b/main/backtrace.c
index cb1a870..b7c525c 100644
--- a/main/backtrace.c
+++ b/main/backtrace.c
@@ -32,6 +32,7 @@
 #include "asterisk/backtrace.h"
 #include "asterisk/utils.h"
 #include "asterisk/strings.h"
+#include "asterisk/vector.h"
 
 #ifdef HAVE_BKTR
 #include <execinfo.h>
@@ -68,159 +69,203 @@
 	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
+
+/*
+ * We CANNOT call the ast_ equivalents for pthread_
+ * functions here so we need to undo the redirections
+ * created by lock.h so we can call the pthread_
+ * functions directly.
+ */
+#undef pthread_mutex_lock
+#undef pthread_mutex_unlock
+#undef pthread_mutex_t
+
+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;
 
-#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);
-		return NULL;
+	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;
+	}
+
+	/*
+	 * We're going to loop after finding the current line using
+	 * 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, '/');
+
+		snprintf(data->msg, MSG_BUFF_LEN, "%s %s:%u %s()",
+			data->libname,
+			fn ? fn + 1 : file,
+			line, S_OR(func, "???"));
+
+		AST_VECTOR_APPEND(data->return_strings, ast_strdup(data->msg));
+
+		/* Let's see if there are any inlined functions */
+	} while (bfd_find_inliner_info(bfdobj, &file, &func, &line));
+}
+
+static struct ast_vector_string *__ast_bt_get_symbols_impl(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 = ast_malloc(sizeof(struct ast_vector_string));
+	if (!return_strings) {
+		return NULL;
+	}
+	AST_VECTOR_INIT(return_strings, num_frames);
+
 	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);
+			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;
+			ast_std_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, ast_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
+static struct ast_vector_string *__ast_bt_get_symbols_impl(void **addresses, size_t num_frames)
+{
+	char **strings;
+	struct ast_vector_string *return_strings;
+	int i;
+
+	return_strings = ast_malloc(sizeof(struct ast_vector_string));
+	if (!return_strings) {
+		return NULL;
+	}
+	AST_VECTOR_INIT(return_strings, num_frames);
 
 	strings = backtrace_symbols(addresses, num_frames);
-#endif /* defined(BETTER_BACKTRACES) */
-	return strings;
+	for (i = 0; i < num_frames; i++) {
+		AST_VECTOR_APPEND(return_strings, ast_strdup(strings[i]));
+	}
+	ast_std_free(strings);
+
+	return return_strings;
+}
+#endif /* BETTER_BACKTRACES */
+
+struct ast_vector_string *__ast_bt_get_symbols(void **addresses, size_t num_frames)
+{
+	return __ast_bt_get_symbols_impl(addresses, num_frames);
 }
 
 #endif /* HAVE_BKTR */
diff --git a/main/logger.c b/main/logger.c
index 20411ce..f9ac2be 100644
--- a/main/logger.c
+++ b/main/logger.c
@@ -1433,6 +1433,9 @@
 			/* Console channels */
 			} else if (chan->type == LOGTYPE_CONSOLE && (chan->logmask & (1 << logmsg->level))) {
 				char linestr[128];
+				int has_file = !ast_strlen_zero(logmsg->file);
+				int has_line = (logmsg->line > 0);
+				int has_func = !ast_strlen_zero(logmsg->function);
 
 				/* If the level is verbose, then skip it */
 				if (logmsg->level == __LOG_VERBOSE)
@@ -1441,15 +1444,17 @@
 				/* Turn the numerical line number into a string */
 				snprintf(linestr, sizeof(linestr), "%d", logmsg->line);
 				/* Build string to print out */
-				snprintf(buf, sizeof(buf), "[%s] " COLORIZE_FMT "[%d]%s: " COLORIZE_FMT ":" COLORIZE_FMT " " COLORIZE_FMT ": %s",
-					 logmsg->date,
-					 COLORIZE(colors[logmsg->level], 0, logmsg->level_name),
-					 logmsg->lwp,
-					 call_identifier_str,
-					 COLORIZE(COLOR_BRWHITE, 0, logmsg->file),
-					 COLORIZE(COLOR_BRWHITE, 0, linestr),
-					 COLORIZE(COLOR_BRWHITE, 0, logmsg->function),
-					 logmsg->message);
+				snprintf(buf, sizeof(buf), "[%s] " COLORIZE_FMT "[%d]%s: " COLORIZE_FMT "%s" COLORIZE_FMT " " COLORIZE_FMT "%s %s",
+					logmsg->date,
+					COLORIZE(colors[logmsg->level], 0, logmsg->level_name),
+					logmsg->lwp,
+					call_identifier_str,
+					COLORIZE(COLOR_BRWHITE, 0, has_file ? logmsg->file : ""),
+					has_file ? ":" : "",
+					COLORIZE(COLOR_BRWHITE, 0, has_line ? linestr : ""),
+					COLORIZE(COLOR_BRWHITE, 0, has_func ? logmsg->function : ""),
+					has_func ? ":" : "",
+					logmsg->message);
 				/* Print out */
 				ast_console_puts_mutable(buf, logmsg->level);
 			/* File channels */
@@ -2044,7 +2049,7 @@
 #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");
@@ -2052,14 +2057,16 @@
 	}
 
 	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);
 
-		ast_std_free(strings);
+		ast_log(__LOG_ERROR, NULL, 0, NULL, "Got %d backtrace record%c\n", count - 3, count - 3 != 1 ? 's' : ' ');
+		for (i = 3; i < AST_VECTOR_SIZE(strings); i++) {
+			ast_log_safe(__LOG_ERROR, NULL, 0, NULL, "#%2d: [%p] %s\n", i - 3, bt->addresses[i], AST_VECTOR_GET(strings, i));
+		}
+		AST_VECTOR_CALLBACK_VOID(strings, ast_free);
+		AST_VECTOR_PTR_FREE(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
diff --git a/main/utils.c b/main/utils.c
index 9441187..5cabc24 100644
--- a/main/utils.c
+++ b/main/utils.c
@@ -965,7 +965,7 @@
 #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) {
@@ -979,11 +979,12 @@
 	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_VECTOR_CALLBACK_VOID(symbols, ast_free);
+		AST_VECTOR_PTR_FREE(symbols);
 	} else {
 		ast_str_append(str, 0, "\tCouldn't retrieve backtrace symbols\n");
 	}
diff --git a/tests/test_pbx.c b/tests/test_pbx.c
index df6b88d..a2f9118 100644
--- a/tests/test_pbx.c
+++ b/tests/test_pbx.c
@@ -345,8 +345,50 @@
 	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()K!!! (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;
@@ -356,6 +398,8 @@
 {
 	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;
 }
 

-- 
To view, visit https://gerrit.asterisk.org/10602
To unsubscribe, or for help writing mail filters, visit https://gerrit.asterisk.org/settings

Gerrit-Project: asterisk
Gerrit-Branch: 13
Gerrit-MessageType: newchange
Gerrit-Change-Id: I79d02862ddaa2423a0809caa4b3b85c128131621
Gerrit-Change-Number: 10602
Gerrit-PatchSet: 1
Gerrit-Owner: George Joseph <gjoseph at digium.com>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.digium.com/pipermail/asterisk-code-review/attachments/20181108/2c20da70/attachment-0001.html>


More information about the asterisk-code-review mailing list