Scope Trace: Make it easier to trace through synchronous tasks

Tracing through synchronous tasks was a little troublesome because
the new thread's stack counter reset to 0.  This change allows
a synchronous task to set its trace level to be the same as the
thread that pushed the task.  For now, the task's level has to be
passed in the task's data structure but a future enhancement to the
taskprocessor subsystem could automatically set the trace level
of the servant to be that of the caller.

This doesn't really make sense for async tasks because you never
know when they're going to run anyway.

Change-Id: Ib8049c0b815063a45d8c7b0cb4e30b7b87b1d825

diff --git a/include/asterisk/logger.h b/include/asterisk/logger.h
index 67e4df74f0dc1319976752be673c6e4d53006d2c..5514d8347cb1e83ff6af752aee257d0281993cbf 100644 (file)
--- a/include/asterisk/logger.h
+++ b/include/asterisk/logger.h
@@ -641,14 +641,16 @@ enum ast_trace_indent_type {
        AST_TRACE_INDENT_DEC_BEFORE,
        /*! Decrement the indent after printing the message */
        AST_TRACE_INDENT_DEC_AFTER,
+       /*! Set the indent to the one provided */
+       AST_TRACE_INDENT_PROVIDED,
        /*! Don't use or alter the level */
        AST_TRACE_INDENT_NONE,
 };
 
 #ifdef AST_DEVMODE
 
-void __attribute__((format (printf, 5, 6))) __ast_trace(const char *file, int line, const char *func,
-       enum ast_trace_indent_type indent_type, const char* format, ...);
+void __attribute__((format (printf, 6, 7))) __ast_trace(const char *file, int line, const char *func,
+       enum ast_trace_indent_type indent_type, unsigned long indent, const char* format, ...);
 
 /*!
  * \brief Print a trace message
@@ -661,7 +663,7 @@ void __attribute__((format (printf, 5, 6))) __ast_trace(const char *file, int li
  */
 #define ast_trace_raw(level, indent_type, ...) \
        if (TRACE_ATLEAST(level)) { \
-               __ast_trace(__FILE__, __LINE__, __PRETTY_FUNCTION__, indent_type, " " __VA_ARGS__); \
+               __ast_trace(__FILE__, __LINE__, __PRETTY_FUNCTION__, indent_type, 0, " " __VA_ARGS__); \
        }
 
 /*!
@@ -675,9 +677,41 @@ void __attribute__((format (printf, 5, 6))) __ast_trace(const char *file, int li
  */
 #define ast_trace(level, ...) \
        if (TRACE_ATLEAST(level)) { \
-               __ast_trace(__FILE__, __LINE__, __PRETTY_FUNCTION__, AST_TRACE_INDENT_SAME, " " __VA_ARGS__); \
+               __ast_trace(__FILE__, __LINE__, __PRETTY_FUNCTION__, AST_TRACE_INDENT_SAME, 0, " " __VA_ARGS__); \
        }
 
+/*!
+ * \brief Get the current indent level
+ *
+ * \returns The current indent level
+ */
+unsigned long _ast_trace_get_indent(void);
+#define ast_trace_get_indent() _ast_trace_get_indent()
+
+/*!
+ * \brief Set the current indent level
+ *
+ * \param indent The new indent level
+ */
+void _ast_trace_set_indent(unsigned long indent);
+#define ast_trace_set_indent(indent) _ast_trace_set_indent(indent)
+
+/*!
+ * \brief Increment the indent level
+ *
+ * \returns The new indent level
+ */
+unsigned long _ast_trace_inc_indent(void);
+#define ast_trace_inc_indent() _ast_trace_inc_indent()
+
+/*!
+ * \brief Decrement the indent level
+ *
+ * \returns The new indent level
+ */
+unsigned long _ast_trace_dec_indent(void);
+#define ast_trace_dec_indent() _ast_trace_dec_indent()
+
 /*!
  * \brief Print a trace message with details when a scope is entered or existed.
  *
@@ -702,14 +736,14 @@ void __attribute__((format (printf, 5, 6))) __ast_trace(const char *file, int li
        auto void __scopevar ## __LINE__ ## __EXIT(void * v); \
        void __scopevar ## __LINE__ ## __EXIT(void * v __attribute__((unused))) { \
                if (TRACE_ATLEAST(level)) { \
-                       __ast_trace(__FILE__, __LINE__, __trace_funcname, AST_TRACE_INDENT_DEC_BEFORE, " " __VA_ARGS__); \
+                       __ast_trace(__FILE__, __LINE__, __trace_funcname, AST_TRACE_INDENT_DEC_BEFORE, 0, " " __VA_ARGS__); \
                } \
        } \
        void *__scopevar ## __LINE__ ## __TRACER __attribute__((cleanup(__scopevar ## __LINE__ ## __EXIT))) = (void *) __PRETTY_FUNCTION__ ; \
        auto int __scopevar ## __LINE__ ## __ENTER(void); \
        int __scopevar ## __LINE__ ## __ENTER(void) { \
                if (TRACE_ATLEAST(level)) { \
-                       __ast_trace(__FILE__, __LINE__, __trace_funcname, AST_TRACE_INDENT_INC_AFTER, " " __VA_ARGS__); \
+                       __ast_trace(__FILE__, __LINE__, __trace_funcname, AST_TRACE_INDENT_INC_AFTER, 0, " " __VA_ARGS__); \
                } \
                return 0; \
        } \
@@ -730,8 +764,16 @@ void __attribute__((format (printf, 5, 6))) __ast_trace(const char *file, int li
  */
 #define SCOPE_ENTER(level, ...) \
        int __scope_level = level; \
