<p>George Joseph <strong>uploaded patch set #2</strong> to this change.</p><p><a href="https://gerrit.asterisk.org/c/asterisk/+/14414">View Change</a></p><pre style="font-family: monospace,monospace; white-space: pre-wrap;">Scope Tracing: A new facility for tracing scope enter/exit<br><br>What's wrong with ast_debug?<br><br> ast_debug is fine for general purpose debug output but it's not<br> really geared for scope tracing since it doesn't present its<br> output in a way that makes capturing and analyzing flow through<br> Asterisk easy.<br><br>How is scope tracing better?<br><br> Scope tracing uses the same "cleanup" attribute that RAII_VAR<br> uses to print messages to a separate "trace" log level. Even<br> better, the messages are indented and unindented based on a<br> thread-local call depth counter. When output to a separate log<br> file, the output is uncluttered and easy to follow.<br><br> Here's an example of the output. The leading timestamps and<br> thread ids are removed and the output cut off at 68 columns for<br> commit message restrictions but you get the idea.<br><br>--> res_pjsip_session.c:3680 handle_incoming PJSIP/1173-00000001<br> --> res_pjsip_session.c:3661 handle_incoming_response PJSIP/1173<br> --> res_pjsip_session.c:3669 handle_incoming_response PJSIP/<br> --> chan_pjsip.c:3265 chan_pjsip_incoming_response_after<br> --> chan_pjsip.c:3194 chan_pjsip_incoming_response P<br> chan_pjsip.c:3245 chan_pjsip_incoming_respon<br> <-- chan_pjsip.c:3194 chan_pjsip_incoming_response P<br> <-- chan_pjsip.c:3265 chan_pjsip_incoming_response_after<br> <-- res_pjsip_session.c:3669 handle_incoming_response PJSIP/<br> <-- res_pjsip_session.c:3661 handle_incoming_response PJSIP/1173<br><-- res_pjsip_session.c:3680 handle_incoming PJSIP/1173-00000001<br><br> Most of those messages were produced by including the following<br> at the top of each function:<br><br> SCOPE_TRACE_MSG(1, "%s\n", ast_sip_session_get_name(session));<br><br> Scope isn't limited to functions any more than RAII_VAR is. You<br> can also see entry and exit from "if", "for", "while", etc blocks.<br><br> There is also an ast_trace() that doesn't track entry or exit but<br> simply outputs a message to the trace log using the current indent<br> level. The deepest message in the sample (chan_pjsip.c:3245) was<br> used to indicate which "case" in a "select" was executed.<br><br>How do you use it?<br><br> More documentation is available in logger.h but here's an overview:<br><br> * Configure with --enable-dev-mode. Like debug, scope tracing<br> is #ifdef'd out if devmode isn't enabled.<br><br> * Add a SCOPE_TRACE() or SCOPE_TRACE_MSG() call to the top of your<br> function.<br><br> * Set a logger channel in logger.conf to output the "trace" level.<br><br> * Use the CLI (or cli.conf) to set a trace level similar to setting<br> debug level... CLI> core set trace 2 res_pjsip.so<br><br>Summary Of Changes:<br><br> * Added LOG_TRACE logger level. Actually it occupies the slot<br> formerly occupied by the now defunct "event" level.<br><br> * Added core asterisk option "trace" similar to debug. Includes<br> ability to specify global trace level in asterisk.conf and CLI<br> commands to turn on/off and set levels. Levels can be set<br> globally (probably not a good idea), or by module/source file.<br><br> * Updated sample asterisk.conf and logger.conf. Tracing is<br> disabled by default in both.<br><br> * Added __ast_trace() to logger.c which keeps track of the indent<br> level using TLS. It's #ifdef'd out if devmode isn't enabled.<br><br> * Added ast_trace(), ast_trace_msg(), SCOPE_TRACE(), and<br> SCOPE_TRACE_MSG() macros to logger.h. These are all #ifdef'd<br> out if devmode isn't enabled.<br><br>Why not use gcc's -finstrument-functions capability?<br><br> gcc's facility doesn't allow accecss to local data and doesn't<br> operate on non-function scopes.<br><br>Known Issues:<br><br> The only know issue is that we currently don't know the line<br> number where the scope exited. It's reported as the same place<br> the scope was entered. There's probably a way to get around it<br> but it might involve looking at the stack and doing an 'addr2line'<br> to get the line number. Kind of like ast_backtrace() does.<br> Not sure if it's worth it.<br><br>Change-Id: Ic5ebb859883f9c10a08c5630802de33500cad027<br>---<br>M configs/samples/asterisk.conf.sample<br>M configs/samples/logger.conf.sample<br>M include/asterisk/logger.h<br>M include/asterisk/options.h<br>M main/asterisk.c<br>M main/asterisk.exports.in<br>M main/cli.c<br>M main/logger.c<br>M main/options.c<br>9 files changed, 519 insertions(+), 100 deletions(-)<br><br></pre><pre style="font-family: monospace,monospace; white-space: pre-wrap;">git pull ssh://gerrit.asterisk.org:29418/asterisk refs/changes/14/14414/2</pre><p>To view, visit <a href="https://gerrit.asterisk.org/c/asterisk/+/14414">change 14414</a>. To unsubscribe, or for help writing mail filters, visit <a href="https://gerrit.asterisk.org/settings">settings</a>.</p><div itemscope itemtype="http://schema.org/EmailMessage"><div itemscope itemprop="action" itemtype="http://schema.org/ViewAction"><link itemprop="url" href="https://gerrit.asterisk.org/c/asterisk/+/14414"/><meta itemprop="name" content="View Change"/></div></div>
<div style="display:none"> Gerrit-Project: asterisk </div>
<div style="display:none"> Gerrit-Branch: master </div>
<div style="display:none"> Gerrit-Change-Id: Ic5ebb859883f9c10a08c5630802de33500cad027 </div>
<div style="display:none"> Gerrit-Change-Number: 14414 </div>
<div style="display:none"> Gerrit-PatchSet: 2 </div>
<div style="display:none"> Gerrit-Owner: George Joseph <gjoseph@digium.com> </div>
<div style="display:none"> Gerrit-Reviewer: Friendly Automation </div>
<div style="display:none"> Gerrit-Reviewer: Kevin Harwell <kharwell@digium.com> </div>
<div style="display:none"> Gerrit-MessageType: newpatchset </div>