From 955b7b4fdbed9ca2d79091c3d33b8331c1fdf7ff Mon Sep 17 00:00:00 2001 From: George Joseph <gjoseph@digium.com> Date: Sun, 5 Jul 2020 17:51:04 -0600 Subject: [PATCH] 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 --- include/asterisk/logger.h | 87 ++++++++++++++++++++++++++++++++------- main/logger.c | 40 +++++++++++++++--- 2 files changed, 108 insertions(+), 19 deletions(-) diff --git a/include/asterisk/logger.h b/include/asterisk/logger.h index 67e4df74f0..5514d8347c 100644 --- 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 c66d820fba..8894b05ae3 100644 --- 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); } -- GitLab