Asterisk - The Open Source Telephony Project GIT-master-0644429
Macros | Enumerations | Functions
Scope Trace

Macros

#define _TRACE_PREFIX_   _TRACE_PREFIX_DEFAULT_
 
#define _TRACE_PREFIX_DEFAULT_   _A_
 
#define ast_trace(level, ...)    ast_debug(level < 0 ? __scope_level : level, " " __VA_ARGS__)
 
#define ast_trace_dec_indent()
 
#define ast_trace_get_indent()   (0)
 
#define ast_trace_inc_indent()
 
#define ast_trace_log(__level, __log_level, ...)
 
#define ast_trace_raw(level, indent_type, ...)    ast_debug(level < 0 ? __scope_level : level, " " __VA_ARGS__)
 
#define ast_trace_set_indent(indent)
 
#define SCOPE_CALL(level, __funcname, ...)    __funcname(__VA_ARGS__)
 
#define SCOPE_CALL_WITH_INT_RESULT(level, __funcname, ...)    __funcname(__VA_ARGS__)
 
#define SCOPE_CALL_WITH_RESULT(level, __var, __funcname, ...)    __var = __funcname(__VA_ARGS__)
 
#define SCOPE_ENTER(level, ...)
 
#define SCOPE_ENTER_TASK(level, indent, ...)
 
#define SCOPE_EXIT(...)    ast_debug(__scope_level, " " __VA_ARGS__)
 
#define SCOPE_EXIT_EXPR(__expr, ...)
 
#define SCOPE_EXIT_LOG(__log_level, ...)
 
#define SCOPE_EXIT_LOG_EXPR(__expr, __log_level, ...)
 
#define SCOPE_EXIT_LOG_RTN(__log_level, ...)
 
#define SCOPE_EXIT_LOG_RTN_VALUE(__value, __log_level, ...)
 
#define SCOPE_EXIT_RTN(...)
 
#define SCOPE_EXIT_RTN_VALUE(__return_value, ...)
 
#define SCOPE_TRACE(__level, ...)
 
#define TRACE_ATLEAST(level)
 

Enumerations

enum  ast_trace_indent_type {
  AST_TRACE_INDENT_SAME = 0 , AST_TRACE_INDENT_INC_BEFORE , AST_TRACE_INDENT_INC_AFTER , AST_TRACE_INDENT_DEC_BEFORE ,
  AST_TRACE_INDENT_DEC_AFTER , AST_TRACE_INDENT_PROVIDED , AST_TRACE_INDENT_NONE
}
 Controls if and when indenting is applied. More...
 

Functions

void ast_init_logger_for_socket_console (void)
 load logger.conf configuration for console socket connections More...
 
unsigned int ast_trace_get_by_module (const char *module)
 Get the trace level for a module. More...
 

Detailed Description

Basic Usage

The Scope Trace facility allows you to instrument code and output scope entry and exit messages with associated data.

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 ] 
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. The destructor prints the name of the function with an "exiting" indicator along with an optional message.
  • Prints the name of the function with an "entering" indicator along with an optional message.

Simple Example: The following code...

static struct pjmedia_sdp_session *create_local_sdp(pjsip_inv_session *inv,
struct ast_sip_session *session, const pjmedia_sdp_session *offer)
{
...
}
static struct ast_mansession session
#define SCOPE_TRACE(__level,...)
static struct pjmedia_sdp_session * create_local_sdp(pjsip_inv_session *inv, struct ast_sip_session *session, const pjmedia_sdp_session *offer, const unsigned int ignore_active_stream_topology)
const char * ast_sip_session_get_name(const struct ast_sip_session *session)
Get the channel or endpoint name associated with the session.
A structure describing a SIP session.

would produce...

