Improved and portable ast_log recursion avoidance
authorCorey Farrell <git@cfware.com>
Fri, 27 Mar 2015 07:12:25 +0000 (07:12 +0000)
committerCorey Farrell <git@cfware.com>
Fri, 27 Mar 2015 07:12:25 +0000 (07:12 +0000)
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
........

Merged revisions 433523 from http://svn.asterisk.org/svn/asterisk/branches/13

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

include/asterisk/logger.h
include/asterisk/threadstorage.h
include/asterisk/utils.h
main/astobj2.c
main/hashtab.c
main/logger.c
main/strings.c

index feb9c7e..efaac48 100644 (file)
@@ -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 */
 typedef unsigned int ast_callid;
 
index e3ece8b..4d587a5 100644 (file)
@@ -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 */
index e4c4c8b..e48ca02 100644 (file)
@@ -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()
index 4ee1734..f1d5001 100644 (file)
@@ -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;
 
 /*!
index 4f52ec5..a35af67 100644 (file)
@@ -44,10 +44,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__)
index 90fb7f2..29122b5 100644 (file)
@@ -102,6 +102,7 @@ static struct {
 } logfiles = { 1 };
 
 static char hostname[MAXHOSTNAMELEN];
+AST_THREADSTORAGE_RAW(in_safe_log);
 
 enum logtypes {
        LOGTYPE_SYSLOG,
@@ -1719,6 +1720,32 @@ void ast_log(int level, const char *file, int line, const char *function, const
        va_end(ap);
 }
 
+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);
+       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);
+
+       /* 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, ast_callid callid, const char *fmt, ...)
 {
        va_list ap;
index 73892eb..b6b9fbc 100644 (file)
@@ -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;
                        }