Improved and portable ast_log recursion avoidance

This introduces a new logger routine ast_log_safe.  This routine should be
used for all error messages in code that can be run as a result of ast_log.
ast_log_safe does nothing if run recursively.  All error logging in
astobj2.c, strings.c and utils.h have been switched to ast_log_safe.

This required adding support for raw threadstorage.  This provides direct
access to the void* pointer in threadstorage.  In ast_log_safe, NULL is used
to signify that this thread is not already running ast_log_safe, (void*)1 when
it is already running.  This was done since it's critical that ast_log_safe
do nothing that could log during recursion checking.

ASTERISK-24155 #close
Reported by: Timo Teräs
Review: https://reviewboard.asterisk.org/r/4502/
........

Merged revisions 433522 from http://svn.asterisk.org/svn/asterisk/branches/11


git-svn-id: https://origsvn.digium.com/svn/asterisk/branches/13@433523 65c4cc65-6c06-0410-ace0-fbb531ad65f3

include/asterisk/logger.h

@@ -62,6 +62,17 @@ extern "C" {
 void ast_log(int level, const char *file, int line, const char *function, const char *fmt, ...)
 	__attribute__((format(printf, 5, 6)));
 
+/*!
+ * \brief Used for sending a log message with protection against recursion.
+ *
+ * \note This function should be used by all error messages that might be directly
+ * or indirectly caused by logging.
+ *
+ * \see ast_log for documentation on the parameters.
+ */
+void ast_log_safe(int level, const char *file, int line, const char *function, const char *fmt, ...)
+	__attribute__((format(printf, 5, 6)));
+
 /* XXX needs documentation */
 struct ast_callid;
 

include/asterisk/threadstorage.h

@@ -84,6 +84,8 @@ void __ast_threadstorage_object_replace(void *key_old, void *key_new, size_t len
 	AST_THREADSTORAGE_CUSTOM_SCOPE(name, NULL, ast_free_ptr,) 
 #define AST_THREADSTORAGE_EXTERNAL(name) \
 	extern struct ast_threadstorage name
+#define AST_THREADSTORAGE_RAW(name) \
+	AST_THREADSTORAGE_CUSTOM_SCOPE(name, NULL, NULL,)
 
 /*!
  * \brief Define a thread storage variable, with custom initialization and cleanup
@@ -216,4 +218,42 @@ void *__ast_threadstorage_get(struct ast_threadstorage *ts, size_t init_size, co
 #define ast_threadstorage_get(ts, init_size) __ast_threadstorage_get(ts, init_size, __FILE__, __PRETTY_FUNCTION__, __LINE__)
 #endif /* defined(DEBUG_THREADLOCALS) */
 
+/*!
+ * \brief Retrieve a raw pointer from threadstorage.
+ * \param ts Threadstorage object to operate on.
+ *
+ * \return A pointer associated with the current thread, NULL
+ * if no pointer is associated yet.
+ *
+ * \note This should only be used on threadstorage declared
+ * by AST_THREADSTORAGE_RAW unless you really know what
+ * you are doing.
+ */
+AST_INLINE_API(
+void *ast_threadstorage_get_ptr(struct ast_threadstorage *ts),
+{
+	pthread_once(&ts->once, ts->key_init);
+	return pthread_getspecific(ts->key);
+}
+)
+
+/*!
+ * \brief Set a raw pointer from threadstorage.
+ * \param ts Threadstorage object to operate on.
+ *
+ * \retval 0 Success
+ * \retval non-zero Failure
+ *
+ * \note This should only be used on threadstorage declared
+ * by AST_THREADSTORAGE_RAW unless you really know what
+ * you are doing.
+ */
+AST_INLINE_API(
+int ast_threadstorage_set_ptr(struct ast_threadstorage *ts, void *ptr),
+{
+	pthread_once(&ts->once, ts->key_init);
+	return pthread_setspecific(ts->key, ptr);
+}
+)
+
 #endif /* ASTERISK_THREADSTORAGE_H */

include/asterisk/utils.h

@@ -25,7 +25,6 @@
 
 #include "asterisk/network.h"
 
-#include <execinfo.h>
 #include <time.h>	/* we want to override localtime_r */
 #include <unistd.h>
 #include <string.h>
@@ -526,26 +525,8 @@ long int ast_random(void);
 #define ast_free free
 #define ast_free_ptr ast_free
 
-/*
- * This buffer is in static memory. We never intend to read it,
- * nor do we care about multiple threads writing to it at the
- * same time. We only want to know if we're recursing too deep
- * already. 60 entries should be more than enough.  Function
- * call depth rarely exceeds 20 or so.
- */
-#define _AST_MEM_BACKTRACE_BUFLEN 60
-extern void *_ast_mem_backtrace_buffer[_AST_MEM_BACKTRACE_BUFLEN];
-
-/*
- * Ok, this sucks. But if we're already out of mem, we don't
- * want the logger to create infinite recursion (and a crash).
- */
 #define MALLOC_FAILURE_MSG \
-	do { \
-		if (backtrace(_ast_mem_backtrace_buffer, _AST_MEM_BACKTRACE_BUFLEN) < _AST_MEM_BACKTRACE_BUFLEN) { \
-			ast_log(LOG_ERROR, "Memory Allocation Failure in function %s at line %d of %s\n", func, lineno, file); \
-		} \
-	} while (0)
+	ast_log_safe(LOG_ERROR, "Memory Allocation Failure in function %s at line %d of %s\n", func, lineno, file)
 
 /*!
  * \brief A wrapper for malloc()

main/astobj2.c

@@ -36,6 +36,9 @@ ASTERISK_FILE_VERSION(__FILE__, "$Revision$")
 #include "asterisk/cli.h"
 #include "asterisk/paths.h"
 
+/* Use ast_log_safe in place of ast_log. */
+#define ast_log ast_log_safe
+
 static FILE *ref_log;
 
 /*!

main/hashtab.c

@@ -43,10 +43,6 @@ ASTERISK_FILE_VERSION(__FILE__, "$Revision$")
 #include "asterisk/hashtab.h"
 
 
-#ifndef __AST_DEBUG_MALLOC
-void *_ast_mem_backtrace_buffer[_AST_MEM_BACKTRACE_BUFLEN];
-#endif
-
 #if (defined(MALLOC_DEBUG) && !defined(STANDALONE))
 static void _ast_hashtab_resize(struct ast_hashtab *tab, const char *file, int lineno, const char *func);
 #define ast_hashtab_resize(a)	_ast_hashtab_resize(a,__FILE__, __LINE__, __PRETTY_FUNCTION__)

main/logger.c

@@ -107,6 +107,7 @@ static struct {
 } logfiles = { 1 };
 
 static char hostname[MAXHOSTNAMELEN];
+AST_THREADSTORAGE_RAW(in_safe_log);
 
 enum logtypes {
 	LOGTYPE_SYSLOG,
@@ -1766,6 +1767,36 @@ void ast_log(int level, const char *file, int line, const char *function, const
 	}
 }
 
+void ast_log_safe(int level, const char *file, int line, const char *function, const char *fmt, ...)
+{
+	va_list ap;
+	void *recursed = ast_threadstorage_get_ptr(&in_safe_log);
+	struct ast_callid *callid;
+
+	if (recursed) {
+		return;
+	}
+
+	if (ast_threadstorage_set_ptr(&in_safe_log, (void*)1)) {
+		/* We've failed to set the flag that protects against
+		 * recursion, so bail. */
+		return;
+	}
+
+	callid = ast_read_threadstorage_callid();
+
+	va_start(ap, fmt);
+	ast_log_full(level, file, line, function, callid, fmt, ap);
+	va_end(ap);
+
+	if (callid) {
+		ast_callid_unref(callid);
+	}
+
+	/* Clear flag so the next allocation failure can be logged. */
+	ast_threadstorage_set_ptr(&in_safe_log, NULL);
+}
+
 void ast_log_callid(int level, const char *file, int line, const char *function, struct ast_callid *callid, const char *fmt, ...)
 {
 	va_list ap;

main/strings.c

@@ -87,9 +87,6 @@ int __ast_str_helper(struct ast_str **buf, ssize_t max_len,
 			} else if (max_len == 0) {	/* if unbounded, give more room for next time */
 				need += 16 + need / 4;
 			}
-			if (0) {	/* debugging */
-				ast_verbose("extend from %d to %d\n", len, need);
-			}
 			if (
 #if (defined(MALLOC_DEBUG) && !defined(STANDALONE))
 					_ast_str_make_space(buf, need, file, lineno, function)
@@ -97,7 +94,7 @@ int __ast_str_helper(struct ast_str **buf, ssize_t max_len,
 					ast_str_make_space(buf, need)
 #endif
 				) {
-				ast_verbose("failed to extend from %d to %d\n", len, need);
+				ast_log_safe(LOG_VERBOSE, "failed to extend from %d to %d\n", len, need);
 				va_end(aq);
 				return AST_DYNSTR_BUILD_FAILED;
 			}