]> git.ipfire.org Git - thirdparty/asterisk.git/commitdiff
logger.h: Add ability to change the prefix on SCOPE_TRACE output
authorGeorge Joseph <gjoseph@sangoma.com>
Thu, 5 Oct 2023 14:18:17 +0000 (08:18 -0600)
committerAsterisk Development Team <asteriskteam@digium.com>
Wed, 21 Feb 2024 13:35:03 +0000 (13:35 +0000)
You can now define the _TRACE_PREFIX_ macro to change the
default trace line prefix of "file:line function" to
something else.  Full documentation in logger.h.

(cherry picked from commit 20b06e7bb5a88c413882031239ddf00ae380246d)

include/asterisk/logger.h

index 95a555e2d33766e37839fbc1d02f14f31d47d0e9..d75280d91fe53ebd616e48d2ffad7f34dad50083 100644 (file)
@@ -538,18 +538,20 @@ void ast_logger_set_queue_limit(int queue_limit);
 int ast_logger_get_queue_limit(void);
 
 
-/*!
- \page Scope_Trace Scope Trace
+/*! \defgroup Scope_Trace Scope Trace
+ * @{
+\page basic Basic Usage
 
 The Scope Trace facility allows you to instrument code and output scope entry
 and exit messages with associated data.
-
+\par
 To start using it:
- * You must have used --enable-dev-mode.
- * In logger.conf, set a logger channel to output the "trace" level.
- * Instrument your code as specified below.
- * Use the cli or cli.conf to enable tracing: CLI> core set trace <trace_level> [ module ]
-
+ - You must have used --enable-dev-mode.
+ - In logger.conf, set a logger channel to output the "trace" level.
+ - Instrument your code as specified below.
+ - Use the cli or cli.conf to enable tracing:
+\verbatim CLI> core set trace <trace_level> [ module ] \endverbatim
+\par
 Its simplest usage requires only 1 macro call that...
        - Registers a destructor for a special variable that gets called when the
          variable goes out of scope.  Uses the same principle as RAII_VAR.
@@ -569,29 +571,29 @@ static struct pjmedia_sdp_session *create_local_sdp(pjsip_inv_session *inv,
 }
 \endcode
 would produce...
-\b [2020-05-17 15:16:51 -0600] TRACE[953402] : --> res_pjsip_session.c:4283 create_local_sdp PJSIP/1173-00000001
-\b [2020-05-17 15:16:51 -0600] TRACE[953402] : <-- res_pjsip_session.c:4283 create_local_sdp PJSIP/1173-00000001
+\verbatim
+[2020-05-17 15:16:51 -0600] TRACE[953402] : --> res_pjsip_session.c:4283 create_local_sdp PJSIP/1173-00000001
+[2020-05-17 15:16:51 -0600] TRACE[953402] : <-- res_pjsip_session.c:4283 create_local_sdp PJSIP/1173-00000001
+\endverbatim
 
 There is one odd bit.  There's no way to capture the line number of there the scope exited
 so it's always going to be the line where SCOPE_TRACE is located.
-
+\par
 Similar to RAII_VAR, any block scope can be traced including "if", "for", "while", etc.
 \note "case" statements don't create a scope block by themselves but you can create
 a block for it, or use the generic trace functions mentioned below.
 
-Scope Output and Level:
-
+\par Scope Output and Level:
 Rather than sending trace messages to the debug facility, a new facility "trace" has been
 added to logger.  A corresponding CLI command "core set trace", and a corresponding "trace"
 parameter in asterisk.conf were added.  This allows a separate log channel to be created
 just for storing trace messages.  The levels are the same as those for debug and verbose.
 
-Scope Indenting:
-
+\par Scope Indenting:
 Each time SCOPE_TRACE or SCOPE_TRACE is called, a thread-local indent value is
 incremented on scope enter, and decremented on scope exit.  This allows output
 like the following (timestamp omitted for brevity):
-
+\verbatim
 TRACE[953402] : --> res_pjsip_session.c:3940 session_inv_on_tsx_state_changed PJSIP/1173-00000001 TSX State: Proceeding  Inv State: CALLING
 TRACE[953402] :        --> res_pjsip_session.c:3680 handle_incoming PJSIP/1173-00000001
 TRACE[953402] :                --> res_pjsip_session.c:3661 handle_incoming_response PJSIP/1173-00000001 Method: INVITE Status: 100
@@ -605,11 +607,10 @@ TRACE[953402] :                   <-- res_pjsip_session.c:3669 handle_incoming_response PJSIP/1
 TRACE[953402] :                <-- res_pjsip_session.c:3661 handle_incoming_response PJSIP/1173-00000001 Method: INVITE Status: 100
 TRACE[953402] :        <-- res_pjsip_session.c:3680 handle_incoming PJSIP/1173-00000001
 TRACE[953402] : <-- res_pjsip_session.c:3940 session_inv_on_tsx_state_changed PJSIP/1173-00000001 TSX State: Proceeding  Inv State: CALLING
-
+\endverbatim
 \note The trace level indicates which messages to print and has no effect on indent.
 
-Generic Trace Messages:
-
+\par Generic Trace Messages:
 Sometimes you may just want to print a message to the trace log with the appropriate indent
 such as when executing a "case" clause in a "switch" statement. For example, the deepest
 message in the sample output above (chan_pjsip.c:3245) is just a single message instead of
@@ -619,10 +620,62 @@ an entry/exit message.  To do so, you can use the ast_trace macros...
                (int)rdata->msg_info.cseq->method.name.slen, rdata->msg_info.cseq->method.name.ptr, status.code);
 \endcode
 
-/note Final note:  The trace facility, like debug, is only available when AST_DEVMODE is defined.
+\note Final note:  The trace facility, like debug, is only available when AST_DEVMODE is defined.
+
+*/
 