[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
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.

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:
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:
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):
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
TRACE[953402] :             --> res_pjsip_session.c:3669 handle_incoming_response PJSIP/1173-00000001 Method: INVITE Status: 100 Supplement: chan_pjsip
TRACE[953402] :                 --> chan_pjsip.c:3265 chan_pjsip_incoming_response_after_media PJSIP/1173-00000001 Method: INVITE Status: 100  After Media
TRACE[953402] :                     --> chan_pjsip.c:3194 chan_pjsip_incoming_response PJSIP/1173-00000001 Method: INVITE Status: 100
TRACE[953402] :                         chan_pjsip.c:3245 chan_pjsip_incoming_response PJSIP/1173-00000001 Method: INVITE Status: 100  Ignored
TRACE[953402] :                     <-- chan_pjsip.c:3194 chan_pjsip_incoming_response PJSIP/1173-00000001 Method: INVITE Status: 100
TRACE[953402] :                 <-- chan_pjsip.c:3265 chan_pjsip_incoming_response_after_media PJSIP/1173-00000001 Method: INVITE Status: 100  After Media
TRACE[953402] :             <-- res_pjsip_session.c:3669 handle_incoming_response PJSIP/1173-00000001 Method: INVITE Status: 100 Supplement: chan_pjsip
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
Note
The trace level indicates which messages to print and has no effect on indent.
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 an entry/exit message. To do so, you can use the ast_trace macros...
ast_trace(1, "%s Method: %.*s Status: %d Ignored\n", ast_sip_session_get_name(session),
(int)rdata->msg_info.cseq->method.name.slen, rdata->msg_info.cseq->method.name.ptr, status.code);
jack_status_t status
Definition: app_jack.c:146
#define ast_trace(level,...)
Note
Final note: The trace facility, like debug, is only available when AST_DEVMODE is defined.

TRACE_PREFIX

The default prefix to each log and trace line is "filename:line function" which is defined in the macro _A_ at the top of this file:

#define _A_ __FILE__, __LINE__, __FUNCTION__

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 _TRACE_PREFIX_ macro. Like _A_, it MUST resolve to 3 arguments:

const char *, int, const char *

so the minimum would be:

#define _TRACE_PREFIX_ "",0,""

Normally you should define _TRACE_PREFIX_ in your source file before including logger.h.

#define _TRACE_PREFIX_ "", __LINE__, ""
Support for logging to various files, console and syslog Configuration in file logger....

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 _TRACE_PREFIX_DEFAULT_.

#undef _TRACE_PREFIX_
#define _TRACE_PREFIX_ "", __LINE__, ""
<code>
#undef _TRACE_PREFIX_
#define _TRACE_PREFIX_ _TRACE_PREFIX_DEFAULT_
Note
Macros have a compilation unit scope so defining _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 _TRACE_PREFIX_ is defined in B, not A.

Macro Definition Documentation

◆ _TRACE_PREFIX_

#define _TRACE_PREFIX_   _TRACE_PREFIX_DEFAULT_

Definition at line 670 of file include/asterisk/logger.h.

◆ _TRACE_PREFIX_DEFAULT_

#define _TRACE_PREFIX_DEFAULT_   _A_

Definition at line 668 of file include/asterisk/logger.h.

◆ ast_trace

#define ast_trace (   level,
  ... 
)     ast_debug(level < 0 ? __scope_level : level, " " __VA_ARGS__)

Definition at line 1000 of file include/asterisk/logger.h.

◆ ast_trace_dec_indent

#define ast_trace_dec_indent ( )

Definition at line 1006 of file include/asterisk/logger.h.

◆ ast_trace_get_indent

#define ast_trace_get_indent ( )    (0)

Definition at line 1003 of file include/asterisk/logger.h.

◆ ast_trace_inc_indent

#define ast_trace_inc_indent ( )

Definition at line 1005 of file include/asterisk/logger.h.

◆ ast_trace_log

#define ast_trace_log (   __level,
  __log_level,
  ... 
)
Value:
({ \
ast_log(__log_level, " " __VA_ARGS__); \
ast_trace(__level < 0 ? __scope_level : __level, " " __VA_ARGS__); \
})

Definition at line 1072 of file include/asterisk/logger.h.

◆ ast_trace_raw

#define ast_trace_raw (   level,
  indent_type,
  ... 
)     ast_debug(level < 0 ? __scope_level : level, " " __VA_ARGS__)

Definition at line 997 of file include/asterisk/logger.h.

◆ ast_trace_set_indent

#define ast_trace_set_indent (   indent)

Definition at line 1004 of file include/asterisk/logger.h.

◆ SCOPE_CALL

#define SCOPE_CALL (   level,
  __funcname,
  ... 
)     __funcname(__VA_ARGS__)

Definition at line 1017 of file include/asterisk/logger.h.

◆ SCOPE_CALL_WITH_INT_RESULT

