logger.h: Add ability to change the prefix on SCOPE_TRACE output
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 b52e07ee1b)
This commit is contained in:
George Joseph
Asterisk Development Team
parent
393d8cb947
commit
f0edab9f3e
|
|
@ -526,19 +526,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:
|
||||
\verbatim CLI> core set trace <trace_level> [ module ] \endverbatim
|
||||
|
||||
- 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.
|
||||
|
|
@ -558,29 +559,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
|
||||
|
|
@ -594,11 +595,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
|
||||
|
|
@ -608,10 +608,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
|
||||
|
|
@ -666,7 +718,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__); \
|
||||
}
|
||||
|
||||
/*!
|
||||
|
|
@ -680,7 +732,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__); \
|
||||
}
|
||||
|
||||
/*!
|
||||
|
|
@ -768,7 +820,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, ...) \
|
||||
|
|
@ -776,7 +828,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__); \
|
||||
} \
|
||||
|
||||
/*!
|
||||
|
|
@ -790,7 +842,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); \
|
||||
} \
|
||||
|
|
@ -819,7 +871,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); \
|
||||
} \
|
||||
|
|
@ -838,7 +890,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); \
|
||||
} \
|
||||
|
|
@ -858,7 +910,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); \
|
||||
} \
|
||||
|
|
@ -943,4 +995,8 @@ unsigned long _ast_trace_dec_indent(void);
|
|||
}
|
||||
#endif
|
||||
|
||||
/*!
|
||||
* @}
|
||||
*/
|
||||
|
||||
#endif /* _ASTERISK_LOGGER_H */
|
||||
|
|
|
|||
Loading…
Reference in New Issue