+/*!
+\page TRACE_PREFIX TRACE_PREFIX
+The default prefix to each log and trace line is
+<tt>"filename:line function"</tt> which is defined in the
+macro \c _A_ at the top of this file:
+\code
+#define _A_ __FILE__, __LINE__, __FUNCTION__
+\endcode
+They become 3 arguments to the __ast_trace function
+and most of the ast_log* functions.  For scope tracing,
+that may be unnecessary clutter in the trace output so
+you can now customise that with the \c _TRACE_PREFIX_
+macro.  Like \c _A_, it MUST resolve to 3 arguments:
+\verbatim
+const char *, int, const char *
+\endverbatim
+so the minimum would be:
+\code
+#define _TRACE_PREFIX_ "",0,""
+\endcode
+Normally you should define \c _TRACE_PREFIX_ in your source
+file before including logger.h.
+\code
+#define _TRACE_PREFIX_ "", __LINE__, ""
+#include "asterisk/logger.h"
+\endcode
+You can also define it later in your source file
+but because logger.h sets it to a default value, you'll
+have to undefine it first, then define it your your liking.
+If you want to go back to the default, you'll have to
+undefine it again, then define it to \c _TRACE_PREFIX_DEFAULT_.
+\code
+#undef _TRACE_PREFIX_
+#define _TRACE_PREFIX_ "", __LINE__, ""
+<code>
+#undef _TRACE_PREFIX_
+#define _TRACE_PREFIX_ _TRACE_PREFIX_DEFAULT_
+\endcode
+
+\note Macros have a compilation unit scope so
+defining \c _TRACE_PREFIX_ in one source file does NOT
+make it apply to any others.  So if you define it
+in source file A, then call a function in source
+file B, the trace output from B will display based
+on how \c _TRACE_PREFIX_ is defined in B, not A.
  */
 
