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/


git-svn-id: https://origsvn.digium.com/svn/asterisk/branches/11@433522 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
@@ -214,4 +216,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

@@ -495,7 +495,8 @@ long int ast_random(void);
 #define ast_free_ptr ast_free
 
 #define MALLOC_FAILURE_MSG \
-	ast_log(LOG_ERROR, "Memory Allocation Failure in function %s at line %d of %s\n", func, lineno, file);
+	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

@@ -33,6 +33,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
+
 #if defined(TEST_FRAMEWORK)
 /* We are building with the test framework enabled so enable AO2 debug tests as well. */
 #define AO2_DEBUG 1

main/logger.c

@@ -104,6 +104,7 @@ static struct {
 } logfiles = { 1 };
 
 static char hostname[MAXHOSTNAMELEN];
+AST_THREADSTORAGE_RAW(in_safe_log);
 
 enum logtypes {
 	LOGTYPE_SYSLOG,
@@ -1634,6 +1635,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;
 			}

utils/refcounter.c

@@ -259,6 +259,18 @@ void ast_log(int level, const char *file, int line, const char *function, const
 	va_end(vars);
 }
 
+void ast_log_safe(int level, const char *file, int line, const char *function, const char *fmt, ...)
+{
+	va_list vars;
+	va_start(vars,fmt);
+	printf("LOG: lev:%d file:%s  line:%d func: %s  ",
+		   level, file, line, function);
+	vprintf(fmt, vars);
+	fflush(stdout);
+	va_end(vars);
+}
+
+
 void __ast_verbose(const char *file, int line, const char *func, int level, const char *fmt, ...)
 {
         va_list vars;