#define SCOPE_CALL_WITH_INT_RESULT (   level,
  __funcname,
  ... 
)     __funcname(__VA_ARGS__)

Definition at line 1023 of file include/asterisk/logger.h.

◆ SCOPE_CALL_WITH_RESULT

#define SCOPE_CALL_WITH_RESULT (   level,
  __var,
  __funcname,
  ... 
)     __var = __funcname(__VA_ARGS__)

Definition at line 1020 of file include/asterisk/logger.h.

◆ SCOPE_ENTER

#define SCOPE_ENTER (   level,
  ... 
)
Value:
int __scope_level = level; \
ast_debug(level, " " __VA_ARGS__)

Definition at line 1009 of file include/asterisk/logger.h.

◆ SCOPE_ENTER_TASK

#define SCOPE_ENTER_TASK (   level,
  indent,
  ... 
)
Value:
int __scope_level = level; \
ast_debug(level, " " __VA_ARGS__)

Definition at line 1013 of file include/asterisk/logger.h.

◆ SCOPE_EXIT

#define SCOPE_EXIT (   ...)     ast_debug(__scope_level, " " __VA_ARGS__)

Definition at line 1026 of file include/asterisk/logger.h.

◆ SCOPE_EXIT_EXPR

#define SCOPE_EXIT_EXPR (   __expr,
  ... 
)
Value:
ast_debug(__scope_level, " " __VA_ARGS__); \
__expr
#define ast_debug(level,...)
Log a DEBUG message.

Definition at line 1029 of file include/asterisk/logger.h.

◆ SCOPE_EXIT_LOG

#define SCOPE_EXIT_LOG (   __log_level,
  ... 
)
Value:
({ \
ast_log(__log_level, " " __VA_ARGS__); \
SCOPE_EXIT(" " __VA_ARGS__); \
})

The following macros will print log messages before running the associated SCOPE_ macro.

Definition at line 1048 of file include/asterisk/logger.h.

◆ SCOPE_EXIT_LOG_EXPR

#define SCOPE_EXIT_LOG_EXPR (   __expr,
  __log_level,
  ... 
)
Value:
({ \
ast_log(__log_level, " " __VA_ARGS__); \
SCOPE_EXIT_EXPR(__expr, " " __VA_ARGS__); \
})

Definition at line 1066 of file include/asterisk/logger.h.

◆ SCOPE_EXIT_LOG_RTN

#define SCOPE_EXIT_LOG_RTN (   __log_level,
  ... 
)
Value:
({ \
ast_log(__log_level, " " __VA_ARGS__); \
SCOPE_EXIT_RTN(" " __VA_ARGS__); \
})

Definition at line 1054 of file include/asterisk/logger.h.

◆ SCOPE_EXIT_LOG_RTN_VALUE

#define SCOPE_EXIT_LOG_RTN_VALUE (   __value,
  __log_level,
  ... 
)
Value:
({ \
ast_log(__log_level, " " __VA_ARGS__); \
SCOPE_EXIT_RTN_VALUE(__value, " " __VA_ARGS__); \
})

Definition at line 1060 of file include/asterisk/logger.h.

◆ SCOPE_EXIT_RTN

#define SCOPE_EXIT_RTN (   ...)
Value:
ast_debug(__scope_level, " " __VA_ARGS__); \
return

Definition at line 1033 of file include/asterisk/logger.h.

◆ SCOPE_EXIT_RTN_VALUE

#define SCOPE_EXIT_RTN_VALUE (   __return_value,
  ... 
)
Value:
ast_debug(__scope_level, " " __VA_ARGS__); \
return __return_value

Definition at line 1037 of file include/asterisk/logger.h.

◆ SCOPE_TRACE

#define SCOPE_TRACE (   __level,
  ... 
)

Definition at line 1007 of file include/asterisk/logger.h.

◆ TRACE_ATLEAST

#define TRACE_ATLEAST (   level)
Value:
(option_trace >= (level) \
&& ((int)ast_trace_get_by_module(AST_MODULE) >= (level) \
|| (int)ast_trace_get_by_module(__FILE__) >= (level))))
#define AST_MODULE
unsigned int ast_trace_get_by_module(const char *module)
Get the trace level for a module.
Definition: main/cli.c:153
int option_trace
Definition: options.c:71
#define ast_opt_trace_module
Definition: options.h:129