+       int __scope_task = 0; \
+       if (TRACE_ATLEAST(level)) { \
+               __ast_trace(__FILE__, __LINE__, __PRETTY_FUNCTION__, AST_TRACE_INDENT_INC_AFTER, 0, " " __VA_ARGS__); \
+       } \
+
+#define SCOPE_ENTER_TASK(level, indent, ...) \
+       int __scope_level = level; \
+       int __scope_task = 1; \
        if (TRACE_ATLEAST(level)) { \
-               __ast_trace(__FILE__, __LINE__, __PRETTY_FUNCTION__, AST_TRACE_INDENT_INC_AFTER, " " __VA_ARGS__); \
+               __ast_trace(__FILE__, __LINE__, __PRETTY_FUNCTION__, AST_TRACE_INDENT_PROVIDED, indent, " " __VA_ARGS__); \
        } \
 
 /*!
@@ -745,7 +787,10 @@ void __attribute__((format (printf, 5, 6))) __ast_trace(const char *file, int li
  */
 #define SCOPE_EXIT(...) \
        if (TRACE_ATLEAST(__scope_level)) { \
-               __ast_trace(__FILE__, __LINE__, __PRETTY_FUNCTION__, AST_TRACE_INDENT_DEC_BEFORE, " " __VA_ARGS__); \
+               __ast_trace(__FILE__, __LINE__, __PRETTY_FUNCTION__, AST_TRACE_INDENT_DEC_BEFORE, 0, " " __VA_ARGS__); \
+               if (__scope_task) { \
+                       _ast_trace_set_indent(0); \
+               } \
        } \
 
 /*!
@@ -770,7 +815,10 @@ void __attribute__((format (printf, 5, 6))) __ast_trace(const char *file, int li
  */
 #define SCOPE_EXIT_EXPR(__expr, ...) \
        if (TRACE_ATLEAST(__scope_level)) { \
-               __ast_trace(__FILE__, __LINE__, __PRETTY_FUNCTION__, AST_TRACE_INDENT_DEC_BEFORE, " " __VA_ARGS__); \
+               __ast_trace(__FILE__, __LINE__, __PRETTY_FUNCTION__, AST_TRACE_INDENT_DEC_BEFORE, 0, " " __VA_ARGS__); \
+               if (__scope_task) { \
+                       _ast_trace_set_indent(0); \
+               } \
        } \
        __expr
 