+#define _TRACE_PREFIX_DEFAULT_ _A_
+#ifndef _TRACE_PREFIX_
+#define _TRACE_PREFIX_ _TRACE_PREFIX_DEFAULT_
+#endif
+
 /*!
  * \brief Get the trace level for a module
  * \param module the name of module
@@ -677,7 +730,7 @@ void __attribute__((format (printf, 6, 7))) __ast_trace(const char *file, int li
 #define ast_trace_raw(level, indent_type, ...) \
        ast_debug(level < 0 ? __scope_level : level, " " __VA_ARGS__); \
        if (TRACE_ATLEAST(level < 0 ? __scope_level : level)) { \
-               __ast_trace(_A_, indent_type, 0, " " __VA_ARGS__); \
+               __ast_trace(_TRACE_PREFIX_, indent_type, 0, " " __VA_ARGS__); \
        }
 
 /*!
@@ -691,7 +744,7 @@ void __attribute__((format (printf, 6, 7))) __ast_trace(const char *file, int li
 #define ast_trace(level, ...) \
        ast_debug(level < 0 ? __scope_level : level, " " __VA_ARGS__); \
        if (TRACE_ATLEAST(level < 0 ? __scope_level : level)) { \
-               __ast_trace(_A_, AST_TRACE_INDENT_SAME, 0, " " __VA_ARGS__); \
+               __ast_trace(_TRACE_PREFIX_, AST_TRACE_INDENT_SAME, 0, " " __VA_ARGS__); \
        }
 
 /*!
@@ -779,7 +832,7 @@ unsigned long _ast_trace_dec_indent(void);
        int __scope_task = 0; \
        ast_debug(__scope_level, " " __VA_ARGS__); \
        if (TRACE_ATLEAST(level)) { \
-               __ast_trace(_A_, AST_TRACE_INDENT_INC_AFTER, 0, " " __VA_ARGS__); \
+               __ast_trace(_TRACE_PREFIX_, AST_TRACE_INDENT_INC_AFTER, 0, " " __VA_ARGS__); \
        } \
 
 #define SCOPE_ENTER_TASK(level, indent, ...) \
@@ -787,7 +840,7 @@ unsigned long _ast_trace_dec_indent(void);
        int __scope_task = 1; \
        ast_debug(__scope_level, " " __VA_ARGS__); \
        if (TRACE_ATLEAST(level)) { \
-               __ast_trace(_A_, AST_TRACE_INDENT_PROVIDED, indent, " " __VA_ARGS__); \
+               __ast_trace(_TRACE_PREFIX_, AST_TRACE_INDENT_PROVIDED, indent, " " __VA_ARGS__); \
        } \
 
 /*!
@@ -801,7 +854,7 @@ unsigned long _ast_trace_dec_indent(void);
 #define SCOPE_EXIT(...) \
        ast_debug(__scope_level, " " __VA_ARGS__); \
        if (TRACE_ATLEAST(__scope_level)) { \
-               __ast_trace(_A_, AST_TRACE_INDENT_DEC_BEFORE, 0, " " __VA_ARGS__); \
+               __ast_trace(_TRACE_PREFIX_, AST_TRACE_INDENT_DEC_BEFORE, 0, " " __VA_ARGS__); \
                if (__scope_task) { \
                        _ast_trace_set_indent(0); \
                } \
@@ -830,7 +883,7 @@ unsigned long _ast_trace_dec_indent(void);
 #define SCOPE_EXIT_EXPR(__expr, ...) \
        ast_debug(__scope_level, " " __VA_ARGS__); \
        if (TRACE_ATLEAST(__scope_level)) { \
-               __ast_trace(_A_, AST_TRACE_INDENT_DEC_BEFORE, 0, " " __VA_ARGS__); \
+               __ast_trace(_TRACE_PREFIX_, AST_TRACE_INDENT_DEC_BEFORE, 0, " " __VA_ARGS__); \
                if (__scope_task) { \
                        _ast_trace_set_indent(0); \
                } \
@@ -849,7 +902,7 @@ unsigned long _ast_trace_dec_indent(void);
 #define SCOPE_EXIT_RTN(...) \
        ast_debug(__scope_level, " " __VA_ARGS__); \
        if (TRACE_ATLEAST(__scope_level)) { \
-               __ast_trace(_A_, AST_TRACE_INDENT_DEC_BEFORE, 0, " " __VA_ARGS__); \
+               __ast_trace(_TRACE_PREFIX_, AST_TRACE_INDENT_DEC_BEFORE, 0, " " __VA_ARGS__); \
                if (__scope_task) { \
                        _ast_trace_set_indent(0); \
                } \
@@ -869,7 +922,7 @@ unsigned long _ast_trace_dec_indent(void);
 #define SCOPE_EXIT_RTN_VALUE(__return_value, ...) \
        ast_debug(__scope_level, " " __VA_ARGS__); \
        if (TRACE_ATLEAST(__scope_level)) { \
-               __ast_trace(_A_, AST_TRACE_INDENT_DEC_BEFORE, 0, " " __VA_ARGS__); \
+               __ast_trace(_TRACE_PREFIX_, AST_TRACE_INDENT_DEC_BEFORE, 0, " " __VA_ARGS__); \
                if (__scope_task) { \
                        _ast_trace_set_indent(0); \
                } \
@@ -954,4 +1007,8 @@ unsigned long _ast_trace_dec_indent(void);
 }
 #endif
 
+/*!
+ *  @}
+ */
+
 #endif /* _ASTERISK_LOGGER_H */