Definition at line 685 of file include/asterisk/logger.h.

Enumeration Type Documentation

◆ ast_trace_indent_type

Controls if and when indenting is applied.

Enumerator
AST_TRACE_INDENT_SAME 

Use the existing indent level

AST_TRACE_INDENT_INC_BEFORE 

Increment the indent before printing the message

AST_TRACE_INDENT_INC_AFTER 

Increment the indent after printing the message

AST_TRACE_INDENT_DEC_BEFORE 

Decrement the indent before printing the message

AST_TRACE_INDENT_DEC_AFTER 

Decrement the indent after printing the message

AST_TRACE_INDENT_PROVIDED 

Set the indent to the one provided

AST_TRACE_INDENT_NONE 

Don't use or alter the level

Definition at line 694 of file include/asterisk/logger.h.

694 {
695 /*! Use the existing indent level */
697 /*! Increment the indent before printing the message */
699 /*! Increment the indent after printing the message */
701 /*! Decrement the indent before printing the message */
703 /*! Decrement the indent after printing the message */
705 /*! Set the indent to the one provided */
707 /*! Don't use or alter the level */
709};
@ AST_TRACE_INDENT_INC_BEFORE
@ AST_TRACE_INDENT_SAME
@ AST_TRACE_INDENT_PROVIDED
@ AST_TRACE_INDENT_NONE
@ AST_TRACE_INDENT_INC_AFTER
@ AST_TRACE_INDENT_DEC_BEFORE
@ AST_TRACE_INDENT_DEC_AFTER

Function Documentation

◆ ast_init_logger_for_socket_console()

void ast_init_logger_for_socket_console ( void  )

load logger.conf configuration for console socket connections

Definition at line 713 of file logger.c.

714{
715 struct ast_config *cfg;
716 const char *s;
717 struct ast_flags config_flags = { 0 };
718
719 if (!(cfg = ast_config_load2("logger.conf", "logger", config_flags)) || cfg == CONFIG_STATUS_FILEINVALID) {
720 return;
721 }
722
723 if ((s = ast_variable_retrieve(cfg, "general", "dateformat"))) {
725 }
726
728}
struct ast_config * ast_config_load2(const char *filename, const char *who_asked, struct ast_flags flags)
Load a config file.
Definition: main/config.c:3322
#define CONFIG_STATUS_FILEINVALID
void ast_config_destroy(struct ast_config *cfg)
Destroys a config.
Definition: extconf.c:1289
const char * ast_variable_retrieve(struct ast_config *config, const char *category, const char *variable)
Definition: main/config.c:784
static char dateformat[256]
Definition: logger.c:81
void ast_copy_string(char *dst, const char *src, size_t size)
Size-limited null-terminating string copy.
Definition: strings.h:425
Structure used to handle boolean flags.
Definition: utils.h:199

References ast_config_destroy(), ast_config_load2(), ast_copy_string(), ast_variable_retrieve(), CONFIG_STATUS_FILEINVALID, and dateformat.

Referenced by ast_remotecontrol().

◆ ast_trace_get_by_module()

unsigned int ast_trace_get_by_module ( const char *  module)

Get the trace level for a module.

Parameters
modulethe name of module
Returns
the trace level

Definition at line 153 of file main/cli.c.

154{
155 struct module_level *ml;
156 unsigned int res = 0;
157
160 if (!strcasecmp(ml->module, module)) {
161 res = ml->level;
162 break;
163 }
164 }
166
167 return res;
168}
#define AST_RWLIST_RDLOCK(head)
Read locks a list.
Definition: linkedlists.h:78
#define AST_RWLIST_UNLOCK(head)
Attempts to unlock a read/write based list.
Definition: linkedlists.h:151
#define AST_LIST_TRAVERSE(head, var, field)
Loops over (traverses) the entries in a list.
Definition: linkedlists.h:491
static struct module_level_list trace_modules
Definition: main/cli.c:108
Definition: search.h:40
map a debug or verbose level to a module name
Definition: main/cli.c:98
unsigned int level
Definition: main/cli.c:99

References AST_LIST_TRAVERSE, AST_RWLIST_RDLOCK, AST_RWLIST_UNLOCK, module_level::level, and trace_modules.