@@ -786,7 +834,10 @@ void __attribute__((format (printf, 5, 6))) __ast_trace(const char *file, int li
  */
 #define SCOPE_EXIT_RTN(...) \
        if (TRACE_ATLEAST(__scope_level)) { \
-               __ast_trace(__FILE__, __LINE__, __PRETTY_FUNCTION__, AST_TRACE_INDENT_DEC_BEFORE, " " __VA_ARGS__); \
+               __ast_trace(__FILE__, __LINE__, __PRETTY_FUNCTION__, AST_TRACE_INDENT_DEC_BEFORE, 0, " " __VA_ARGS__); \
+               if (__scope_task) { \
+                       _ast_trace_set_indent(0); \
+               } \
        } \
        return
 
@@ -803,19 +854,27 @@ void __attribute__((format (printf, 5, 6))) __ast_trace(const char *file, int li
  */
 #define SCOPE_EXIT_RTN_VALUE(__return_value, ...) \
        if (TRACE_ATLEAST(__scope_level)) { \
-               __ast_trace(__FILE__, __LINE__, __PRETTY_FUNCTION__, AST_TRACE_INDENT_DEC_BEFORE, " " __VA_ARGS__); \
+               __ast_trace(__FILE__, __LINE__, __PRETTY_FUNCTION__, AST_TRACE_INDENT_DEC_BEFORE, 0, " " __VA_ARGS__); \
+               if (__scope_task) { \
+                       _ast_trace_set_indent(0); \
+               } \
        } \
        return(__return_value)
 
 #else
 #define ast_trace_raw(__level, __indent_type, ...)
 #define ast_trace(__level, ...)
+#define ast_trace_get_indent() (0)
+#define ast_trace_set_indent(indent)
+#define ast_trace_inc_indent()
+#define ast_trace_dec_indent()
 #define SCOPE_TRACE(__level, ...)
 #define SCOPE_ENTER(level, ...)
+#define SCOPE_ENTER_TASK(level, indent, ...)
 #define SCOPE_EXIT(...)
-#define SCOPE_EXIT_EXPR(__expr, ...)
-#define SCOPE_EXIT_RTN(...)
-#define SCOPE_EXIT_RTN_VALUE(__return_value, ...)
+#define SCOPE_EXIT_EXPR(__expr, ...) __expr
+#define SCOPE_EXIT_RTN(...) return
+#define SCOPE_EXIT_RTN_VALUE(__return_value, ...) return __return_value
 #endif
 
 #if defined(__cplusplus) || defined(c_plusplus)

diff --git a/main/logger.c b/main/logger.c
index c66d820fba515aa036dc0a04f6f8edfd3ee0ee32..8894b05ae3cbce19b4959f5797c3a504ca90459d 100644 (file)
--- a/main/logger.c
+++ b/main/logger.c
@@ -2287,9 +2287,36 @@ static void update_logchannels(void)
 AST_THREADSTORAGE_RAW(trace_indent);
 #define LOTS_O_SPACES "                                                                                            "
 
+unsigned long _ast_trace_get_indent(void)
+{
+       return (unsigned long)ast_threadstorage_get_ptr(&trace_indent);
+}
+
+void _ast_trace_set_indent(unsigned long indent)
+{
+       ast_threadstorage_set_ptr(&trace_indent, (void*)indent);
+}
+
+unsigned long _ast_trace_inc_indent(void)
+{
+       unsigned long indent = (unsigned long)ast_threadstorage_get_ptr(&trace_indent);
+       indent++;
+       ast_threadstorage_set_ptr(&trace_indent, (void*)indent);
+
+       return indent;
+}
+
+unsigned long _ast_trace_dec_indent(void)
+{
+       unsigned long indent = (unsigned long)ast_threadstorage_get_ptr(&trace_indent);
+       indent--;
+       ast_threadstorage_set_ptr(&trace_indent, (void*)indent);
+
+       return indent;
+}
 
 void __ast_trace(const char *file, int line, const char *func, enum ast_trace_indent_type indent_type,
-       const char* format, ...)
+       unsigned long new_indent, const char* format, ...)
 {
        va_list ap;
        unsigned long indent = (unsigned long)ast_threadstorage_get_ptr(&trace_indent);
@@ -2300,11 +2327,13 @@ void __ast_trace(const char *file, int line, const char *func, enum ast_trace_in
                return;
        }
 
-       if (indent_type == AST_TRACE_INDENT_INC_BEFORE) {
+       if (indent_type == AST_TRACE_INDENT_PROVIDED) {
+               indent = new_indent;
+               ast_threadstorage_set_ptr(&trace_indent, (void*)indent);
+       } else if (indent_type == AST_TRACE_INDENT_INC_BEFORE) {
                indent++;
                ast_threadstorage_set_ptr(&trace_indent, (void*)indent);
-       }
-       if (indent_type == AST_TRACE_INDENT_DEC_BEFORE) {
+       } else if (indent_type == AST_TRACE_INDENT_DEC_BEFORE) {
                indent--;
                ast_threadstorage_set_ptr(&trace_indent, (void*)indent);
        }
@@ -2316,6 +2345,7 @@ void __ast_trace(const char *file, int line, const char *func, enum ast_trace_in
                break;
        case AST_TRACE_INDENT_INC_BEFORE:
        case AST_TRACE_INDENT_INC_AFTER:
+       case AST_TRACE_INDENT_PROVIDED:
                direction = "--> ";
                break;
        case AST_TRACE_INDENT_DEC_BEFORE:
@@ -2327,7 +2357,7 @@ void __ast_trace(const char *file, int line, const char *func, enum ast_trace_in
        ast_str_set(&fmt, 0, "%2d %-.*s%s%s:%d %s: %s", (int)indent, (indent_type == AST_TRACE_INDENT_NONE ? 0 : (int)(indent * 4)),
                LOTS_O_SPACES, direction, file, line, func, S_OR(ast_skip_blanks(format), "\n"));
 
-       if (indent_type == AST_TRACE_INDENT_INC_AFTER) {
+       if (indent_type == AST_TRACE_INDENT_INC_AFTER || indent_type == AST_TRACE_INDENT_PROVIDED) {
                indent++;
                ast_threadstorage_set_ptr(&trace_indent, (void*)indent);
        }