<p>George Joseph <strong>submitted</strong> this change.</p><p><a href="https://gerrit.asterisk.org/c/asterisk/+/14631">View Change</a></p><div style="white-space:pre-wrap">Approvals:
  Kevin Harwell: Looks good to me, but someone else must approve
  George Joseph: Looks good to me, approved; Approved for Submit

</div><pre style="font-family: monospace,monospace; white-space: pre-wrap;">ACN: Add tracing to existing code<br><br>Prior to making any modifications to the pjsip infrastructure<br>for ACN, I've added the tracing functions to the existing code.<br>This should make the final commit easier to review, but we can also<br>now run a "before and after" trace.<br><br>No functional changes were made with this commit.<br><br>Change-Id: Ia83a1a2687ccb96f2bc8a2a3928a5214c4be775c<br>---<br>M apps/app_dial.c<br>M channels/chan_pjsip.c<br>M include/asterisk/res_pjsip_session.h<br>M main/bridge.c<br>M main/channel.c<br>M main/channel_internal_api.c<br>M main/features.c<br>M res/res_pjsip_sdp_rtp.c<br>M res/res_pjsip_session.c<br>9 files changed, 438 insertions(+), 179 deletions(-)<br><br></pre><pre style="font-family: monospace,monospace; white-space: pre-wrap;"><span>diff --git a/apps/app_dial.c b/apps/app_dial.c</span><br><span>index 2744868..95f36d7 100644</span><br><span>--- a/apps/app_dial.c</span><br><span>+++ b/apps/app_dial.c</span><br><span>@@ -1223,6 +1223,7 @@</span><br><span>         int sent_ring = 0;</span><br><span>   int sent_progress = 0;</span><br><span>       struct timeval start = ast_tvnow();</span><br><span style="color: hsl(120, 100%, 40%);">+   SCOPE_TRACE(1, "%s\n", ast_channel_name(in));</span><br><span> </span><br><span>  if (single) {</span><br><span>                /* Turn off hold music, etc */</span><br><span>@@ -1389,6 +1390,7 @@</span><br><span>                               case AST_CONTROL_ANSWER:</span><br><span>                                     /* This is our guy if someone answered. */</span><br><span>                                   if (!peer) {</span><br><span style="color: hsl(120, 100%, 40%);">+                                          ast_trace(1, "%s answered %s\n", ast_channel_name(c), ast_channel_name(in));</span><br><span>                                               ast_verb(3, "%s answered %s\n", ast_channel_name(c), ast_channel_name(in));</span><br><span>                                                if (o->orig_chan_name</span><br><span>                                                     && strcmp(o->orig_chan_name, ast_channel_name(c))) {</span><br><span>@@ -2269,6 +2271,7 @@</span><br><span>       */</span><br><span>  struct ast_party_caller caller;</span><br><span>      int max_forwards;</span><br><span style="color: hsl(120, 100%, 40%);">+     SCOPE_TRACE(1, "%s Data: %s\n", ast_channel_name(chan), data);</span><br><span> </span><br><span>         /* Reset all DIAL variables back to blank, to prevent confusion (in case we don't reset all of them). */</span><br><span>         ast_channel_lock(chan);</span><br><span>diff --git a/channels/chan_pjsip.c b/channels/chan_pjsip.c</span><br><span>index 2fc98b4..e99ec31 100644</span><br><span>--- a/channels/chan_pjsip.c</span><br><span>+++ b/channels/chan_pjsip.c</span><br><span>@@ -241,7 +241,10 @@</span><br><span> /*! \brief Function called by RTP engine to get peer capabilities */</span><br><span> static void chan_pjsip_get_codec(struct ast_channel *chan, struct ast_format_cap *result)</span><br><span> {</span><br><span style="color: hsl(120, 100%, 40%);">+     SCOPE_ENTER(1, "%s Native formats %s\n", ast_channel_name(chan),</span><br><span style="color: hsl(120, 100%, 40%);">+            ast_str_tmp(AST_FORMAT_CAP_NAMES_LEN, ast_format_cap_get_names(ast_channel_nativeformats(chan), &STR_TMP)));</span><br><span>     ast_format_cap_append_from_cap(result, ast_channel_nativeformats(chan), AST_MEDIA_TYPE_UNKNOWN);</span><br><span style="color: hsl(120, 100%, 40%);">+      SCOPE_EXIT_RTN();</span><br><span> }</span><br><span> </span><br><span> /*! \brief Destructor function for \ref transport_info_data */</span><br><span>@@ -450,21 +453,23 @@</span><br><span>         struct ast_sip_channel_pvt *channel = ast_channel_tech_pvt(chan);</span><br><span>    struct ast_sip_session *session = channel->session;</span><br><span>       struct rtp_direct_media_data *cdata;</span><br><span style="color: hsl(120, 100%, 40%);">+  SCOPE_ENTER(1, "%s %s\n", ast_channel_name(chan),</span><br><span style="color: hsl(120, 100%, 40%);">+           ast_str_tmp(AST_FORMAT_CAP_NAMES_LEN, ast_format_cap_get_names(cap, &STR_TMP)));</span><br><span> </span><br><span>     /* Don't try to do any direct media shenanigans on early bridges */</span><br><span>      if ((rtp || vrtp || tpeer) && !ast_channel_is_bridged(chan)) {</span><br><span>               ast_debug(4, "Disregarding setting RTP on %s: channel is not bridged\n", ast_channel_name(chan));</span><br><span style="color: hsl(0, 100%, 40%);">-             return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+             SCOPE_EXIT_RTN_VALUE(0, "Channel not bridged\n");</span><br><span>  }</span><br><span> </span><br><span>        if (nat_active && session->endpoint->media.direct_media.disable_on_nat) {</span><br><span>              ast_debug(4, "Disregarding setting RTP on %s: NAT is active\n", ast_channel_name(chan));</span><br><span style="color: hsl(0, 100%, 40%);">-              return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+             SCOPE_EXIT_RTN_VALUE(0, "NAT is active\n");</span><br><span>        }</span><br><span> </span><br><span>        cdata = rtp_direct_media_data_create(chan, rtp, vrtp, cap, session);</span><br><span>         if (!cdata) {</span><br><span style="color: hsl(0, 100%, 40%);">-           return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+             SCOPE_EXIT_RTN_VALUE(0);</span><br><span>     }</span><br><span> </span><br><span>        if (ast_sip_push_task(session->serializer, send_direct_media_request, cdata)) {</span><br><span>@@ -472,7 +477,7 @@</span><br><span>             ao2_ref(cdata, -1);</span><br><span>  }</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-   return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+     SCOPE_EXIT_RTN_VALUE(0);</span><br><span> }</span><br><span> </span><br><span> /*! \brief Local glue for interacting with the RTP engine core */</span><br><span>@@ -520,17 +525,20 @@</span><br><span> {</span><br><span>  struct ast_format_cap *cap_from_top;</span><br><span>         int res;</span><br><span style="color: hsl(120, 100%, 40%);">+      SCOPE_ENTER(1, "Topology: %s Formats: %s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+                ast_str_tmp(AST_FORMAT_CAP_NAMES_LEN, ast_stream_topology_to_str(top, &STR_TMP)),</span><br><span style="color: hsl(120, 100%, 40%);">+         ast_str_tmp(AST_FORMAT_CAP_NAMES_LEN, ast_format_cap_get_names(cap, &STR_TMP)));</span><br><span> </span><br><span>     cap_from_top = ast_stream_topology_get_formats(top);</span><br><span> </span><br><span>     if (!cap_from_top) {</span><br><span style="color: hsl(0, 100%, 40%);">-            return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+             SCOPE_EXIT_RTN_VALUE(0, "Topology had no formats\n");</span><br><span>      }</span><br><span> </span><br><span>        res = ast_format_cap_iscompatible(cap_from_top, cap);</span><br><span>        ao2_ref(cap_from_top, -1);</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-  return res;</span><br><span style="color: hsl(120, 100%, 40%);">+   SCOPE_EXIT_RTN_VALUE(res, "Compatible? %s\n", res ? "yes" : "no");</span><br><span> }</span><br><span> </span><br><span> /*! \brief Function called to create a new PJSIP Asterisk channel */</span><br><span>@@ -542,9 +550,10 @@</span><br><span>     struct ast_sip_channel_pvt *channel;</span><br><span>         struct ast_variable *var;</span><br><span>    struct ast_stream_topology *topology;</span><br><span style="color: hsl(120, 100%, 40%);">+ SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(session));</span><br><span> </span><br><span>     if (!(pvt = ao2_alloc_options(sizeof(*pvt), chan_pjsip_pvt_dtor, AO2_ALLOC_OPT_LOCK_NOLOCK))) {</span><br><span style="color: hsl(0, 100%, 40%);">-         return NULL;</span><br><span style="color: hsl(120, 100%, 40%);">+          SCOPE_EXIT_RTN_VALUE(NULL, "Couldn't create pvt\n");</span><br><span>   }</span><br><span> </span><br><span>        chan = ast_channel_alloc_with_endpoint(1, state,</span><br><span>@@ -557,7 +566,7 @@</span><br><span>               ast_sorcery_object_get_id(session->endpoint),</span><br><span>             (unsigned) ast_atomic_fetchadd_int((int *) &chan_idx, +1));</span><br><span>      if (!chan) {</span><br><span style="color: hsl(0, 100%, 40%);">-            return NULL;</span><br><span style="color: hsl(120, 100%, 40%);">+          SCOPE_EXIT_RTN_VALUE(NULL, "Couldn't create channel\n");</span><br><span>       }</span><br><span> </span><br><span>        ast_channel_tech_set(chan, &chan_pjsip_tech);</span><br><span>@@ -565,7 +574,7 @@</span><br><span>      if (!(channel = ast_sip_channel_pvt_alloc(pvt, session))) {</span><br><span>          ast_channel_unlock(chan);</span><br><span>            ast_hangup(chan);</span><br><span style="color: hsl(0, 100%, 40%);">-               return NULL;</span><br><span style="color: hsl(120, 100%, 40%);">+          SCOPE_EXIT_RTN_VALUE(NULL, "Couldn't create pvt channel\n");</span><br><span>   }</span><br><span> </span><br><span>        ast_channel_tech_pvt_set(chan, channel);</span><br><span>@@ -576,7 +585,7 @@</span><br><span>               if (!caps) {</span><br><span>                         ast_channel_unlock(chan);</span><br><span>                    ast_hangup(chan);</span><br><span style="color: hsl(0, 100%, 40%);">-                       return NULL;</span><br><span style="color: hsl(120, 100%, 40%);">+                  SCOPE_EXIT_RTN_VALUE(NULL, "Couldn't create caps\n");</span><br><span>          }</span><br><span>            ast_format_cap_append_from_cap(caps, session->endpoint->media.codecs, AST_MEDIA_TYPE_UNKNOWN);</span><br><span>                 topology = ast_stream_topology_clone(session->endpoint->media.topology);</span><br><span>@@ -590,7 +599,7 @@</span><br><span>                 ast_stream_topology_free(topology);</span><br><span>          ast_channel_unlock(chan);</span><br><span>            ast_hangup(chan);</span><br><span style="color: hsl(0, 100%, 40%);">-               return NULL;</span><br><span style="color: hsl(120, 100%, 40%);">+          SCOPE_EXIT_RTN_VALUE(NULL, "Couldn't get caps or clone topology\n");</span><br><span>   }</span><br><span> </span><br><span>        ast_channel_stage_snapshot(chan);</span><br><span>@@ -660,14 +669,21 @@</span><br><span> </span><br><span>        set_channel_on_rtp_instance(session, ast_channel_uniqueid(chan));</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-   return chan;</span><br><span style="color: hsl(120, 100%, 40%);">+  SCOPE_EXIT_RTN_VALUE(chan);</span><br><span> }</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+struct answer_data {</span><br><span style="color: hsl(120, 100%, 40%);">+    struct ast_sip_session *session;</span><br><span style="color: hsl(120, 100%, 40%);">+      unsigned long indent;</span><br><span style="color: hsl(120, 100%, 40%);">+};</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> static int answer(void *data)</span><br><span> {</span><br><span style="color: hsl(120, 100%, 40%);">+     struct answer_data *ans_data = data;</span><br><span>         pj_status_t status = PJ_SUCCESS;</span><br><span>     pjsip_tx_data *packet = NULL;</span><br><span style="color: hsl(0, 100%, 40%);">-   struct ast_sip_session *session = data;</span><br><span style="color: hsl(120, 100%, 40%);">+       struct ast_sip_session *session = ans_data->session;</span><br><span style="color: hsl(120, 100%, 40%);">+       SCOPE_ENTER_TASK(1, ans_data->indent, "%s\n", ast_sip_session_get_name(session));</span><br><span> </span><br><span>   if (session->inv_session->state == PJSIP_INV_STATE_DISCONNECTED) {</span><br><span>             ast_log(LOG_ERROR, "Session already DISCONNECTED [reason=%d (%s)]\n",</span><br><span>@@ -676,7 +692,7 @@</span><br><span> #ifdef HAVE_PJSIP_INV_SESSION_REF</span><br><span>           pjsip_inv_dec_ref(session->inv_session);</span><br><span> #endif</span><br><span style="color: hsl(0, 100%, 40%);">-           return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+             SCOPE_EXIT_RTN_VALUE(0, "Disconnected\n");</span><br><span>         }</span><br><span> </span><br><span>        pjsip_dlg_inc_lock(session->inv_session->dlg);</span><br><span>@@ -706,9 +722,9 @@</span><br><span>            * Return this value so we can distinguish between this</span><br><span>               * failure and the threadpool synchronous push failing.</span><br><span>               */</span><br><span style="color: hsl(0, 100%, 40%);">-             return -2;</span><br><span style="color: hsl(120, 100%, 40%);">+            SCOPE_EXIT_RTN_VALUE(-2, "pjproject failure\n");</span><br><span>   }</span><br><span style="color: hsl(0, 100%, 40%);">-       return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+     SCOPE_EXIT_RTN_VALUE(0);</span><br><span> }</span><br><span> </span><br><span> /*! \brief Function called by core when we should answer a PJSIP session */</span><br><span>@@ -716,9 +732,12 @@</span><br><span> {</span><br><span>         struct ast_sip_channel_pvt *channel = ast_channel_tech_pvt(ast);</span><br><span>     struct ast_sip_session *session;</span><br><span style="color: hsl(120, 100%, 40%);">+      struct answer_data ans_data = { 0, };</span><br><span>        int res;</span><br><span style="color: hsl(120, 100%, 40%);">+      SCOPE_ENTER(1, "%s\n", ast_channel_name(ast));</span><br><span> </span><br><span>         if (ast_channel_state(ast) == AST_STATE_UP) {</span><br><span style="color: hsl(120, 100%, 40%);">+         SCOPE_EXIT_RTN_VALUE(0, "Already up\n");</span><br><span>           return 0;</span><br><span>    }</span><br><span> </span><br><span>@@ -727,9 +746,9 @@</span><br><span> </span><br><span> #ifdef HAVE_PJSIP_INV_SESSION_REF</span><br><span>         if (pjsip_inv_add_ref(session->inv_session) != PJ_SUCCESS) {</span><br><span style="color: hsl(0, 100%, 40%);">-         ast_log(LOG_ERROR, "Can't increase the session reference counter\n");</span><br><span style="color: hsl(120, 100%, 40%);">+           ast_log(LOG_ERROR, "Couldn't increase the session reference counter\n");</span><br><span>               ao2_ref(session, -1);</span><br><span style="color: hsl(0, 100%, 40%);">-           return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+            SCOPE_EXIT_RTN_VALUE(-1, "Couldn't increase the session reference counter\n");</span><br><span>         }</span><br><span> #endif</span><br><span> </span><br><span>@@ -737,7 +756,9 @@</span><br><span>           can occur between this thread and bridging (specifically when native bridging</span><br><span>        attempts to do direct media) */</span><br><span>   ast_channel_unlock(ast);</span><br><span style="color: hsl(0, 100%, 40%);">-        res = ast_sip_push_task_wait_serializer(session->serializer, answer, session);</span><br><span style="color: hsl(120, 100%, 40%);">+     ans_data.session = session;</span><br><span style="color: hsl(120, 100%, 40%);">+   ans_data.indent = ast_trace_get_indent();</span><br><span style="color: hsl(120, 100%, 40%);">+     res = ast_sip_push_task_wait_serializer(session->serializer, answer, &ans_data);</span><br><span>      if (res) {</span><br><span>           if (res == -1) {</span><br><span>                     ast_log(LOG_ERROR,"Cannot answer '%s': Unable to push answer task to the threadpool.\n",</span><br><span>@@ -748,12 +769,12 @@</span><br><span>           }</span><br><span>            ao2_ref(session, -1);</span><br><span>                ast_channel_lock(ast);</span><br><span style="color: hsl(0, 100%, 40%);">-          return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+            SCOPE_EXIT_RTN_VALUE(-1, "Couldn't push task\n");</span><br><span>      }</span><br><span>    ao2_ref(session, -1);</span><br><span>        ast_channel_lock(ast);</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-      return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+     SCOPE_EXIT_RTN_VALUE(0);</span><br><span> }</span><br><span> </span><br><span> /*! \brief Internal helper function called when CNG tone is detected */</span><br><span>@@ -1564,6 +1585,9 @@</span><br><span> </span><br><span> static int on_topology_change_response(struct ast_sip_session *session, pjsip_rx_data *rdata)</span><br><span> {</span><br><span style="color: hsl(120, 100%, 40%);">+        SCOPE_ENTER(1, "%s Status code: %d\n", ast_sip_session_get_name(session),</span><br><span style="color: hsl(120, 100%, 40%);">+           rdata->msg_info.msg->line.status.code);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span>      if (PJSIP_IS_STATUS_IN_CLASS(rdata->msg_info.msg->line.status.code, 200)) {</span><br><span>            /* The topology was changed to something new so give notice to what requested</span><br><span>                 * it so it queries the channel and updates accordingly.</span><br><span>@@ -1576,20 +1600,21 @@</span><br><span>           ast_sip_session_media_state_reset(session->pending_media_state);</span><br><span>  }</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-   return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+     SCOPE_EXIT_RTN_VALUE(0);</span><br><span> }</span><br><span> </span><br><span> static int send_topology_change_refresh(void *data)</span><br><span> {</span><br><span>        struct topology_change_refresh_data *refresh_data = data;</span><br><span>    int ret;</span><br><span style="color: hsl(120, 100%, 40%);">+      SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(refresh_data->session));</span><br><span> </span><br><span>    ret = ast_sip_session_refresh(refresh_data->session, NULL, NULL, on_topology_change_response,</span><br><span>             AST_SIP_SESSION_REFRESH_METHOD_INVITE, 1, refresh_data->media_state);</span><br><span>     refresh_data->media_state = NULL;</span><br><span>         topology_change_refresh_data_free(refresh_data);</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-    return ret;</span><br><span style="color: hsl(120, 100%, 40%);">+   SCOPE_EXIT_RTN_VALUE(ret, "RC: %d\n", ret);</span><br><span> }</span><br><span> </span><br><span> static int handle_topology_request_change(struct ast_sip_session *session,</span><br><span>@@ -1597,17 +1622,18 @@</span><br><span> {</span><br><span>  struct topology_change_refresh_data *refresh_data;</span><br><span>   int res;</span><br><span style="color: hsl(120, 100%, 40%);">+      SCOPE_ENTER(1);</span><br><span> </span><br><span>  refresh_data = topology_change_refresh_data_alloc(session, proposed);</span><br><span>        if (!refresh_data) {</span><br><span style="color: hsl(0, 100%, 40%);">-            return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+            SCOPE_EXIT_RTN_VALUE(-1, "Couldn't create refresh_data\n");</span><br><span>    }</span><br><span> </span><br><span>        res = ast_sip_push_task(session->serializer, send_topology_change_refresh, refresh_data);</span><br><span>         if (res) {</span><br><span>           topology_change_refresh_data_free(refresh_data);</span><br><span>     }</span><br><span style="color: hsl(0, 100%, 40%);">-       return res;</span><br><span style="color: hsl(120, 100%, 40%);">+   SCOPE_EXIT_RTN_VALUE(res, "RC: %d\n", res);</span><br><span> }</span><br><span> </span><br><span> /*! \brief Function called by core to ask the channel to indicate some sort of condition */</span><br><span>@@ -1621,6 +1647,10 @@</span><br><span>       size_t device_buf_size;</span><br><span>      int i;</span><br><span>       const struct ast_stream_topology *topology;</span><br><span style="color: hsl(120, 100%, 40%);">+   struct ast_frame f = { .frametype = AST_FRAME_CONTROL, .subclass = { .integer = condition } };</span><br><span style="color: hsl(120, 100%, 40%);">+        char subclass[40] = "";</span><br><span style="color: hsl(120, 100%, 40%);">+     SCOPE_ENTER(1, "%s Handling %s\n", ast_channel_name(ast),</span><br><span style="color: hsl(120, 100%, 40%);">+           ast_frame_subclass2str(&f, subclass, sizeof(subclass), NULL, 0));</span><br><span> </span><br><span>    switch (condition) {</span><br><span>         case AST_CONTROL_RINGING:</span><br><span>@@ -1727,7 +1757,7 @@</span><br><span>            if (pjsip_inv_add_ref(channel->session->inv_session) != PJ_SUCCESS) {</span><br><span>                  ast_log(LOG_ERROR, "Can't increase the session reference counter\n");</span><br><span>                  ao2_cleanup(channel->session);</span><br><span style="color: hsl(0, 100%, 40%);">-                       return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+                    SCOPE_EXIT_RTN_VALUE(-1, "Couldn't increase the session reference counter\n");</span><br><span>                 }</span><br><span> #endif</span><br><span>          if (ast_sip_push_task(channel->session->serializer, update_connected_line_information, channel->session)) {</span><br><span>@@ -1836,13 +1866,13 @@</span><br><span>               struct indicate_data *ind_data = indicate_data_alloc(channel->session, condition, response_code, data, datalen);</span><br><span> </span><br><span>              if (!ind_data) {</span><br><span style="color: hsl(0, 100%, 40%);">-                        return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+                    SCOPE_EXIT_RTN_VALUE(-1, "Couldn't create indicate data\n");</span><br><span>           }</span><br><span> #ifdef HAVE_PJSIP_INV_SESSION_REF</span><br><span>               if (pjsip_inv_add_ref(ind_data->session->inv_session) != PJ_SUCCESS) {</span><br><span>                         ast_log(LOG_ERROR, "Can't increase the session reference counter\n");</span><br><span>                  ao2_cleanup(ind_data);</span><br><span style="color: hsl(0, 100%, 40%);">-                  return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+                    SCOPE_EXIT_RTN_VALUE(-1, "Couldn't increase the session reference counter\n");</span><br><span>                 }</span><br><span> #endif</span><br><span>          if (ast_sip_push_task(channel->session->serializer, indicate, ind_data)) {</span><br><span>@@ -1856,7 +1886,7 @@</span><br><span>             }</span><br><span>    }</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-   return res;</span><br><span style="color: hsl(120, 100%, 40%);">+   SCOPE_EXIT_RTN_VALUE(res, "RC: %d\n", res);</span><br><span> }</span><br><span> </span><br><span> struct transfer_data {</span><br><span>@@ -2397,8 +2427,14 @@</span><br><span>    struct ast_sip_channel_pvt *channel = data;</span><br><span>  struct ast_sip_session *session = channel->session;</span><br><span>       pjsip_tx_data *tdata;</span><br><span style="color: hsl(120, 100%, 40%);">+ int res = 0;</span><br><span style="color: hsl(120, 100%, 40%);">+  SCOPE_ENTER(1, "%s Topology: %s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+         ast_sip_session_get_name(session),</span><br><span style="color: hsl(120, 100%, 40%);">+            ast_str_tmp(256, ast_stream_topology_to_str(channel->session->pending_media_state->topology, &STR_TMP))</span><br><span style="color: hsl(120, 100%, 40%);">+          );</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-  int res = ast_sip_session_create_invite(session, &tdata);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+       res = ast_sip_session_create_invite(session, &tdata);</span><br><span> </span><br><span>        if (res) {</span><br><span>           ast_set_hangupsource(session->channel, ast_channel_name(session->channel), 0);</span><br><span>@@ -2409,22 +2445,24 @@</span><br><span>               ast_sip_session_send_request(session, tdata);</span><br><span>        }</span><br><span>    ao2_ref(channel, -1);</span><br><span style="color: hsl(0, 100%, 40%);">-   return res;</span><br><span style="color: hsl(120, 100%, 40%);">+   SCOPE_EXIT_RTN_VALUE(res, "RC: %d\n", res);</span><br><span> }</span><br><span> </span><br><span> /*! \brief Function called by core to actually start calling a remote party */</span><br><span> static int chan_pjsip_call(struct ast_channel *ast, const char *dest, int timeout)</span><br><span> {</span><br><span>  struct ast_sip_channel_pvt *channel = ast_channel_tech_pvt(ast);</span><br><span style="color: hsl(120, 100%, 40%);">+      SCOPE_ENTER(1, "%s Topology: %s\n", ast_sip_session_get_name(channel->session),</span><br><span style="color: hsl(120, 100%, 40%);">+          ast_str_tmp(256, ast_stream_topology_to_str(channel->session->pending_media_state->topology, &STR_TMP)));</span><br><span> </span><br><span>   ao2_ref(channel, +1);</span><br><span>        if (ast_sip_push_task(channel->session->serializer, call, channel)) {</span><br><span>          ast_log(LOG_WARNING, "Error attempting to place outbound call to '%s'\n", dest);</span><br><span>           ao2_cleanup(channel);</span><br><span style="color: hsl(0, 100%, 40%);">-           return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+            SCOPE_EXIT_RTN_VALUE(-1, "Couldn't push task\n");</span><br><span>      }</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-   return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+     SCOPE_EXIT_RTN_VALUE(0, "'call' task pushed\n");</span><br><span> }</span><br><span> </span><br><span> /*! \brief Internal function which translates from Asterisk cause codes to SIP response codes */</span><br><span>@@ -2514,6 +2552,8 @@</span><br><span>      struct hangup_data *h_data = data;</span><br><span>   struct ast_channel *ast = h_data->chan;</span><br><span>   struct ast_sip_channel_pvt *channel = ast_channel_tech_pvt(ast);</span><br><span style="color: hsl(120, 100%, 40%);">+      SCOPE_ENTER(1, "%s\n", ast_channel_name(ast));</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span>   /*</span><br><span>    * Before cleaning we have to ensure that channel or its session is not NULL</span><br><span>          * we have seen rare case when taskprocessor calls hangup but channel is NULL</span><br><span>@@ -2536,7 +2576,7 @@</span><br><span>                ao2_cleanup(channel);</span><br><span>        }</span><br><span>    ao2_cleanup(h_data);</span><br><span style="color: hsl(0, 100%, 40%);">-    return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+     SCOPE_EXIT_RTN_VALUE(0);</span><br><span> }</span><br><span> </span><br><span> /*! \brief Function called by core to hang up a PJSIP session */</span><br><span>@@ -2545,9 +2585,10 @@</span><br><span>       struct ast_sip_channel_pvt *channel = ast_channel_tech_pvt(ast);</span><br><span>     int cause;</span><br><span>   struct hangup_data *h_data;</span><br><span style="color: hsl(120, 100%, 40%);">+   SCOPE_ENTER(1, "%s\n", ast_channel_name(ast));</span><br><span> </span><br><span>         if (!channel || !channel->session) {</span><br><span style="color: hsl(0, 100%, 40%);">-         return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+            SCOPE_EXIT_RTN_VALUE(-1, "No channel or session\n");</span><br><span>       }</span><br><span> </span><br><span>        cause = hangup_cause2sip(ast_channel_hangupcause(channel->session->channel));</span><br><span>@@ -2562,7 +2603,7 @@</span><br><span>          goto failure;</span><br><span>        }</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-   return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+     SCOPE_EXIT_RTN_VALUE(0, "Cause: %d\n", cause);</span><br><span> </span><br><span> failure:</span><br><span>     /* Go ahead and do our cleanup of the session and channel even if we're not going</span><br><span>@@ -2572,7 +2613,7 @@</span><br><span>        ao2_cleanup(channel);</span><br><span>        ao2_cleanup(h_data);</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-        return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+    SCOPE_EXIT_RTN_VALUE(-1, "Cause: %d\n", cause);</span><br><span> }</span><br><span> </span><br><span> struct request_data {</span><br><span>@@ -2593,11 +2634,12 @@</span><br><span>                AST_APP_ARG(endpoint);</span><br><span>               AST_APP_ARG(aor);</span><br><span>    );</span><br><span style="color: hsl(120, 100%, 40%);">+    SCOPE_ENTER(1, "%s\n",tmp);</span><br><span> </span><br><span>    if (ast_strlen_zero(tmp)) {</span><br><span>          ast_log(LOG_ERROR, "Unable to create PJSIP channel with empty destination\n");</span><br><span>             req_data->cause = AST_CAUSE_CHANNEL_UNACCEPTABLE;</span><br><span style="color: hsl(0, 100%, 40%);">-            return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+            SCOPE_EXIT_RTN_VALUE(-1, "Empty destination\n");</span><br><span>   }</span><br><span> </span><br><span>        AST_NONSTANDARD_APP_ARGS(args, tmp, '/');</span><br><span>@@ -2619,14 +2661,14 @@</span><br><span>                          ast_log(LOG_ERROR, "Unable to create PJSIP channel with empty endpoint name\n");</span><br><span>                   }</span><br><span>                    req_data->cause = AST_CAUSE_CHANNEL_UNACCEPTABLE;</span><br><span style="color: hsl(0, 100%, 40%);">-                    return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+                    SCOPE_EXIT_RTN_VALUE(-1, "Empty endpoint name\n");</span><br><span>                 }</span><br><span>            endpoint = ast_sorcery_retrieve_by_id(ast_sip_get_sorcery(), "endpoint",</span><br><span>                   endpoint_name);</span><br><span>              if (!endpoint) {</span><br><span>                     ast_log(LOG_ERROR, "Unable to create PJSIP channel - endpoint '%s' was not found\n", endpoint_name);</span><br><span>                       req_data->cause = AST_CAUSE_NO_ROUTE_DESTINATION;</span><br><span style="color: hsl(0, 100%, 40%);">-                    return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+                    SCOPE_EXIT_RTN_VALUE(-1, "Endpoint not found\n");</span><br><span>          }</span><br><span>    } else {</span><br><span>             /* First try to find an exact endpoint match, for single (user) or multi-domain (user@domain) */</span><br><span>@@ -2634,7 +2676,7 @@</span><br><span>             if (ast_strlen_zero(endpoint_name)) {</span><br><span>                        ast_log(LOG_ERROR, "Unable to create PJSIP channel with empty endpoint name\n");</span><br><span>                   req_data->cause = AST_CAUSE_CHANNEL_UNACCEPTABLE;</span><br><span style="color: hsl(0, 100%, 40%);">-                    return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+                    SCOPE_EXIT_RTN_VALUE(-1, "Empty endpoint name\n");</span><br><span>                 }</span><br><span>            endpoint = ast_sorcery_retrieve_by_id(ast_sip_get_sorcery(), "endpoint",</span><br><span>                   endpoint_name);</span><br><span>@@ -2652,7 +2694,7 @@</span><br><span>                              ast_log(LOG_ERROR, "Unable to create PJSIP channel - endpoint '%s' was not found\n",</span><br><span>                                       args.endpoint);</span><br><span>                              req_data->cause = AST_CAUSE_NO_ROUTE_DESTINATION;</span><br><span style="color: hsl(0, 100%, 40%);">-                            return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+                            SCOPE_EXIT_RTN_VALUE(-1, "Endpoint not found\n");</span><br><span>                  }</span><br><span>                    request_user = args.endpoint;</span><br><span>                        *endpoint_name++ = '\0';</span><br><span>@@ -2661,7 +2703,7 @@</span><br><span>                             ast_log(LOG_ERROR, "Unable to create PJSIP channel with empty endpoint name: %s@<endpoint-name>\n",</span><br><span>                                  request_user);</span><br><span>                               req_data->cause = AST_CAUSE_CHANNEL_UNACCEPTABLE;</span><br><span style="color: hsl(0, 100%, 40%);">-                            return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+                            SCOPE_EXIT_RTN_VALUE(-1, "Empty endpoint name\n");</span><br><span>                         }</span><br><span> </span><br><span>                        endpoint = ast_sorcery_retrieve_by_id(ast_sip_get_sorcery(), "endpoint",</span><br><span>@@ -2669,7 +2711,7 @@</span><br><span>                   if (!endpoint) {</span><br><span>                             ast_log(LOG_ERROR, "Unable to create PJSIP channel - endpoint '%s' was not found\n", endpoint_name);</span><br><span>                               req_data->cause = AST_CAUSE_NO_ROUTE_DESTINATION;</span><br><span style="color: hsl(0, 100%, 40%);">-                            return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+                            SCOPE_EXIT_RTN_VALUE(-1, "Endpoint not found\n");</span><br><span>                  }</span><br><span>            }</span><br><span>    }</span><br><span>@@ -2680,12 +2722,12 @@</span><br><span>  if (!session) {</span><br><span>              ast_log(LOG_ERROR, "Failed to create outgoing session to endpoint '%s'\n", endpoint_name);</span><br><span>                 req_data->cause = AST_CAUSE_NO_ROUTE_DESTINATION;</span><br><span style="color: hsl(0, 100%, 40%);">-            return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+            SCOPE_EXIT_RTN_VALUE(-1, "Couldn't create session\n");</span><br><span>         }</span><br><span> </span><br><span>        req_data->session = session;</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-     return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+     SCOPE_EXIT_RTN_VALUE(0);</span><br><span> }</span><br><span> </span><br><span> /*! \brief Function called by core to create a new outgoing PJSIP session */</span><br><span>@@ -2693,6 +2735,8 @@</span><br><span> {</span><br><span>       struct request_data req_data;</span><br><span>        RAII_VAR(struct ast_sip_session *, session, NULL, ao2_cleanup);</span><br><span style="color: hsl(120, 100%, 40%);">+       SCOPE_ENTER(1, "%s Topology: %s\n", data,</span><br><span style="color: hsl(120, 100%, 40%);">+           ast_str_tmp(256, ast_stream_topology_to_str(topology, &STR_TMP)));</span><br><span> </span><br><span>   req_data.topology = topology;</span><br><span>        req_data.dest = data;</span><br><span>@@ -2701,17 +2745,17 @@</span><br><span> </span><br><span>  if (ast_sip_push_task_wait_servant(NULL, request, &req_data)) {</span><br><span>          *cause = req_data.cause;</span><br><span style="color: hsl(0, 100%, 40%);">-                return NULL;</span><br><span style="color: hsl(120, 100%, 40%);">+          SCOPE_EXIT_RTN_VALUE(NULL, "Couldn't push task\n");</span><br><span>    }</span><br><span> </span><br><span>        session = req_data.session;</span><br><span> </span><br><span>      if (!(session->channel = chan_pjsip_new(session, AST_STATE_DOWN, NULL, NULL, assignedids, requestor, NULL))) {</span><br><span>            /* Session needs to be terminated prematurely */</span><br><span style="color: hsl(0, 100%, 40%);">-                return NULL;</span><br><span style="color: hsl(120, 100%, 40%);">+          SCOPE_EXIT_RTN_VALUE(NULL, "Couldn't create channel\n");</span><br><span>       }</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-   return session->channel;</span><br><span style="color: hsl(120, 100%, 40%);">+   SCOPE_EXIT_RTN_VALUE(session->channel, "Channel: %s\n", ast_channel_name(session->channel));</span><br><span> }</span><br><span> </span><br><span> static struct ast_channel *chan_pjsip_request(const char *type, struct ast_format_cap *cap, const struct ast_assigned_ids *assignedids, const struct ast_channel *requestor, const char *data, int *cause)</span><br><span>@@ -2988,27 +3032,31 @@</span><br><span> static void chan_pjsip_session_begin(struct ast_sip_session *session)</span><br><span> {</span><br><span>  RAII_VAR(struct ast_datastore *, datastore, NULL, ao2_cleanup);</span><br><span style="color: hsl(120, 100%, 40%);">+       SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(session));</span><br><span> </span><br><span>     if (session->endpoint->media.direct_media.glare_mitigation ==</span><br><span>                  AST_SIP_DIRECT_MEDIA_GLARE_MITIGATION_NONE) {</span><br><span style="color: hsl(0, 100%, 40%);">-           return;</span><br><span style="color: hsl(120, 100%, 40%);">+               SCOPE_EXIT_RTN("Direct media no glare mitigation\n");</span><br><span>      }</span><br><span> </span><br><span>        datastore = ast_sip_session_alloc_datastore(&direct_media_mitigation_info,</span><br><span>                       "direct_media_glare_mitigation");</span><br><span> </span><br><span>      if (!datastore) {</span><br><span style="color: hsl(0, 100%, 40%);">-               return;</span><br><span style="color: hsl(120, 100%, 40%);">+               SCOPE_EXIT_RTN("Couldn't create datastore\n");</span><br><span>         }</span><br><span> </span><br><span>        ast_sip_session_add_datastore(session, datastore);</span><br><span style="color: hsl(120, 100%, 40%);">+    SCOPE_EXIT_RTN();</span><br><span> }</span><br><span> </span><br><span> /*! \brief Function called when the session ends */</span><br><span> static void chan_pjsip_session_end(struct ast_sip_session *session)</span><br><span> {</span><br><span style="color: hsl(120, 100%, 40%);">+ SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(session));</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span>       if (!session->channel) {</span><br><span style="color: hsl(0, 100%, 40%);">-             return;</span><br><span style="color: hsl(120, 100%, 40%);">+               SCOPE_EXIT_RTN("No channel\n");</span><br><span>    }</span><br><span> </span><br><span>        chan_pjsip_remove_hold(ast_channel_uniqueid(session->channel));</span><br><span>@@ -3021,6 +3069,8 @@</span><br><span>   } else {</span><br><span>             ast_queue_hangup(session->channel);</span><br><span>       }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+   SCOPE_EXIT_RTN();</span><br><span> }</span><br><span> </span><br><span> /*! \brief Function called when a request is received on the session */</span><br><span>@@ -3029,9 +3079,10 @@</span><br><span>       RAII_VAR(struct ast_datastore *, datastore, NULL, ao2_cleanup);</span><br><span>      struct transport_info_data *transport_data;</span><br><span>  pjsip_tx_data *packet = NULL;</span><br><span style="color: hsl(120, 100%, 40%);">+ SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(session));</span><br><span> </span><br><span>     if (session->channel) {</span><br><span style="color: hsl(0, 100%, 40%);">-              return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+             SCOPE_EXIT_RTN_VALUE(0, "Already have channel\n");</span><br><span>         }</span><br><span> </span><br><span>        /* Check for a to-tag to determine if this is a reinvite */</span><br><span>@@ -3047,17 +3098,17 @@</span><br><span>                 */</span><br><span>          session->defer_terminate = 0;</span><br><span>             ast_sip_session_terminate(session, 400);</span><br><span style="color: hsl(0, 100%, 40%);">-                return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+            SCOPE_EXIT_RTN_VALUE(-1, "Reinvite without channel\n");</span><br><span>    }</span><br><span> </span><br><span>        datastore = ast_sip_session_alloc_datastore(&transport_info, "transport_info");</span><br><span>        if (!datastore) {</span><br><span style="color: hsl(0, 100%, 40%);">-               return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+            SCOPE_EXIT_RTN_VALUE(-1, "Couldn't create datastore\n");</span><br><span>       }</span><br><span> </span><br><span>        transport_data = ast_calloc(1, sizeof(*transport_data));</span><br><span>     if (!transport_data) {</span><br><span style="color: hsl(0, 100%, 40%);">-          return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+            SCOPE_EXIT_RTN_VALUE(-1, "Couldn't create transport_data\n");</span><br><span>  }</span><br><span>    pj_sockaddr_cp(&transport_data->local_addr, &rdata->tp_info.transport->local_addr);</span><br><span>         pj_sockaddr_cp(&transport_data->remote_addr, &rdata->pkt_info.src_addr);</span><br><span>@@ -3071,11 +3122,11 @@</span><br><span>             }</span><br><span> </span><br><span>                ast_log(LOG_ERROR, "Failed to allocate new PJSIP channel on incoming SIP INVITE\n");</span><br><span style="color: hsl(0, 100%, 40%);">-          return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+            SCOPE_EXIT_RTN_VALUE(-1, "Couldn't create channel\n");</span><br><span>         }</span><br><span>    /* channel gets created on incoming request, but we wait to call start</span><br><span>            so other supplements have a chance to run */</span><br><span style="color: hsl(0, 100%, 40%);">-       return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+     SCOPE_EXIT_RTN_VALUE(0);</span><br><span> }</span><br><span> </span><br><span> static int call_pickup_incoming_request(struct ast_sip_session *session, pjsip_rx_data *rdata)</span><br><span>@@ -3131,11 +3182,12 @@</span><br><span> static int pbx_start_incoming_request(struct ast_sip_session *session, pjsip_rx_data *rdata)</span><br><span> {</span><br><span>   int res;</span><br><span style="color: hsl(120, 100%, 40%);">+      SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(session));</span><br><span> </span><br><span>     /* Check for a to-tag to determine if this is a reinvite */</span><br><span>  if (rdata->msg_info.to->tag.slen) {</span><br><span>            /* We don't care about reinvites */</span><br><span style="color: hsl(0, 100%, 40%);">-         return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+             SCOPE_EXIT_RTN_VALUE(0, "Reinvite\n");</span><br><span>     }</span><br><span> </span><br><span>        res = ast_pbx_start(session->channel);</span><br><span>@@ -3158,7 +3210,7 @@</span><br><span> </span><br><span>        ast_debug(3, "Started PBX on new PJSIP channel %s\n", ast_channel_name(session->channel));</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-     return (res == AST_PBX_SUCCESS) ? 0 : -1;</span><br><span style="color: hsl(120, 100%, 40%);">+     SCOPE_EXIT_RTN_VALUE((res == AST_PBX_SUCCESS) ? 0 : -1, "RC: %d\n", res);</span><br><span> }</span><br><span> </span><br><span> static struct ast_sip_session_supplement pbx_start_supplement = {</span><br><span>@@ -3173,9 +3225,11 @@</span><br><span>   struct pjsip_status_line status = rdata->msg_info.msg->line.status;</span><br><span>    struct ast_control_pvt_cause_code *cause_code;</span><br><span>       int data_size = sizeof(*cause_code);</span><br><span style="color: hsl(120, 100%, 40%);">+  SCOPE_ENTER(1, "%s Method: %.*s Status: %d\n", ast_sip_session_get_name(session),</span><br><span style="color: hsl(120, 100%, 40%);">+           (int)rdata->msg_info.cseq->method.name.slen, rdata->msg_info.cseq->method.name.ptr, status.code);</span><br><span> </span><br><span>    if (!session->channel) {</span><br><span style="color: hsl(0, 100%, 40%);">-             return;</span><br><span style="color: hsl(120, 100%, 40%);">+               SCOPE_EXIT_RTN("No channel\n");</span><br><span>    }</span><br><span> </span><br><span>        /* Build and send the tech-specific cause information */</span><br><span>@@ -3195,6 +3249,8 @@</span><br><span> </span><br><span>         switch (status.code) {</span><br><span>       case 180:</span><br><span style="color: hsl(120, 100%, 40%);">+             ast_trace(1, "%s Method: %.*s Status: %d  Queueing RINGING\n", ast_sip_session_get_name(session),</span><br><span style="color: hsl(120, 100%, 40%);">+                   (int)rdata->msg_info.cseq->method.name.slen, rdata->msg_info.cseq->method.name.ptr, status.code);</span><br><span>                ast_queue_control(session->channel, AST_CONTROL_RINGING);</span><br><span>                 ast_channel_lock(session->channel);</span><br><span>               if (ast_channel_state(session->channel) != AST_STATE_UP) {</span><br><span>@@ -3206,28 +3262,45 @@</span><br><span>              if (session->endpoint->ignore_183_without_sdp) {</span><br><span>                       pjsip_rdata_sdp_info *sdp = pjsip_rdata_get_sdp_info(rdata);</span><br><span>                         if (sdp && sdp->body.ptr) {</span><br><span style="color: hsl(120, 100%, 40%);">+                                ast_trace(1, "%s Method: %.*s Status: %d  Queueing PROGRESS with SDP\n", ast_sip_session_get_name(session),</span><br><span style="color: hsl(120, 100%, 40%);">+                                 (int)rdata->msg_info.cseq->method.name.slen, rdata->msg_info.cseq->method.name.ptr, status.code);</span><br><span>                                ast_queue_control(session->channel, AST_CONTROL_PROGRESS);</span><br><span>                        }</span><br><span>            } else {</span><br><span style="color: hsl(120, 100%, 40%);">+                      ast_trace(1, "%s Method: %.*s Status: %d  Queueing PROGRESS without SDP\n", ast_sip_session_get_name(session),</span><br><span style="color: hsl(120, 100%, 40%);">+                              (int)rdata->msg_info.cseq->method.name.slen, rdata->msg_info.cseq->method.name.ptr, status.code);</span><br><span>                        ast_queue_control(session->channel, AST_CONTROL_PROGRESS);</span><br><span>                }</span><br><span>            break;</span><br><span>       case 200:</span><br><span style="color: hsl(120, 100%, 40%);">+             ast_trace(1, "%s Method: %.*s Status: %d  Queueing ANSWER\n", ast_sip_session_get_name(session),</span><br><span style="color: hsl(120, 100%, 40%);">+                    (int)rdata->msg_info.cseq->method.name.slen, rdata->msg_info.cseq->method.name.ptr, status.code);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span>              ast_queue_control(session->channel, AST_CONTROL_ANSWER);</span><br><span>          break;</span><br><span>       default:</span><br><span style="color: hsl(120, 100%, 40%);">+              ast_trace(1, "%s Method: %.*s Status: %d  Ignored\n", ast_sip_session_get_name(session),</span><br><span style="color: hsl(120, 100%, 40%);">+                    (int)rdata->msg_info.cseq->method.name.slen, rdata->msg_info.cseq->method.name.ptr, status.code);</span><br><span>                break;</span><br><span>       }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+   SCOPE_EXIT_RTN();</span><br><span> }</span><br><span> </span><br><span> static int chan_pjsip_incoming_ack(struct ast_sip_session *session, struct pjsip_rx_data *rdata)</span><br><span> {</span><br><span style="color: hsl(120, 100%, 40%);">+   SCOPE_ENTER(1, "%s Method: %.*s Status: %d  After Media\n", ast_sip_session_get_name(session),</span><br><span style="color: hsl(120, 100%, 40%);">+              (int)rdata->msg_info.cseq->method.name.slen, rdata->msg_info.cseq->method.name.ptr,</span><br><span style="color: hsl(120, 100%, 40%);">+               rdata->msg_info.msg->line.status.code);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span>      if (rdata->msg_info.msg->line.req.method.id == PJSIP_ACK_METHOD) {</span><br><span>             if (session->endpoint->media.direct_media.enabled && session->channel) {</span><br><span style="color: hsl(120, 100%, 40%);">+                     ast_trace(1, "%s Method: %.*s  Queueing SRCCHANGE\n", ast_sip_session_get_name(session),</span><br><span style="color: hsl(120, 100%, 40%);">+                            (int)rdata->msg_info.cseq->method.name.slen, rdata->msg_info.cseq->method.name.ptr);</span><br><span>                     ast_queue_control(session->channel, AST_CONTROL_SRCCHANGE);</span><br><span>               }</span><br><span>    }</span><br><span style="color: hsl(0, 100%, 40%);">-       return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+     SCOPE_EXIT_RTN_VALUE(0);</span><br><span> }</span><br><span> </span><br><span> static int update_devstate(void *obj, void *arg, int flags)</span><br><span>diff --git a/include/asterisk/res_pjsip_session.h b/include/asterisk/res_pjsip_session.h</span><br><span>index fd49a7b..9db68a8 100644</span><br><span>--- a/include/asterisk/res_pjsip_session.h</span><br><span>+++ b/include/asterisk/res_pjsip_session.h</span><br><span>@@ -926,4 +926,13 @@</span><br><span>  */</span><br><span> struct ast_sip_session_media *ast_sip_session_media_get_transport(struct ast_sip_session *session, struct ast_sip_session_media *session_media);</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+/*!</span><br><span style="color: hsl(120, 100%, 40%);">+ * \brief Get the channel or endpoint name associated with the session</span><br><span style="color: hsl(120, 100%, 40%);">+ * \since 18.0.0</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * \param session</span><br><span style="color: hsl(120, 100%, 40%);">+ * \retval Channel name or endpoint name or "unknown"</span><br><span style="color: hsl(120, 100%, 40%);">+ */</span><br><span style="color: hsl(120, 100%, 40%);">+const char *ast_sip_session_get_name(const struct ast_sip_session *session);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> #endif /* _RES_PJSIP_SESSION_H */</span><br><span>diff --git a/main/bridge.c b/main/bridge.c</span><br><span>index fb7012d..7a7b6f6 100644</span><br><span>--- a/main/bridge.c</span><br><span>+++ b/main/bridge.c</span><br><span>@@ -1673,6 +1673,7 @@</span><br><span> {</span><br><span>   struct ast_bridge_channel *bridge_channel;</span><br><span>   int res = 0;</span><br><span style="color: hsl(120, 100%, 40%);">+  SCOPE_TRACE(1, "%s Bridge: %s\n", ast_channel_name(chan), bridge->uniqueid);</span><br><span> </span><br><span>        bridge_channel = bridge_channel_internal_alloc(bridge);</span><br><span>      if (flags & AST_BRIDGE_JOIN_PASS_REFERENCE) {</span><br><span>@@ -1921,6 +1922,7 @@</span><br><span>            .done = 0,</span><br><span>   };</span><br><span>   int res;</span><br><span style="color: hsl(120, 100%, 40%);">+      SCOPE_TRACE(1, "%s Bridge: %s\n", ast_channel_name(chan), bridge->uniqueid);</span><br><span> </span><br><span>        ast_mutex_init(&cond.lock);</span><br><span>      ast_cond_init(&cond.cond, NULL);</span><br><span>@@ -1942,6 +1944,7 @@</span><br><span> {</span><br><span>    struct ast_bridge_channel *bridge_channel;</span><br><span>   int departable;</span><br><span style="color: hsl(120, 100%, 40%);">+       SCOPE_TRACE(1, "%s\n", ast_channel_name(chan));</span><br><span> </span><br><span>        ast_channel_lock(chan);</span><br><span>      bridge_channel = ast_channel_internal_bridge_channel(chan);</span><br><span>diff --git a/main/channel.c b/main/channel.c</span><br><span>index 2f3aad1..8dd008d 100644</span><br><span>--- a/main/channel.c</span><br><span>+++ b/main/channel.c</span><br><span>@@ -2622,6 +2622,7 @@</span><br><span> int ast_raw_answer(struct ast_channel *chan)</span><br><span> {</span><br><span>        int res = 0;</span><br><span style="color: hsl(120, 100%, 40%);">+  SCOPE_TRACE(1, "%s\n", ast_channel_name(chan));</span><br><span> </span><br><span>        ast_channel_lock(chan);</span><br><span> </span><br><span>@@ -2670,6 +2671,7 @@</span><br><span> {</span><br><span>     int res = 0;</span><br><span>         enum ast_channel_state old_state;</span><br><span style="color: hsl(120, 100%, 40%);">+     SCOPE_TRACE(1, "%s\n", ast_channel_name(chan));</span><br><span> </span><br><span>        old_state = ast_channel_state(chan);</span><br><span>         if ((res = ast_raw_answer(chan))) {</span><br><span>@@ -2777,6 +2779,7 @@</span><br><span> </span><br><span> int ast_answer(struct ast_channel *chan)</span><br><span> {</span><br><span style="color: hsl(120, 100%, 40%);">+      SCOPE_TRACE(1, "%s\n", ast_channel_name(chan));</span><br><span>    return __ast_answer(chan, 0);</span><br><span> }</span><br><span> </span><br><span>diff --git a/main/channel_internal_api.c b/main/channel_internal_api.c</span><br><span>index be8fd7c..fb62da5 100644</span><br><span>--- a/main/channel_internal_api.c</span><br><span>+++ b/main/channel_internal_api.c</span><br><span>@@ -677,6 +677,10 @@</span><br><span> void ast_channel_nativeformats_set(struct ast_channel *chan,</span><br><span>       struct ast_format_cap *value)</span><br><span> {</span><br><span style="color: hsl(120, 100%, 40%);">+    SCOPE_ENTER(2, "%s: %sFormats: %s\n", S_OR(ast_channel_name(chan), "<initializing>"),</span><br><span style="color: hsl(120, 100%, 40%);">+               S_COR(ast_channel_is_multistream(chan), "Multistream", ""),</span><br><span style="color: hsl(120, 100%, 40%);">+               ast_str_tmp(128, ast_format_cap_get_names(value, &STR_TMP)));</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span>  ast_assert(chan != NULL);</span><br><span> </span><br><span>        ao2_replace(chan->nativeformats, value);</span><br><span>@@ -685,7 +689,7 @@</span><br><span>     * and topology is destroyed.</span><br><span>         */</span><br><span>  if (!chan->stream_topology) {</span><br><span style="color: hsl(0, 100%, 40%);">-                return;</span><br><span style="color: hsl(120, 100%, 40%);">+               SCOPE_EXIT_RTN("Channel is being initialized or destroyed\n");</span><br><span>     }</span><br><span> </span><br><span>        if (!ast_channel_is_multistream(chan) || !value) {</span><br><span>@@ -693,7 +697,9 @@</span><br><span> </span><br><span>                 new_topology = ast_stream_topology_create_from_format_cap(value);</span><br><span>            ast_channel_internal_set_stream_topology(chan, new_topology);</span><br><span style="color: hsl(120, 100%, 40%);">+         SCOPE_EXIT_RTN("New %stopology set\n", value ? "" : "empty ");</span><br><span>         }</span><br><span style="color: hsl(120, 100%, 40%);">+     SCOPE_EXIT_RTN("Set native formats but not topology\n");</span><br><span> }</span><br><span> </span><br><span> struct ast_framehook_list *ast_channel_framehooks(const struct ast_channel *chan)</span><br><span>@@ -1586,6 +1592,8 @@</span><br><span>     struct ast_stream_topology *topology)</span><br><span> {</span><br><span>   struct ast_stream_topology *new_topology;</span><br><span style="color: hsl(120, 100%, 40%);">+     SCOPE_ENTER(1, "%s: %s\n", ast_channel_name(chan),</span><br><span style="color: hsl(120, 100%, 40%);">+          ast_str_tmp(256, ast_stream_topology_to_str(topology, &STR_TMP)));</span><br><span> </span><br><span>   ast_assert(chan != NULL);</span><br><span> </span><br><span>@@ -1605,7 +1613,7 @@</span><br><span>                ast_channel_internal_set_stream_topology(chan, new_topology);</span><br><span>        }</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-   return new_topology;</span><br><span style="color: hsl(120, 100%, 40%);">+  SCOPE_EXIT_RTN_VALUE(new_topology, "Used %s topology\n", topology ? "provided" : "empty");</span><br><span> }</span><br><span> </span><br><span> struct ast_stream *ast_channel_get_default_stream(struct ast_channel *chan,</span><br><span>diff --git a/main/features.c b/main/features.c</span><br><span>index ab03bef..51cc3ed 100644</span><br><span>--- a/main/features.c</span><br><span>+++ b/main/features.c</span><br><span>@@ -536,6 +536,7 @@</span><br><span>              struct ast_bridge_features *chan_features, struct ast_bridge_features *peer_features)</span><br><span> {</span><br><span>   int res;</span><br><span style="color: hsl(120, 100%, 40%);">+      SCOPE_TRACE(1, "%s Peer: %s\n", ast_channel_name(chan), ast_channel_name(peer));</span><br><span> </span><br><span>       set_bridge_features_on_config(config, pbx_builtin_getvar_helper(chan, "BRIDGE_FEATURES"));</span><br><span>         add_features_datastores(chan, peer, config);</span><br><span>@@ -629,6 +630,7 @@</span><br><span>   struct ast_bridge *bridge;</span><br><span>   struct ast_bridge_features chan_features;</span><br><span>    struct ast_bridge_features *peer_features;</span><br><span style="color: hsl(120, 100%, 40%);">+    SCOPE_TRACE(1, "%s Peer: %s\n", ast_channel_name(chan), ast_channel_name(peer));</span><br><span> </span><br><span>       /* Setup features. */</span><br><span>        res = ast_bridge_features_init(&chan_features);</span><br><span>diff --git a/res/res_pjsip_sdp_rtp.c b/res/res_pjsip_sdp_rtp.c</span><br><span>index 1bcb661..eacae22 100644</span><br><span>--- a/res/res_pjsip_sdp_rtp.c</span><br><span>+++ b/res/res_pjsip_sdp_rtp.c</span><br><span>@@ -324,6 +324,7 @@</span><br><span>   char fmt_param[256];</span><br><span>         enum ast_rtp_options options = session->endpoint->media.g726_non_standard ?</span><br><span>            AST_RTP_OPT_G726_NONSTANDARD : 0;</span><br><span style="color: hsl(120, 100%, 40%);">+     SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(session));</span><br><span> </span><br><span>     ast_rtp_codecs_payloads_initialize(codecs);</span><br><span> </span><br><span>@@ -395,6 +396,8 @@</span><br><span>                        ast_rtp_codecs_set_framing(codecs, framing);</span><br><span>                 }</span><br><span>    }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+   SCOPE_EXIT_RTN();</span><br><span> }</span><br><span> </span><br><span> static int apply_cap_to_bundled(struct ast_sip_session_media *session_media,</span><br><span>@@ -436,12 +439,14 @@</span><br><span>   struct ast_format_cap *remote;</span><br><span>       struct ast_rtp_codecs codecs = AST_RTP_CODECS_NULL_INIT;</span><br><span>     int fmts = 0;</span><br><span style="color: hsl(120, 100%, 40%);">+ SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(session));</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> </span><br><span>   remote = ast_format_cap_alloc(AST_FORMAT_CAP_FLAG_DEFAULT);</span><br><span>  if (!remote) {</span><br><span>               ast_log(LOG_ERROR, "Failed to allocate %s incoming remote capabilities\n",</span><br><span>                                 ast_codec_media_type2str(session_media->type));</span><br><span style="color: hsl(0, 100%, 40%);">-              return NULL;</span><br><span style="color: hsl(120, 100%, 40%);">+          SCOPE_EXIT_RTN_VALUE(NULL, "Couldn't allocate caps\n");</span><br><span>        }</span><br><span> </span><br><span>        /* Get the peer's capabilities*/</span><br><span>@@ -456,7 +461,7 @@</span><br><span>   if (!incoming_call_offer_cap || ast_format_cap_empty(incoming_call_offer_cap)) {</span><br><span>             ao2_cleanup(incoming_call_offer_cap);</span><br><span>                ast_rtp_codecs_payloads_destroy(&codecs);</span><br><span style="color: hsl(0, 100%, 40%);">-           return NULL;</span><br><span style="color: hsl(120, 100%, 40%);">+          SCOPE_EXIT_RTN_VALUE(NULL, "No incoming call offer caps\n");</span><br><span>       }</span><br><span> </span><br><span>        /*</span><br><span>@@ -470,7 +475,7 @@</span><br><span> </span><br><span>         ast_rtp_codecs_payloads_destroy(&codecs);</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-       return incoming_call_offer_cap;</span><br><span style="color: hsl(120, 100%, 40%);">+       SCOPE_EXIT_RTN_VALUE(incoming_call_offer_cap);</span><br><span> }</span><br><span> </span><br><span> static int set_caps(struct ast_sip_session *session,</span><br><span>@@ -488,13 +493,15 @@</span><br><span>      int direct_media_enabled = !ast_sockaddr_isnull(&session_media->direct_media_addr) &&</span><br><span>                 ast_format_cap_count(session->direct_media_cap);</span><br><span>  int dsp_features = 0;</span><br><span style="color: hsl(120, 100%, 40%);">+ SCOPE_ENTER(1, "%s %s\n", ast_sip_session_get_name(session), is_offer ? "OFFER" : "ANSWER");</span><br><span> </span><br><span>       if (!(caps = ast_format_cap_alloc(AST_FORMAT_CAP_FLAG_DEFAULT)) ||</span><br><span>       !(peer = ast_format_cap_alloc(AST_FORMAT_CAP_FLAG_DEFAULT)) ||</span><br><span>       !(joint = ast_format_cap_alloc(AST_FORMAT_CAP_FLAG_DEFAULT))) {</span><br><span>          ast_log(LOG_ERROR, "Failed to allocate %s capabilities\n",</span><br><span>                         ast_codec_media_type2str(session_media->type));</span><br><span style="color: hsl(0, 100%, 40%);">-              return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+            SCOPE_EXIT_RTN_VALUE(-1, "Couldn't create %s capabilities\n",</span><br><span style="color: hsl(120, 100%, 40%);">+                   ast_codec_media_type2str(session_media->type));</span><br><span>   }</span><br><span> </span><br><span>        /* get the endpoint capabilities */</span><br><span>@@ -519,7 +526,10 @@</span><br><span>                   ast_codec_media_type2str(session_media->type),</span><br><span>                    ast_format_cap_get_names(caps, &usbuf),</span><br><span>                  ast_format_cap_get_names(peer, &thembuf));</span><br><span style="color: hsl(0, 100%, 40%);">-          return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+            SCOPE_EXIT_RTN_VALUE(-1, "No joint capabilities for '%s' media stream between our configuration(%s) and incoming SDP(%s)\n",</span><br><span style="color: hsl(120, 100%, 40%);">+                        ast_codec_media_type2str(session_media->type),</span><br><span style="color: hsl(120, 100%, 40%);">+                     ast_format_cap_get_names(caps, &usbuf),</span><br><span style="color: hsl(120, 100%, 40%);">+                   ast_format_cap_get_names(peer, &thembuf));</span><br><span>       }</span><br><span> </span><br><span>        if (is_offer) {</span><br><span>@@ -594,7 +604,7 @@</span><br><span>        }</span><br><span> </span><br><span>        ast_rtp_codecs_payloads_destroy(&codecs);</span><br><span style="color: hsl(0, 100%, 40%);">-   return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+     SCOPE_EXIT_RTN_VALUE(0);</span><br><span> }</span><br><span> </span><br><span> static pjmedia_sdp_attr* generate_rtpmap_attr(struct ast_sip_session *session, pjmedia_sdp_media *media, pj_pool_t *pool,</span><br><span>@@ -1416,12 +1426,13 @@</span><br><span>     enum ast_sip_session_media_encryption encryption = AST_SIP_MEDIA_ENCRYPT_NONE;</span><br><span>       struct ast_format_cap *joint;</span><br><span>        int res;</span><br><span style="color: hsl(120, 100%, 40%);">+      SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(session));</span><br><span> </span><br><span>     /* If no type formats have been configured reject this stream */</span><br><span>     if (!ast_format_cap_has_type(session->endpoint->media.codecs, media_type)) {</span><br><span>           ast_debug(3, "Endpoint has no codecs for media type '%s', declining stream\n",</span><br><span>                     ast_codec_media_type2str(session_media->type));</span><br><span style="color: hsl(0, 100%, 40%);">-              return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+             SCOPE_EXIT_RTN_VALUE(0, "Endpoint has no codecs\n");</span><br><span>       }</span><br><span> </span><br><span>        /* Ensure incoming transport is compatible with the endpoint's configuration */</span><br><span>@@ -1429,7 +1440,7 @@</span><br><span>          encryption = check_endpoint_media_transport(session->endpoint, stream);</span><br><span> </span><br><span>               if (encryption == AST_SIP_MEDIA_TRANSPORT_INVALID) {</span><br><span style="color: hsl(0, 100%, 40%);">-                    return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+                    SCOPE_EXIT_RTN_VALUE(-1, "Incompatible transport\n");</span><br><span>              }</span><br><span>    }</span><br><span> </span><br><span>@@ -1438,12 +1449,12 @@</span><br><span>      /* Ensure that the address provided is valid */</span><br><span>      if (ast_sockaddr_resolve(&addrs, host, PARSE_PORT_FORBID, AST_AF_UNSPEC) <= 0) {</span><br><span>              /* The provided host was actually invalid so we error out this negotiation */</span><br><span style="color: hsl(0, 100%, 40%);">-           return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+            SCOPE_EXIT_RTN_VALUE(-1, "Invalid host\n");</span><br><span>        }</span><br><span> </span><br><span>        /* Using the connection information create an appropriate RTP instance */</span><br><span>    if (!session_media->rtp && create_rtp(session, session_media, sdp)) {</span><br><span style="color: hsl(0, 100%, 40%);">-                return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+            SCOPE_EXIT_RTN_VALUE(-1, "Couldn't create rtp\n");</span><br><span>     }</span><br><span> </span><br><span>        process_ssrc_attributes(session, session_media, stream);</span><br><span>@@ -1465,7 +1476,7 @@</span><br><span>                              * but was not this session must fail. This must also fail if crypto was</span><br><span>                              * required in the offer but could not be set up.</span><br><span>                             */</span><br><span style="color: hsl(0, 100%, 40%);">-                             return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+                            SCOPE_EXIT_RTN_VALUE(-1, "Incompatible crypto\n");</span><br><span>                         }</span><br><span>                    /* There is no encryption, sad. */</span><br><span>                   session_media->encryption = AST_SIP_MEDIA_ENCRYPT_NONE;</span><br><span>@@ -1510,10 +1521,10 @@</span><br><span>         res = apply_cap_to_bundled(session_media, session_media_transport, asterisk_stream, joint);</span><br><span>  ao2_cleanup(joint);</span><br><span>  if (res != 0) {</span><br><span style="color: hsl(0, 100%, 40%);">-         return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+             SCOPE_EXIT_RTN_VALUE(0, "Something failed\n");</span><br><span>     }</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-   return 1;</span><br><span style="color: hsl(120, 100%, 40%);">+     SCOPE_EXIT_RTN_VALUE(1);</span><br><span> }</span><br><span> </span><br><span> static int add_crypto_to_stream(struct ast_sip_session *session,</span><br><span>@@ -1666,13 +1677,14 @@</span><br><span>      enum ast_media_type media_type = session_media->type;</span><br><span>     struct ast_sip_session_media *session_media_transport;</span><br><span>       pj_sockaddr ip;</span><br><span style="color: hsl(0, 100%, 40%);">-</span><br><span>      int direct_media_enabled = !ast_sockaddr_isnull(&session_media->direct_media_addr) &&</span><br><span>                 ast_format_cap_count(session->direct_media_cap);</span><br><span style="color: hsl(120, 100%, 40%);">+   SCOPE_ENTER(1, "%s Type: %s %s\n", ast_sip_session_get_name(session),</span><br><span style="color: hsl(120, 100%, 40%);">+               ast_codec_media_type2str(media_type), ast_str_tmp(128, ast_stream_to_str(stream, &STR_TMP)));</span><br><span> </span><br><span>        media = pj_pool_zalloc(pool, sizeof(struct pjmedia_sdp_media));</span><br><span>      if (!media) {</span><br><span style="color: hsl(0, 100%, 40%);">-           return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+            SCOPE_EXIT_RTN_VALUE(-1, "Pool alloc failure\n");</span><br><span>  }</span><br><span>    pj_strdup2(pool, &media->desc.media, ast_codec_media_type2str(session_media->type));</span><br><span> </span><br><span>@@ -1702,11 +1714,11 @@</span><br><span>                 sdp->media[sdp->media_count++] = media;</span><br><span>                ast_stream_set_state(stream, AST_STREAM_STATE_REMOVED);</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-             return 1;</span><br><span style="color: hsl(120, 100%, 40%);">+             SCOPE_EXIT_RTN_VALUE(1, "Stream removed or no formats\n");</span><br><span>         }</span><br><span> </span><br><span>        if (!session_media->rtp && create_rtp(session, session_media, sdp)) {</span><br><span style="color: hsl(0, 100%, 40%);">-                return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+            SCOPE_EXIT_RTN_VALUE(-1, "Couldn't create rtp\n");</span><br><span>     }</span><br><span> </span><br><span>        /* If this stream has not been bundled already it is new and we need to ensure there is no SSRC conflict */</span><br><span>@@ -1738,7 +1750,7 @@</span><br><span>           * set up according to the configuration. This ends up changing the media transport.</span><br><span>                  */</span><br><span>          if (add_crypto_to_stream(session, session_media, pool, media)) {</span><br><span style="color: hsl(0, 100%, 40%);">-                        return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+                    SCOPE_EXIT_RTN_VALUE(-1, "Couldn't add crypto\n");</span><br><span>             }</span><br><span> </span><br><span>                if (pj_strlen(&session_media->transport)) {</span><br><span>@@ -1755,7 +1767,7 @@</span><br><span> </span><br><span>               media->conn = pj_pool_zalloc(pool, sizeof(struct pjmedia_sdp_conn));</span><br><span>              if (!media->conn) {</span><br><span style="color: hsl(0, 100%, 40%);">-                  return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+                    SCOPE_EXIT_RTN_VALUE(-1, "Pool alloc failure\n");</span><br><span>          }</span><br><span> </span><br><span>                /* Add connection level details */</span><br><span>@@ -1770,7 +1782,7 @@</span><br><span>           if (ast_strlen_zero(hostip)) {</span><br><span>                       ast_log(LOG_ERROR, "No local host IP available for stream %s\n",</span><br><span>                           ast_codec_media_type2str(session_media->type));</span><br><span style="color: hsl(0, 100%, 40%);">-                      return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+                    SCOPE_EXIT_RTN_VALUE(-1, "No local host ip\n");</span><br><span>            }</span><br><span> </span><br><span>                media->conn->net_type = STR_IN;</span><br><span>@@ -1798,7 +1810,7 @@</span><br><span>                media->desc.port = bundle_group_stream->desc.port;</span><br><span> </span><br><span>                 if (add_crypto_to_stream(session, session_media_transport, pool, media)) {</span><br><span style="color: hsl(0, 100%, 40%);">-                      return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+                    SCOPE_EXIT_RTN_VALUE(-1, "Couldn't add crypto\n");</span><br><span>             }</span><br><span> </span><br><span>                add_ice_to_stream(session, session_media_transport, pool, media, 0);</span><br><span>@@ -1809,7 +1821,7 @@</span><br><span>         if (!(caps = ast_format_cap_alloc(AST_FORMAT_CAP_FLAG_DEFAULT))) {</span><br><span>           ast_log(LOG_ERROR, "Failed to allocate %s capabilities\n",</span><br><span>                         ast_codec_media_type2str(session_media->type));</span><br><span style="color: hsl(0, 100%, 40%);">-              return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+            SCOPE_EXIT_RTN_VALUE(-1, "Couldn't create caps\n");</span><br><span>    }</span><br><span> </span><br><span>        if (direct_media_enabled) {</span><br><span>@@ -1896,7 +1908,7 @@</span><br><span> </span><br><span>      /* If no formats were actually added to the media stream don't add it to the SDP */</span><br><span>      if (!media->desc.fmt_count) {</span><br><span style="color: hsl(0, 100%, 40%);">-                return 1;</span><br><span style="color: hsl(120, 100%, 40%);">+             SCOPE_EXIT_RTN_VALUE(1, "No formats added to stream\n");</span><br><span>   }</span><br><span> </span><br><span>        /* If ptime is set add it as an attribute */</span><br><span>@@ -1952,7 +1964,7 @@</span><br><span>         /* Add the media stream to the SDP */</span><br><span>        sdp->media[sdp->media_count++] = media;</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-       return 1;</span><br><span style="color: hsl(120, 100%, 40%);">+     SCOPE_EXIT_RTN_VALUE(1, "RC: 1\n");</span><br><span> }</span><br><span> </span><br><span> static struct ast_frame *media_session_rtp_read_callback(struct ast_sip_session *session, struct ast_sip_session_media *session_media)</span><br><span>@@ -2010,20 +2022,22 @@</span><br><span>   char host[NI_MAXHOST];</span><br><span>       int res;</span><br><span>     struct ast_sip_session_media *session_media_transport;</span><br><span style="color: hsl(120, 100%, 40%);">+        SCOPE_ENTER(1, "%s Stream: %s\n", ast_sip_session_get_name(session),</span><br><span style="color: hsl(120, 100%, 40%);">+                ast_str_tmp(128, ast_stream_to_str(asterisk_stream, &STR_TMP)));</span><br><span> </span><br><span>     if (!session->channel) {</span><br><span style="color: hsl(0, 100%, 40%);">-             return 1;</span><br><span style="color: hsl(120, 100%, 40%);">+             SCOPE_EXIT_RTN_VALUE(1, "No channel\n");</span><br><span>   }</span><br><span> </span><br><span>        /* Ensure incoming transport is compatible with the endpoint's configuration */</span><br><span>  if (!session->endpoint->media.rtp.use_received_transport &&</span><br><span>            check_endpoint_media_transport(session->endpoint, remote_stream) == AST_SIP_MEDIA_TRANSPORT_INVALID) {</span><br><span style="color: hsl(0, 100%, 40%);">-               return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+            SCOPE_EXIT_RTN_VALUE(-1, "Incompatible transport\n");</span><br><span>      }</span><br><span> </span><br><span>        /* Create an RTP instance if need be */</span><br><span>      if (!session_media->rtp && create_rtp(session, session_media, local)) {</span><br><span style="color: hsl(0, 100%, 40%);">-              return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+            SCOPE_EXIT_RTN_VALUE(-1, "Couldn't create rtp\n");</span><br><span>     }</span><br><span> </span><br><span>        process_ssrc_attributes(session, session_media, remote_stream);</span><br><span>@@ -2042,11 +2056,11 @@</span><br><span>                    /* If optimistic encryption is disabled and crypto should have been enabled but was not</span><br><span>                       * this session must fail.</span><br><span>                    */</span><br><span style="color: hsl(0, 100%, 40%);">-                     return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+                    SCOPE_EXIT_RTN_VALUE(-1, "Incompatible crypto\n");</span><br><span>                 }</span><br><span> </span><br><span>                if (!remote_stream->conn && !remote->conn) {</span><br><span style="color: hsl(0, 100%, 40%);">-                      return 1;</span><br><span style="color: hsl(120, 100%, 40%);">+                     SCOPE_EXIT_RTN_VALUE(1, "No connection info\n");</span><br><span>           }</span><br><span> </span><br><span>                ast_copy_pj_str(host, remote_stream->conn ? &remote_stream->conn->addr : &remote->conn->addr, sizeof(host));</span><br><span>@@ -2054,7 +2068,7 @@</span><br><span>          /* Ensure that the address provided is valid */</span><br><span>              if (ast_sockaddr_resolve(&addrs, host, PARSE_PORT_FORBID, AST_AF_UNSPEC) <= 0) {</span><br><span>                      /* The provided host was actually invalid so we error out this negotiation */</span><br><span style="color: hsl(0, 100%, 40%);">-                   return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+                    SCOPE_EXIT_RTN_VALUE(-1, "Host invalid\n");</span><br><span>                }</span><br><span> </span><br><span>                /* Apply connection information to the RTP instance */</span><br><span>@@ -2079,7 +2093,7 @@</span><br><span>       }</span><br><span> </span><br><span>        if (set_caps(session, session_media, session_media_transport, remote_stream, 0, asterisk_stream)) {</span><br><span style="color: hsl(0, 100%, 40%);">-             return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+            SCOPE_EXIT_RTN_VALUE(-1, "set_caps failed\n");</span><br><span>     }</span><br><span> </span><br><span>        /* Set the channel uniqueid on the RTP instance now that it is becoming active */</span><br><span>@@ -2097,7 +2111,7 @@</span><br><span>                    && (session->inv_session->state == PJSIP_INV_STATE_CONFIRMED)) {</span><br><span>                       ast_queue_control(session->channel, AST_CONTROL_UPDATE_RTP_PEER);</span><br><span>                 }</span><br><span style="color: hsl(0, 100%, 40%);">-               return 1;</span><br><span style="color: hsl(120, 100%, 40%);">+             SCOPE_EXIT_RTN_VALUE(1, "moh\n");</span><br><span>  }</span><br><span> </span><br><span>        if (session_media->remotely_held_changed) {</span><br><span>@@ -2155,7 +2169,7 @@</span><br><span>                       session_media, 1);</span><br><span>   }</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-   return 1;</span><br><span style="color: hsl(120, 100%, 40%);">+     SCOPE_EXIT_RTN_VALUE(1, "Handled\n");</span><br><span> }</span><br><span> </span><br><span> /*! \brief Function which updates the media stream with external media address, if applicable */</span><br><span>diff --git a/res/res_pjsip_session.c b/res/res_pjsip_session.c</span><br><span>index 450c401..0cf0c8a 100644</span><br><span>--- a/res/res_pjsip_session.c</span><br><span>+++ b/res/res_pjsip_session.c</span><br><span>@@ -111,6 +111,20 @@</span><br><span>         return ast_str_hash(stream_type);</span><br><span> }</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+const char *ast_sip_session_get_name(const struct ast_sip_session *session)</span><br><span style="color: hsl(120, 100%, 40%);">+{</span><br><span style="color: hsl(120, 100%, 40%);">+    if (!session) {</span><br><span style="color: hsl(120, 100%, 40%);">+               return "(null session)";</span><br><span style="color: hsl(120, 100%, 40%);">+    }</span><br><span style="color: hsl(120, 100%, 40%);">+     if (session->channel) {</span><br><span style="color: hsl(120, 100%, 40%);">+            return ast_channel_name(session->channel);</span><br><span style="color: hsl(120, 100%, 40%);">+ } else if (session->endpoint) {</span><br><span style="color: hsl(120, 100%, 40%);">+            return ast_sorcery_object_get_id(session->endpoint);</span><br><span style="color: hsl(120, 100%, 40%);">+       } else {</span><br><span style="color: hsl(120, 100%, 40%);">+              return "unknown";</span><br><span style="color: hsl(120, 100%, 40%);">+   }</span><br><span style="color: hsl(120, 100%, 40%);">+}</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> static int sdp_handler_list_cmp(void *obj, void *arg, int flags)</span><br><span> {</span><br><span>      struct sdp_handler_list *handler_list1 = obj;</span><br><span>@@ -713,17 +727,18 @@</span><br><span>        int i;</span><br><span>       int handled = 0;</span><br><span>     int type_streams[AST_MEDIA_TYPE_END] = {0};</span><br><span style="color: hsl(120, 100%, 40%);">+   SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(session));</span><br><span> </span><br><span>     if (session->inv_session && session->inv_session->state == PJSIP_INV_STATE_DISCONNECTED) {</span><br><span>          ast_log(LOG_ERROR, "Failed to handle incoming SDP. Session has been already disconnected\n");</span><br><span style="color: hsl(0, 100%, 40%);">-         return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+            SCOPE_EXIT_RTN_VALUE(-1, "Already disconnected\n");</span><br><span>        }</span><br><span> </span><br><span>        /* It is possible for SDP deferral to have already created a pending topology */</span><br><span>     if (!session->pending_media_state->topology) {</span><br><span>                 session->pending_media_state->topology = ast_stream_topology_alloc();</span><br><span>          if (!session->pending_media_state->topology) {</span><br><span style="color: hsl(0, 100%, 40%);">-                    return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+                    SCOPE_EXIT_RTN_VALUE(-1, "No topology\n");</span><br><span>                 }</span><br><span>    }</span><br><span> </span><br><span>@@ -756,11 +771,11 @@</span><br><span> </span><br><span>                    stream = ast_stream_alloc(existing_stream ? ast_stream_get_name(existing_stream) : ast_codec_media_type2str(type), type);</span><br><span>                    if (!stream) {</span><br><span style="color: hsl(0, 100%, 40%);">-                          return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+                            SCOPE_EXIT_RTN_VALUE(-1, "Couldn't create stream\n");</span><br><span>                  }</span><br><span>                    if (ast_stream_topology_set_stream(session->pending_media_state->topology, i, stream)) {</span><br><span>                               ast_stream_free(stream);</span><br><span style="color: hsl(0, 100%, 40%);">-                                return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+                            SCOPE_EXIT_RTN_VALUE(-1, "Couldn't set stream\n");</span><br><span>                     }</span><br><span>                    if (existing_stream) {</span><br><span>                               const char *stream_label = ast_stream_get_metadata(existing_stream, "SDP:LABEL");</span><br><span>@@ -792,7 +807,7 @@</span><br><span> </span><br><span>                session_media = ast_sip_session_media_state_add(session, session->pending_media_state, ast_media_type_from_str(media), i);</span><br><span>                if (!session_media) {</span><br><span style="color: hsl(0, 100%, 40%);">-                   return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+                    SCOPE_EXIT_RTN_VALUE(-1, "Couldn't add session media\n");</span><br><span>              }</span><br><span> </span><br><span>                /* If this stream is already declined mark it as such, or mark it as such if we've reached the limit */</span><br><span>@@ -814,7 +829,7 @@</span><br><span>                    res = handler->negotiate_incoming_sdp_stream(session, session_media, sdp, i, stream);</span><br><span>                     if (res < 0) {</span><br><span>                            /* Catastrophic failure. Abort! */</span><br><span style="color: hsl(0, 100%, 40%);">-                              return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+                            SCOPE_EXIT_RTN_VALUE(-1, "Couldn't negotiate incoming sdp stream\n");</span><br><span>                  } else if (res == 0) {</span><br><span>                               ast_debug(1, "Declining incoming SDP media stream '%s' at position '%d'\n",</span><br><span>                                        ast_codec_media_type2str(type), i);</span><br><span>@@ -865,9 +880,12 @@</span><br><span>           }</span><br><span>    }</span><br><span>    if (!handled) {</span><br><span style="color: hsl(0, 100%, 40%);">-         return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+            SCOPE_EXIT_RTN_VALUE(-1, "Not handled\n");</span><br><span>         }</span><br><span style="color: hsl(0, 100%, 40%);">-       return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+     SCOPE_EXIT_RTN_VALUE(0, "Handled.  Active: %s  Pending: %s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+              ast_str_tmp(256, ast_stream_topology_to_str(session->active_media_state->topology, &STR_TMP)),</span><br><span style="color: hsl(120, 100%, 40%);">+              ast_str_tmp(256, ast_stream_topology_to_str(session->pending_media_state->topology, &STR_TMP))</span><br><span style="color: hsl(120, 100%, 40%);">+              );</span><br><span> }</span><br><span> </span><br><span> static int handle_negotiated_sdp_session_media(struct ast_sip_session_media *session_media,</span><br><span>@@ -880,6 +898,7 @@</span><br><span>     struct ast_sip_session_sdp_handler *handler;</span><br><span>         RAII_VAR(struct sdp_handler_list *, handler_list, NULL, ao2_cleanup);</span><br><span>        int res;</span><br><span style="color: hsl(120, 100%, 40%);">+      SCOPE_ENTER(1, "%s\n", session ? ast_sip_session_get_name(session) : "unknown");</span><br><span> </span><br><span>     /* We need a null-terminated version of the media string */</span><br><span>  ast_copy_pj_str(media, &local->media[index]->desc.media, sizeof(media));</span><br><span>@@ -918,15 +937,20 @@</span><br><span>                   ast_debug(1, "Applied negotiated SDP media stream '%s' using %s SDP handler\n",</span><br><span>                            ast_codec_media_type2str(session_media->type),</span><br><span>                            handler->id);</span><br><span style="color: hsl(0, 100%, 40%);">-                        return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+                     SCOPE_EXIT_RTN_VALUE(0,  "%s: Applied negotiated SDP media stream '%s' using %s SDP handler\n",</span><br><span style="color: hsl(120, 100%, 40%);">+                             ast_sip_session_get_name(session), ast_codec_media_type2str(session_media->type),</span><br><span style="color: hsl(120, 100%, 40%);">+                          handler->id);</span><br><span>             }</span><br><span style="color: hsl(0, 100%, 40%);">-               return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+            SCOPE_EXIT_RTN_VALUE(-1,  "%s: Failed to apply negotiated SDP media stream '%s' using %s SDP handler\n",</span><br><span style="color: hsl(120, 100%, 40%);">+                    ast_sip_session_get_name(session), ast_codec_media_type2str(session_media->type),</span><br><span style="color: hsl(120, 100%, 40%);">+                  handler->id);</span><br><span>     }</span><br><span> </span><br><span>        handler_list = ao2_find(sdp_handlers, media, OBJ_KEY);</span><br><span>       if (!handler_list) {</span><br><span>                 ast_debug(1, "No registered SDP handlers for media type '%s'\n", media);</span><br><span style="color: hsl(0, 100%, 40%);">-              return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+            SCOPE_EXIT_RTN_VALUE(-1, "%s: No registered SDP handlers for media type '%s'\n",</span><br><span style="color: hsl(120, 100%, 40%);">+                    ast_sip_session_get_name(session), media);</span><br><span>   }</span><br><span>    AST_LIST_TRAVERSE(&handler_list->list, handler, next) {</span><br><span>               if (handler == session_media->handler) {</span><br><span>@@ -938,7 +962,8 @@</span><br><span>            res = handler->apply_negotiated_sdp_stream(session, session_media, local, remote, index, asterisk_stream);</span><br><span>                if (res < 0) {</span><br><span>                    /* Catastrophic failure. Abort! */</span><br><span style="color: hsl(0, 100%, 40%);">-                      return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+                    SCOPE_EXIT_RTN_VALUE(-1, "%s: Handler '%s' returned %d\n",</span><br><span style="color: hsl(120, 100%, 40%);">+                          ast_sip_session_get_name(session), handler->id, res);</span><br><span>             }</span><br><span>            if (res > 0) {</span><br><span>                    ast_debug(1, "Applied negotiated SDP media stream '%s' using %s SDP handler\n",</span><br><span>@@ -946,17 +971,22 @@</span><br><span>                            handler->id);</span><br><span>                     /* Handled by this handler. Move to the next stream */</span><br><span>                       session_media_set_handler(session_media, handler);</span><br><span style="color: hsl(0, 100%, 40%);">-                      return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+                     SCOPE_EXIT_RTN_VALUE(0, "%s: Handler '%s' handled this sdp stream\n",</span><br><span style="color: hsl(120, 100%, 40%);">+                               ast_sip_session_get_name(session), handler->id);</span><br><span>          }</span><br><span>    }</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+ res = 0;</span><br><span>     if (session_media->handler && session_media->handler->stream_stop) {</span><br><span style="color: hsl(120, 100%, 40%);">+         res = 1;</span><br><span>             ast_debug(1, "Stopping SDP media stream '%s' as it is not currently negotiated\n",</span><br><span>                         ast_codec_media_type2str(session_media->type));</span><br><span>           session_media->handler->stream_stop(session_media);</span><br><span>    }</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-   return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+     SCOPE_EXIT_RTN_VALUE(0, "%s: Media type '%s' %s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+         ast_sip_session_get_name(session), ast_codec_media_type2str(session_media->type),</span><br><span style="color: hsl(120, 100%, 40%);">+          res ? "not negotiated.  Stopped" : "handled");</span><br><span> }</span><br><span> </span><br><span> static int handle_negotiated_sdp(struct ast_sip_session *session, const pjmedia_sdp_session *local, const pjmedia_sdp_session *remote)</span><br><span>@@ -964,6 +994,7 @@</span><br><span>  int i;</span><br><span>       struct ast_stream_topology *topology;</span><br><span>        unsigned int changed = 0; /* 0 = unchanged, 1 = new source, 2 = new topology */</span><br><span style="color: hsl(120, 100%, 40%);">+       SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(session));</span><br><span> </span><br><span>     if (!session->pending_media_state->topology) {</span><br><span>                 if (session->active_media_state->topology) {</span><br><span>@@ -979,7 +1010,7 @@</span><br><span>                    if (!active_media_state_clone) {</span><br><span>                             ast_log(LOG_WARNING, "Unable to clone active media state for channel '%s'\n",</span><br><span>                                      session->channel ? ast_channel_name(session->channel) : "unknown");</span><br><span style="color: hsl(0, 100%, 40%);">-                             return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+                            SCOPE_EXIT_RTN_VALUE(-1, "Unable to clone active media state\n");</span><br><span>                  }</span><br><span> </span><br><span>                        ast_sip_session_media_state_free(session->pending_media_state);</span><br><span>@@ -987,7 +1018,7 @@</span><br><span>            } else {</span><br><span>                     ast_log(LOG_WARNING, "No pending or active media state for channel '%s'\n",</span><br><span>                                session->channel ? ast_channel_name(session->channel) : "unknown");</span><br><span style="color: hsl(0, 100%, 40%);">-                     return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+                    SCOPE_EXIT_RTN_VALUE(-1, "No media state\n");</span><br><span>              }</span><br><span>    }</span><br><span> </span><br><span>@@ -1001,7 +1032,7 @@</span><br><span>                ast_log(LOG_WARNING, "Local SDP for channel '%s' contains %d media streams while we expected it to contain %u\n",</span><br><span>                  session->channel ? ast_channel_name(session->channel) : "unknown",</span><br><span>                   ast_stream_topology_get_count(session->pending_media_state->topology), local->media_count);</span><br><span style="color: hsl(0, 100%, 40%);">-            return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+            SCOPE_EXIT_RTN_VALUE(-1, "Media stream count mismatch\n");</span><br><span>         }</span><br><span> </span><br><span>        for (i = 0; i < local->media_count; ++i) {</span><br><span>@@ -1038,7 +1069,7 @@</span><br><span>             }</span><br><span> </span><br><span>                if (handle_negotiated_sdp_session_media(session_media, session, local, remote, i, stream)) {</span><br><span style="color: hsl(0, 100%, 40%);">-                    return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+                    SCOPE_EXIT_RTN_VALUE(-1, "Unable to handle negotiated session media\n");</span><br><span>           }</span><br><span> </span><br><span>                changed |= session_media->changed;</span><br><span>@@ -1118,7 +1149,7 @@</span><br><span>                ast_queue_frame(session->channel, &ast_null_frame);</span><br><span>   }</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-   return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+     SCOPE_EXIT_RTN_VALUE(0);</span><br><span> }</span><br><span> </span><br><span> #define DATASTORE_BUCKETS 53</span><br><span>@@ -1499,6 +1530,7 @@</span><br><span> {</span><br><span>       pjsip_inv_session *inv_session = session->inv_session;</span><br><span>    const pjmedia_sdp_session *previous_sdp = NULL;</span><br><span style="color: hsl(120, 100%, 40%);">+       SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(session));</span><br><span> </span><br><span>     if (inv_session->neg) {</span><br><span>           if (pjmedia_sdp_neg_was_answer_remote(inv_session->neg)) {</span><br><span>@@ -1507,7 +1539,7 @@</span><br><span>                        pjmedia_sdp_neg_get_active_local(inv_session->neg, &previous_sdp);</span><br><span>            }</span><br><span>    }</span><br><span style="color: hsl(0, 100%, 40%);">-       return create_local_sdp(inv_session, session, previous_sdp);</span><br><span style="color: hsl(120, 100%, 40%);">+  SCOPE_EXIT_RTN_VALUE(create_local_sdp(inv_session, session, previous_sdp));</span><br><span> }</span><br><span> </span><br><span> static void set_from_header(struct ast_sip_session *session)</span><br><span>@@ -1878,13 +1910,14 @@</span><br><span>       pjsip_inv_session *inv_session = session->inv_session;</span><br><span>    pjmedia_sdp_session *new_answer = NULL;</span><br><span>      const pjmedia_sdp_session *previous_offer = NULL;</span><br><span style="color: hsl(120, 100%, 40%);">+     SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(session));</span><br><span> </span><br><span>     /* The SDP answer can only be regenerated if it is still pending to be sent */</span><br><span>       if (!inv_session->neg || (pjmedia_sdp_neg_get_state(inv_session->neg) != PJMEDIA_SDP_NEG_STATE_REMOTE_OFFER &&</span><br><span>                 pjmedia_sdp_neg_get_state(inv_session->neg) != PJMEDIA_SDP_NEG_STATE_WAIT_NEGO)) {</span><br><span>                ast_log(LOG_WARNING, "Requested to regenerate local SDP answer for channel '%s' but negotiation in state '%s'\n",</span><br><span>                  ast_channel_name(session->channel), pjmedia_sdp_neg_state_str(pjmedia_sdp_neg_get_state(inv_session->neg)));</span><br><span style="color: hsl(0, 100%, 40%);">-              return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+            SCOPE_EXIT_RTN_VALUE(-1, "Bad negotiation state\n");</span><br><span>       }</span><br><span> </span><br><span>        pjmedia_sdp_neg_get_neg_remote(inv_session->neg, &previous_offer);</span><br><span>@@ -1898,18 +1931,18 @@</span><br><span>  if (!new_answer) {</span><br><span>           ast_log(LOG_WARNING, "Could not create a new local SDP answer for channel '%s'\n",</span><br><span>                         ast_channel_name(session->channel));</span><br><span style="color: hsl(0, 100%, 40%);">-         return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+            SCOPE_EXIT_RTN_VALUE(-1, "Couldn't create new SDP\n");</span><br><span>         }</span><br><span> </span><br><span>        if (on_sdp_creation) {</span><br><span>               if (on_sdp_creation(session, new_answer)) {</span><br><span style="color: hsl(0, 100%, 40%);">-                     return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+                    SCOPE_EXIT_RTN_VALUE(-1, "Callback failed\n");</span><br><span>             }</span><br><span>    }</span><br><span> </span><br><span>        pjsip_inv_set_sdp_answer(inv_session, new_answer);</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-  return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+     SCOPE_EXIT_RTN_VALUE(0);</span><br><span> }</span><br><span> </span><br><span> void ast_sip_session_send_response(struct ast_sip_session *session, pjsip_tx_data *tdata)</span><br><span>@@ -1920,11 +1953,15 @@</span><br><span> }</span><br><span> </span><br><span> static pj_bool_t session_on_rx_request(pjsip_rx_data *rdata);</span><br><span style="color: hsl(120, 100%, 40%);">+static pj_bool_t session_on_rx_response(pjsip_rx_data *rdata);</span><br><span style="color: hsl(120, 100%, 40%);">+static void session_on_tsx_state(pjsip_transaction *tsx, pjsip_event *e);</span><br><span> </span><br><span> static pjsip_module session_module = {</span><br><span>  .name = {"Session Module", 14},</span><br><span>    .priority = PJSIP_MOD_PRIORITY_APPLICATION,</span><br><span>  .on_rx_request = session_on_rx_request,</span><br><span style="color: hsl(120, 100%, 40%);">+       .on_rx_response = session_on_rx_response,</span><br><span style="color: hsl(120, 100%, 40%);">+     .on_tsx_state = session_on_tsx_state,</span><br><span> };</span><br><span> </span><br><span> /*! \brief Determine whether the SDP provided requires deferral of negotiating or not</span><br><span>@@ -2226,10 +2263,11 @@</span><br><span> int ast_sip_session_create_invite(struct ast_sip_session *session, pjsip_tx_data **tdata)</span><br><span> {</span><br><span>         pjmedia_sdp_session *offer;</span><br><span style="color: hsl(120, 100%, 40%);">+   SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(session));</span><br><span> </span><br><span>     if (!(offer = create_local_sdp(session->inv_session, session, NULL))) {</span><br><span>           pjsip_inv_terminate(session->inv_session, 500, PJ_FALSE);</span><br><span style="color: hsl(0, 100%, 40%);">-            return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+            SCOPE_EXIT_RTN_VALUE(-1, "Couldn't create offer\n");</span><br><span>   }</span><br><span> </span><br><span>        pjsip_inv_set_local_sdp(session->inv_session, offer);</span><br><span>@@ -2247,10 +2285,10 @@</span><br><span>   set_from_header(session);</span><br><span> </span><br><span>        if (pjsip_inv_invite(session->inv_session, tdata) != PJ_SUCCESS) {</span><br><span style="color: hsl(0, 100%, 40%);">-           return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+            SCOPE_EXIT_RTN_VALUE(-1, "pjsip_inv_invite failed\n");</span><br><span>     }</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-   return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+     SCOPE_EXIT_RTN_VALUE(0);</span><br><span> }</span><br><span> </span><br><span> static int datastore_hash(const void *obj, int flags)</span><br><span>@@ -2668,6 +2706,8 @@</span><br><span>   struct pjsip_inv_session *inv_session;</span><br><span>       RAII_VAR(struct ast_sip_session *, session, NULL, ao2_cleanup);</span><br><span>      struct ast_sip_session *ret_session;</span><br><span style="color: hsl(120, 100%, 40%);">+  SCOPE_ENTER(1, "%s %s Topology: %s\n", ast_sorcery_object_get_id(endpoint), request_user,</span><br><span style="color: hsl(120, 100%, 40%);">+           ast_str_tmp(256, ast_stream_topology_to_str(req_topology, &STR_TMP)));</span><br><span> </span><br><span>       /* If no location has been provided use the AOR list from the endpoint itself */</span><br><span>     if (location || !contact) {</span><br><span>@@ -2688,21 +2728,21 @@</span><br><span>        if (ast_strlen_zero(uri)) {</span><br><span>          ast_log(LOG_ERROR, "Endpoint '%s': No URI available.  Is endpoint registered?\n",</span><br><span>                  ast_sorcery_object_get_id(endpoint));</span><br><span style="color: hsl(0, 100%, 40%);">-           return NULL;</span><br><span style="color: hsl(120, 100%, 40%);">+          SCOPE_EXIT_RTN_VALUE(NULL, "No URI\n");</span><br><span>    }</span><br><span> </span><br><span>        if (!(dlg = ast_sip_create_dialog_uac(endpoint, uri, request_user))) {</span><br><span style="color: hsl(0, 100%, 40%);">-          return NULL;</span><br><span style="color: hsl(120, 100%, 40%);">+          SCOPE_EXIT_RTN_VALUE(NULL, "Couldn't create dialog\n");</span><br><span>        }</span><br><span> </span><br><span>        if (setup_outbound_invite_auth(dlg)) {</span><br><span>               pjsip_dlg_terminate(dlg);</span><br><span style="color: hsl(0, 100%, 40%);">-               return NULL;</span><br><span style="color: hsl(120, 100%, 40%);">+          SCOPE_EXIT_RTN_VALUE(NULL, "Couldn't setup auth\n");</span><br><span>   }</span><br><span> </span><br><span>        if (pjsip_inv_create_uac(dlg, NULL, endpoint->extensions.flags, &inv_session) != PJ_SUCCESS) {</span><br><span>                pjsip_dlg_terminate(dlg);</span><br><span style="color: hsl(0, 100%, 40%);">-               return NULL;</span><br><span style="color: hsl(120, 100%, 40%);">+          SCOPE_EXIT_RTN_VALUE(NULL, "Couldn't create uac\n");</span><br><span>   }</span><br><span> #if defined(HAVE_PJSIP_REPLACE_MEDIA_STREAM) || defined(PJMEDIA_SDP_NEG_ALLOW_MEDIA_CHANGE)</span><br><span>     inv_session->sdp_neg_flags = PJMEDIA_SDP_NEG_ALLOW_MEDIA_CHANGE;</span><br><span>@@ -2749,7 +2789,7 @@</span><br><span>                          if (!session->pending_media_state->topology) {</span><br><span>                                         pjsip_inv_terminate(inv_session, 500, PJ_FALSE);</span><br><span>                                     ao2_ref(session, -1);</span><br><span style="color: hsl(0, 100%, 40%);">-                                   return NULL;</span><br><span style="color: hsl(120, 100%, 40%);">+                                  SCOPE_EXIT_RTN_VALUE(NULL, "Couldn't create topology\n");</span><br><span>                              }</span><br><span>                    }</span><br><span> </span><br><span>@@ -2766,7 +2806,7 @@</span><br><span>                if (!session->pending_media_state->topology) {</span><br><span>                         pjsip_inv_terminate(inv_session, 500, PJ_FALSE);</span><br><span>                     ao2_ref(session, -1);</span><br><span style="color: hsl(0, 100%, 40%);">-                   return NULL;</span><br><span style="color: hsl(120, 100%, 40%);">+                  SCOPE_EXIT_RTN_VALUE(NULL, "Couldn't clone topology\n");</span><br><span>               }</span><br><span>    }</span><br><span> </span><br><span>@@ -2776,13 +2816,13 @@</span><br><span>               * we need to manually drop its reference to session</span><br><span>                  */</span><br><span>          ao2_ref(session, -1);</span><br><span style="color: hsl(0, 100%, 40%);">-           return NULL;</span><br><span style="color: hsl(120, 100%, 40%);">+          SCOPE_EXIT_RTN_VALUE(NULL, "Couldn't add usage\n");</span><br><span>    }</span><br><span> </span><br><span>        /* Avoid unnecessary ref manipulation to return a session */</span><br><span>         ret_session = session;</span><br><span>       session = NULL;</span><br><span style="color: hsl(0, 100%, 40%);">- return ret_session;</span><br><span style="color: hsl(120, 100%, 40%);">+   SCOPE_EXIT_RTN_VALUE(ret_session);</span><br><span> }</span><br><span> </span><br><span> static int session_end(void *vsession);</span><br><span>@@ -2792,10 +2832,11 @@</span><br><span> {</span><br><span>        pj_status_t status;</span><br><span>  pjsip_tx_data *packet = NULL;</span><br><span style="color: hsl(120, 100%, 40%);">+ SCOPE_ENTER(1, "%s Response %d\n", ast_sip_session_get_name(session), response);</span><br><span> </span><br><span>       if (session->defer_terminate) {</span><br><span>           session->terminate_while_deferred = 1;</span><br><span style="color: hsl(0, 100%, 40%);">-               return;</span><br><span style="color: hsl(120, 100%, 40%);">+               SCOPE_EXIT_RTN("Deferred\n");</span><br><span>      }</span><br><span> </span><br><span>        if (!response) {</span><br><span>@@ -2863,6 +2904,7 @@</span><br><span>             }</span><br><span>            break;</span><br><span>       }</span><br><span style="color: hsl(120, 100%, 40%);">+     SCOPE_EXIT_RTN();</span><br><span> }</span><br><span> </span><br><span> static int session_termination_task(void *data)</span><br><span>@@ -3175,6 +3217,7 @@</span><br><span>        pjsip_rdata_sdp_info *sdp_info;</span><br><span>      pjmedia_sdp_session *local = NULL;</span><br><span>   char buffer[AST_SOCKADDR_BUFLEN];</span><br><span style="color: hsl(120, 100%, 40%);">+     SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(invite->session));</span><br><span> </span><br><span>  /* From this point on, any calls to pjsip_inv_terminate have the last argument as PJ_TRUE</span><br><span>     * so that we will be notified so we can destroy the session properly</span><br><span>@@ -3187,7 +3230,7 @@</span><br><span> #ifdef HAVE_PJSIP_INV_SESSION_REF</span><br><span>           pjsip_inv_dec_ref(invite->session->inv_session);</span><br><span> #endif</span><br><span style="color: hsl(0, 100%, 40%);">-                return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+            SCOPE_EXIT_RTN_VALUE(-1, "Already disconnected\n");</span><br><span>        }</span><br><span> </span><br><span>        switch (get_destination(invite->session, invite->rdata)) {</span><br><span>@@ -3297,7 +3340,10 @@</span><br><span> #ifdef HAVE_PJSIP_INV_SESSION_REF</span><br><span>       pjsip_inv_dec_ref(invite->session->inv_session);</span><br><span> #endif</span><br><span style="color: hsl(0, 100%, 40%);">-        return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+     SCOPE_EXIT_RTN_VALUE(0, "Handled.  Active: %s  Pending: %s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+              ast_str_tmp(256, ast_stream_topology_to_str(invite->session->active_media_state->topology, &STR_TMP)),</span><br><span style="color: hsl(120, 100%, 40%);">+           ast_str_tmp(256, ast_stream_topology_to_str(invite->session->pending_media_state->topology, &STR_TMP))</span><br><span style="color: hsl(120, 100%, 40%);">+           );</span><br><span> }</span><br><span> </span><br><span> static void handle_new_invite_request(pjsip_rx_data *rdata)</span><br><span>@@ -3308,13 +3354,16 @@</span><br><span>         pjsip_inv_session *inv_session = NULL;</span><br><span>       struct ast_sip_session *session;</span><br><span>     struct new_invite invite;</span><br><span style="color: hsl(120, 100%, 40%);">+     char *req_uri = TRACE_ATLEAST(1) ? ast_alloca(256) : "";</span><br><span style="color: hsl(120, 100%, 40%);">+    int res = TRACE_ATLEAST(1) ? pjsip_uri_print(PJSIP_URI_IN_REQ_URI, rdata->msg_info.msg->line.req.uri, req_uri, 256) : 0;</span><br><span style="color: hsl(120, 100%, 40%);">+        SCOPE_ENTER(1, "Request: %s\n", res ? req_uri : "");</span><br><span> </span><br><span>         ast_assert(endpoint != NULL);</span><br><span> </span><br><span>    inv_session = pre_session_setup(rdata, endpoint);</span><br><span>    if (!inv_session) {</span><br><span>          /* pre_session_setup() returns a response on failure */</span><br><span style="color: hsl(0, 100%, 40%);">-         return;</span><br><span style="color: hsl(120, 100%, 40%);">+               SCOPE_EXIT_RTN("Failure in pre session setup\n");</span><br><span>  }</span><br><span> </span><br><span> #ifdef HAVE_PJSIP_INV_SESSION_REF</span><br><span>@@ -3327,7 +3376,7 @@</span><br><span>                           pjsip_inv_send_msg(inv_session, tdata);</span><br><span>                      }</span><br><span>            }</span><br><span style="color: hsl(0, 100%, 40%);">-               return;</span><br><span style="color: hsl(120, 100%, 40%);">+               SCOPE_EXIT_RTN("Couldn't add invite session reference\n");</span><br><span>     }</span><br><span> #endif</span><br><span> </span><br><span>@@ -3341,7 +3390,7 @@</span><br><span> #ifdef HAVE_PJSIP_INV_SESSION_REF</span><br><span>                 pjsip_inv_dec_ref(inv_session);</span><br><span> #endif</span><br><span style="color: hsl(0, 100%, 40%);">-               return;</span><br><span style="color: hsl(120, 100%, 40%);">+               SCOPE_EXIT_RTN("Couldn't create session\n");</span><br><span>   }</span><br><span>    session->call_direction = AST_SIP_SESSION_INCOMING_CALL;</span><br><span> </span><br><span>@@ -3356,6 +3405,7 @@</span><br><span>      invite.rdata = rdata;</span><br><span>        new_invite(&invite);</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+  SCOPE_EXIT("Request: %s Session: %s\n", req_uri, ast_sip_session_get_name(session));</span><br><span>       ao2_ref(session, -1);</span><br><span> }</span><br><span> </span><br><span>@@ -3388,6 +3438,46 @@</span><br><span>      }</span><br><span>    return PJ_FALSE;</span><br><span> }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+/*!</span><br><span style="color: hsl(120, 100%, 40%);">+ * \internal</span><br><span style="color: hsl(120, 100%, 40%);">+ * Added for debugging purposes</span><br><span style="color: hsl(120, 100%, 40%);">+ */</span><br><span style="color: hsl(120, 100%, 40%);">+static void session_on_tsx_state(pjsip_transaction *tsx, pjsip_event *e)</span><br><span style="color: hsl(120, 100%, 40%);">+{</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+       pjsip_dialog *dlg = pjsip_tsx_get_dlg(tsx);</span><br><span style="color: hsl(120, 100%, 40%);">+   pjsip_inv_session *inv_session = (dlg ? pjsip_dlg_get_inv_session(dlg) : NULL);</span><br><span style="color: hsl(120, 100%, 40%);">+       struct ast_sip_session *session = (inv_session ? inv_session->mod_data[session_module.id] : NULL);</span><br><span style="color: hsl(120, 100%, 40%);">+ SCOPE_ENTER(1, "%s TSX State: %s  Inv State: %s\n", ast_sip_session_get_name(session),</span><br><span style="color: hsl(120, 100%, 40%);">+                      pjsip_tsx_state_str(tsx->state), inv_session ? pjsip_inv_state_name(inv_session->state) : "unknown");</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+       if (session) {</span><br><span style="color: hsl(120, 100%, 40%);">+                ast_trace(2, "Topology: Pending: %s  Active: %s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+                 ast_str_tmp(256, ast_stream_topology_to_str(session->pending_media_state->topology, &STR_TMP)),</span><br><span style="color: hsl(120, 100%, 40%);">+                     ast_str_tmp(256, ast_stream_topology_to_str(session->active_media_state->topology, &STR_TMP)));</span><br><span style="color: hsl(120, 100%, 40%);">+     }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+   SCOPE_EXIT_RTN();</span><br><span style="color: hsl(120, 100%, 40%);">+}</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+/*!</span><br><span style="color: hsl(120, 100%, 40%);">+ * \internal</span><br><span style="color: hsl(120, 100%, 40%);">+ * Added for debugging purposes</span><br><span style="color: hsl(120, 100%, 40%);">+ */</span><br><span style="color: hsl(120, 100%, 40%);">+static pj_bool_t session_on_rx_response(pjsip_rx_data *rdata)</span><br><span style="color: hsl(120, 100%, 40%);">+{</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+   struct pjsip_status_line status = rdata->msg_info.msg->line.status;</span><br><span style="color: hsl(120, 100%, 40%);">+     pjsip_dialog *dlg = pjsip_rdata_get_dlg(rdata);</span><br><span style="color: hsl(120, 100%, 40%);">+       pjsip_inv_session *inv_session = pjsip_dlg_get_inv_session(dlg);</span><br><span style="color: hsl(120, 100%, 40%);">+      struct ast_sip_session *session = (inv_session ? inv_session->mod_data[session_module.id] : NULL);</span><br><span style="color: hsl(120, 100%, 40%);">+ SCOPE_ENTER(1, "%s Method: %.*s Status: %d\n", ast_sip_session_get_name(session),</span><br><span style="color: hsl(120, 100%, 40%);">+           (int)rdata->msg_info.cseq->method.name.slen, rdata->msg_info.cseq->method.name.ptr, status.code);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+       SCOPE_EXIT_RTN_VALUE(PJ_FALSE);</span><br><span style="color: hsl(120, 100%, 40%);">+}</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> /*!</span><br><span>  * \brief Called when a new SIP request comes into PJSIP</span><br><span>  *</span><br><span>@@ -3408,10 +3498,16 @@</span><br><span> static pj_bool_t session_on_rx_request(pjsip_rx_data *rdata)</span><br><span> {</span><br><span>         pj_status_t handled = PJ_FALSE;</span><br><span style="color: hsl(120, 100%, 40%);">+       struct pjsip_request_line req = rdata->msg_info.msg->line.req;</span><br><span>         pjsip_dialog *dlg = pjsip_rdata_get_dlg(rdata);</span><br><span style="color: hsl(0, 100%, 40%);">- pjsip_inv_session *inv_session;</span><br><span style="color: hsl(120, 100%, 40%);">+       pjsip_inv_session *inv_session = (dlg ? pjsip_dlg_get_inv_session(dlg) : NULL);</span><br><span style="color: hsl(120, 100%, 40%);">+       struct ast_sip_session *session = (inv_session ? inv_session->mod_data[session_module.id] : NULL);</span><br><span style="color: hsl(120, 100%, 40%);">+ char *req_uri = TRACE_ATLEAST(1) ? ast_alloca(256) : "";</span><br><span style="color: hsl(120, 100%, 40%);">+    int res = TRACE_ATLEAST(1) ? pjsip_uri_print(PJSIP_URI_IN_REQ_URI, rdata->msg_info.msg->line.req.uri, req_uri, 256) : 0;</span><br><span style="color: hsl(120, 100%, 40%);">+        SCOPE_ENTER(1, "%s Request: %.*s %s\n", ast_sip_session_get_name(session),</span><br><span style="color: hsl(120, 100%, 40%);">+          (int) pj_strlen(&req.method.name), pj_strbuf(&req.method.name), res ? req_uri : "");</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-      switch (rdata->msg_info.msg->line.req.method.id) {</span><br><span style="color: hsl(120, 100%, 40%);">+      switch (req.method.id) {</span><br><span>     case PJSIP_INVITE_METHOD:</span><br><span>            if (dlg) {</span><br><span>                   ast_log(LOG_WARNING, "on_rx_request called for INVITE in mid-dialog?\n");</span><br><span>@@ -3427,7 +3523,9 @@</span><br><span>          break;</span><br><span>       }</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-   return handled;</span><br><span style="color: hsl(120, 100%, 40%);">+       SCOPE_EXIT_RTN_VALUE(handled, "%s Handled request %.*s %s ? %s\n", ast_sip_session_get_name(session),</span><br><span style="color: hsl(120, 100%, 40%);">+               (int) pj_strlen(&req.method.name), pj_strbuf(&req.method.name), req_uri,</span><br><span style="color: hsl(120, 100%, 40%);">+              handled == PJ_TRUE ? "yes" : "no");</span><br><span> }</span><br><span> </span><br><span> static void resend_reinvite(pj_timer_heap_t *timer, pj_timer_entry *entry)</span><br><span>@@ -3541,6 +3639,8 @@</span><br><span> {</span><br><span>  struct ast_sip_session_supplement *supplement;</span><br><span>       struct pjsip_request_line req = rdata->msg_info.msg->line.req;</span><br><span style="color: hsl(120, 100%, 40%);">+  SCOPE_ENTER(1, "%s Method: %.*s\n", ast_sip_session_get_name(session),</span><br><span style="color: hsl(120, 100%, 40%);">+              (int) pj_strlen(&req.method.name), pj_strbuf(&req.method.name));</span><br><span> </span><br><span>         ast_debug(3, "Method is %.*s\n", (int) pj_strlen(&req.method.name), pj_strbuf(&req.method.name));</span><br><span>  AST_LIST_TRAVERSE(&session->supplements, supplement, next) {</span><br><span>@@ -3550,6 +3650,8 @@</span><br><span>                  }</span><br><span>            }</span><br><span>    }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+   SCOPE_EXIT_RTN();</span><br><span> }</span><br><span> </span><br><span> static void handle_session_begin(struct ast_sip_session *session)</span><br><span>@@ -3591,6 +3693,10 @@</span><br><span> {</span><br><span>        struct ast_sip_session_supplement *supplement;</span><br><span>       struct pjsip_status_line status = rdata->msg_info.msg->line.status;</span><br><span style="color: hsl(120, 100%, 40%);">+     SCOPE_ENTER(1, "%s Method: %.*s Status: %d  Priority %s\n", ast_sip_session_get_name(session),</span><br><span style="color: hsl(120, 100%, 40%);">+              (int)rdata->msg_info.cseq->method.name.slen, rdata->msg_info.cseq->method.name.ptr,</span><br><span style="color: hsl(120, 100%, 40%);">+               rdata->msg_info.msg->line.status.code,</span><br><span style="color: hsl(120, 100%, 40%);">+          response_priority == AST_SIP_SESSION_AFTER_MEDIA ? "after" : "before");</span><br><span> </span><br><span>      ast_debug(3, "Response is %d %.*s\n", status.code, (int) pj_strlen(&status.reason),</span><br><span>                    pj_strbuf(&status.reason));</span><br><span>@@ -3603,11 +3709,14 @@</span><br><span>                    supplement->incoming_response(session, rdata);</span><br><span>            }</span><br><span>    }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+   SCOPE_EXIT_RTN();</span><br><span> }</span><br><span> </span><br><span> static int handle_incoming(struct ast_sip_session *session, pjsip_rx_data *rdata,</span><br><span>              enum ast_sip_session_response_priority response_priority)</span><br><span> {</span><br><span style="color: hsl(120, 100%, 40%);">+        SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(session));</span><br><span>         ast_debug(3, "Received %s\n", rdata->msg_info.msg->type == PJSIP_REQUEST_MSG ?</span><br><span>                       "request" : "response");</span><br><span> </span><br><span>@@ -3617,13 +3726,16 @@</span><br><span>           handle_incoming_response(session, rdata, response_priority);</span><br><span>         }</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-   return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+     SCOPE_EXIT_RTN_VALUE(0);</span><br><span> }</span><br><span> </span><br><span> static void handle_outgoing_request(struct ast_sip_session *session, pjsip_tx_data *tdata)</span><br><span> {</span><br><span>         struct ast_sip_session_supplement *supplement;</span><br><span>       struct pjsip_request_line req = tdata->msg->line.req;</span><br><span style="color: hsl(120, 100%, 40%);">+   SCOPE_ENTER(1, "%s Method: %.*s\n",  ast_sip_session_get_name(session),</span><br><span style="color: hsl(120, 100%, 40%);">+             (int) pj_strlen(&req.method.name),</span><br><span style="color: hsl(120, 100%, 40%);">+                pj_strbuf(&req.method.name));</span><br><span> </span><br><span>        ast_debug(3, "Method is %.*s\n", (int) pj_strlen(&req.method.name), pj_strbuf(&req.method.name));</span><br><span> </span><br><span>@@ -3634,6 +3746,8 @@</span><br><span>                      supplement->outgoing_request(session, tdata);</span><br><span>             }</span><br><span>    }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+   SCOPE_EXIT_RTN();</span><br><span> }</span><br><span> </span><br><span> static void handle_outgoing_response(struct ast_sip_session *session, pjsip_tx_data *tdata)</span><br><span>@@ -3641,10 +3755,14 @@</span><br><span>  struct ast_sip_session_supplement *supplement;</span><br><span>       struct pjsip_status_line status = tdata->msg->line.status;</span><br><span>     pjsip_cseq_hdr *cseq = pjsip_msg_find_hdr(tdata->msg, PJSIP_H_CSEQ, NULL);</span><br><span style="color: hsl(120, 100%, 40%);">+ SCOPE_ENTER(1, "%s Method is %.*s, Response is %d %.*s\n", ast_sip_session_get_name(session),</span><br><span style="color: hsl(120, 100%, 40%);">+               (int) pj_strlen(&cseq->method.name),</span><br><span style="color: hsl(120, 100%, 40%);">+           pj_strbuf(&cseq->method.name), status.code, (int) pj_strlen(&status.reason),</span><br><span style="color: hsl(120, 100%, 40%);">+               pj_strbuf(&status.reason));</span><br><span> </span><br><span>  if (!cseq) {</span><br><span>                 ast_log(LOG_ERROR, "Cannot send response due to missing sequence header");</span><br><span style="color: hsl(0, 100%, 40%);">-            return;</span><br><span style="color: hsl(120, 100%, 40%);">+               SCOPE_EXIT_RTN("Missing cseq\n");</span><br><span>  }</span><br><span> </span><br><span>        ast_debug(3, "Method is %.*s, Response is %d %.*s\n", (int) pj_strlen(&cseq->method.name),</span><br><span>@@ -3658,6 +3776,8 @@</span><br><span>                  supplement->outgoing_response(session, tdata);</span><br><span>            }</span><br><span>    }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+   SCOPE_EXIT_RTN();</span><br><span> }</span><br><span> </span><br><span> static int session_end(void *vsession)</span><br><span>@@ -3722,6 +3842,7 @@</span><br><span>         struct ast_sip_session *session, pjsip_rx_data *rdata)</span><br><span> {</span><br><span>  pjsip_msg *msg;</span><br><span style="color: hsl(120, 100%, 40%);">+       SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(session));</span><br><span> </span><br><span>     handle_incoming(session, rdata, AST_SIP_SESSION_BEFORE_MEDIA);</span><br><span>       msg = rdata->msg_info.msg;</span><br><span>@@ -3746,15 +3867,19 @@</span><br><span>                      ast_sip_session_send_request(session, tdata);</span><br><span>                }</span><br><span>    }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+   SCOPE_EXIT_RTN();</span><br><span> }</span><br><span> </span><br><span> static void session_inv_on_state_changed(pjsip_inv_session *inv, pjsip_event *e)</span><br><span> {</span><br><span style="color: hsl(0, 100%, 40%);">-     struct ast_sip_session *session;</span><br><span>     pjsip_event_id_e type;</span><br><span style="color: hsl(120, 100%, 40%);">+        struct ast_sip_session *session = inv->mod_data[session_module.id];</span><br><span style="color: hsl(120, 100%, 40%);">+        SCOPE_ENTER(1, "%s Event: %s  Inv State: %s\n", ast_sip_session_get_name(session),</span><br><span style="color: hsl(120, 100%, 40%);">+          pjsip_event_str(e->type), pjsip_inv_state_name(inv->state));</span><br><span> </span><br><span>       if (ast_shutdown_final()) {</span><br><span style="color: hsl(0, 100%, 40%);">-             return;</span><br><span style="color: hsl(120, 100%, 40%);">+               SCOPE_EXIT_RTN("Shutting down\n");</span><br><span>         }</span><br><span> </span><br><span>        if (e) {</span><br><span>@@ -3766,7 +3891,7 @@</span><br><span> </span><br><span>         session = inv->mod_data[session_module.id];</span><br><span>       if (!session) {</span><br><span style="color: hsl(0, 100%, 40%);">-         return;</span><br><span style="color: hsl(120, 100%, 40%);">+               SCOPE_EXIT_RTN("No session\n");</span><br><span>    }</span><br><span> </span><br><span>        switch(type) {</span><br><span>@@ -3814,7 +3939,7 @@</span><br><span>               if (session->defer_end) {</span><br><span>                         ast_debug(3, "Deferring session (%p) end\n", session);</span><br><span>                     session->ended_while_deferred = 1;</span><br><span style="color: hsl(0, 100%, 40%);">-                   return;</span><br><span style="color: hsl(120, 100%, 40%);">+                       SCOPE_EXIT_RTN("Deferring\n");</span><br><span>             }</span><br><span> </span><br><span>                if (ast_sip_push_task(session->serializer, session_end, session)) {</span><br><span>@@ -3822,6 +3947,8 @@</span><br><span>                       session_end(session);</span><br><span>                }</span><br><span>    }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+   SCOPE_EXIT_RTN();</span><br><span> }</span><br><span> </span><br><span> static void session_inv_on_new_session(pjsip_inv_session *inv, pjsip_event *e)</span><br><span>@@ -3863,11 +3990,13 @@</span><br><span> {</span><br><span>  ast_sip_session_response_cb cb;</span><br><span>      int id = session_module.id;</span><br><span style="color: hsl(0, 100%, 40%);">-     struct ast_sip_session *session;</span><br><span>     pjsip_tx_data *tdata;</span><br><span style="color: hsl(120, 100%, 40%);">+ struct ast_sip_session *session = inv->mod_data[session_module.id];</span><br><span style="color: hsl(120, 100%, 40%);">+        SCOPE_ENTER(1, "%s TSX State: %s  Inv State: %s\n", ast_sip_session_get_name(session),</span><br><span style="color: hsl(120, 100%, 40%);">+              pjsip_tsx_state_str(tsx->state), pjsip_inv_state_name(inv->state));</span><br><span> </span><br><span>        if (ast_shutdown_final()) {</span><br><span style="color: hsl(0, 100%, 40%);">-             return;</span><br><span style="color: hsl(120, 100%, 40%);">+               SCOPE_EXIT_RTN("Shutting down\n");</span><br><span>         }</span><br><span> </span><br><span>        session = inv->mod_data[id];</span><br><span>@@ -3875,7 +4004,7 @@</span><br><span>      print_debug_details(inv, tsx, e);</span><br><span>    if (!session) {</span><br><span>              /* The session has ended.  Ignore the transaction change. */</span><br><span style="color: hsl(0, 100%, 40%);">-            return;</span><br><span style="color: hsl(120, 100%, 40%);">+               SCOPE_EXIT_RTN("Session ended\n");</span><br><span>         }</span><br><span> </span><br><span>        /*</span><br><span>@@ -3885,7 +4014,7 @@</span><br><span>    * state but the BYE request transaction has not yet completed.</span><br><span>       */</span><br><span>  if (tsx->method.id != PJSIP_BYE_METHOD && session_end_if_disconnected(id, inv)) {</span><br><span style="color: hsl(0, 100%, 40%);">-            return;</span><br><span style="color: hsl(120, 100%, 40%);">+               SCOPE_EXIT_RTN("Disconnected\n");</span><br><span>  }</span><br><span> </span><br><span>        switch (e->body.tsx_state.type) {</span><br><span>@@ -3915,7 +4044,7 @@</span><br><span>                                         /* This means we got a non 2XX final response to our outgoing INVITE */</span><br><span>                                      if (tsx->status_code == PJSIP_SC_REQUEST_PENDING) {</span><br><span>                                               reschedule_reinvite(session, cb);</span><br><span style="color: hsl(0, 100%, 40%);">-                                               return;</span><br><span style="color: hsl(120, 100%, 40%);">+                                               SCOPE_EXIT_RTN("Non 2XX final response\n");</span><br><span>                                        }</span><br><span>                                    if (inv->state == PJSIP_INV_STATE_CONFIRMED) {</span><br><span>                                            ast_debug(1, "reINVITE received final response code %d\n",</span><br><span>@@ -3926,7 +4055,7 @@</span><br><span>                                                                 e->body.tsx_state.src.rdata, tsx->last_tx, &tdata)) {</span><br><span>                                                      /* Send authed reINVITE */</span><br><span>                                                   ast_sip_session_send_request_with_cb(session, tdata, cb);</span><br><span style="color: hsl(0, 100%, 40%);">-                                                       return;</span><br><span style="color: hsl(120, 100%, 40%);">+                                                       SCOPE_EXIT_RTN("Sending authed reinvite\n");</span><br><span>                                               }</span><br><span>                                            if (tsx->status_code != 488 && tsx->status_code != 500) {</span><br><span>                                                      /* Other reinvite failures (except 488 and 500) result in destroying the session. */</span><br><span>@@ -3956,7 +4085,7 @@</span><br><span>                                                         session->channel ? ast_channel_name(session->channel) : "",</span><br><span>                                                  pjsip_rx_data_get_info(e->body.tsx_state.src.rdata));</span><br><span>                                             pjsip_inv_end_session(session->inv_session, 503, NULL, &tdata);</span><br><span style="color: hsl(0, 100%, 40%);">-                                          return;</span><br><span style="color: hsl(120, 100%, 40%);">+                                               SCOPE_EXIT_RTN("Incomplete SDP negotiation\n");</span><br><span>                                    }</span><br><span> </span><br><span>                                        if (inv->cancelling && tsx->status_code == PJSIP_SC_OK) {</span><br><span>@@ -4017,7 +4146,8 @@</span><br><span>                                                      e->body.tsx_state.src.rdata, tsx->last_tx, &tdata)) {</span><br><span>                                              /* Send authed version of the method */</span><br><span>                                              ast_sip_session_send_request_with_cb(session, tdata, cb);</span><br><span style="color: hsl(0, 100%, 40%);">-                                               return;</span><br><span style="color: hsl(120, 100%, 40%);">+                                               SCOPE_EXIT_RTN("Sending authed %.*s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+                                                     (int) pj_strlen(&tsx->method.name), pj_strbuf(&tsx->method.name));</span><br><span>                                     }</span><br><span>                            }</span><br><span>                    }</span><br><span>@@ -4033,7 +4163,7 @@</span><br><span>             * by the session serializer.</span><br><span>                 */</span><br><span>          if (session_end_if_disconnected(id, inv)) {</span><br><span style="color: hsl(0, 100%, 40%);">-                     return;</span><br><span style="color: hsl(120, 100%, 40%);">+                       SCOPE_EXIT_RTN("Disconnected\n");</span><br><span>          }</span><br><span>            break;</span><br><span>       case PJSIP_EVENT_USER:</span><br><span>@@ -4045,7 +4175,7 @@</span><br><span> </span><br><span>   if (AST_LIST_EMPTY(&session->delayed_requests)) {</span><br><span>             /* No delayed request pending, so just return */</span><br><span style="color: hsl(0, 100%, 40%);">-                return;</span><br><span style="color: hsl(120, 100%, 40%);">+               SCOPE_EXIT_RTN("Nothing delayed\n");</span><br><span>       }</span><br><span> </span><br><span>        if (tsx->method.id == PJSIP_INVITE_METHOD) {</span><br><span>@@ -4076,6 +4206,8 @@</span><br><span>                      pjsip_tsx_state_str(tsx->state));</span><br><span>                 check_delayed_requests(session, update_completed);</span><br><span>   }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+   SCOPE_EXIT_RTN();</span><br><span> }</span><br><span> </span><br><span> static int add_sdp_streams(struct ast_sip_session_media *session_media,</span><br><span>@@ -4085,20 +4217,22 @@</span><br><span> {</span><br><span>         struct ast_sip_session_sdp_handler *handler = session_media->handler;</span><br><span>     RAII_VAR(struct sdp_handler_list *, handler_list, NULL, ao2_cleanup);</span><br><span style="color: hsl(0, 100%, 40%);">-   int res;</span><br><span style="color: hsl(120, 100%, 40%);">+      int res = 0;</span><br><span style="color: hsl(120, 100%, 40%);">+  SCOPE_ENTER(1, "%s Stream: %s\n", ast_sip_session_get_name(session),</span><br><span style="color: hsl(120, 100%, 40%);">+                ast_str_tmp(128, ast_stream_to_str(stream, &STR_TMP)));</span><br><span> </span><br><span>      if (handler) {</span><br><span>               /* if an already assigned handler reports a catastrophic error, fail */</span><br><span>              res = handler->create_outgoing_sdp_stream(session, session_media, answer, remote, stream);</span><br><span>                if (res < 0) {</span><br><span style="color: hsl(0, 100%, 40%);">-                       return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+                    SCOPE_EXIT_RTN_VALUE(-1, "Coudn't create sdp stream\n");</span><br><span>               }</span><br><span style="color: hsl(0, 100%, 40%);">-               return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+             SCOPE_EXIT_RTN_VALUE(0, "Had handler\n");</span><br><span>  }</span><br><span> </span><br><span>        handler_list = ao2_find(sdp_handlers, ast_codec_media_type2str(session_media->type), OBJ_KEY);</span><br><span>    if (!handler_list) {</span><br><span style="color: hsl(0, 100%, 40%);">-            return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+             SCOPE_EXIT_RTN_VALUE(0, "No handlers\n");</span><br><span>  }</span><br><span> </span><br><span>        /* no handler for this stream type and we have a list to search */</span><br><span>@@ -4109,17 +4243,17 @@</span><br><span>                 res = handler->create_outgoing_sdp_stream(session, session_media, answer, remote, stream);</span><br><span>                if (res < 0) {</span><br><span>                    /* catastrophic error */</span><br><span style="color: hsl(0, 100%, 40%);">-                        return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+                    SCOPE_EXIT_RTN_VALUE(-1, "Coudn't create sdp stream\n");</span><br><span>               }</span><br><span>            if (res > 0) {</span><br><span>                    /* Handled by this handler. Move to the next stream */</span><br><span>                       session_media_set_handler(session_media, handler);</span><br><span style="color: hsl(0, 100%, 40%);">-                      return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+                     SCOPE_EXIT_RTN_VALUE(0, "Handled\n");</span><br><span>              }</span><br><span>    }</span><br><span> </span><br><span>        /* streams that weren't handled won't be included in generated outbound SDP */</span><br><span style="color: hsl(0, 100%, 40%);">-  return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+     SCOPE_EXIT_RTN_VALUE(0, "Not handled\n");</span><br><span> }</span><br><span> </span><br><span> /*! \brief Bundle group building structure */</span><br><span>@@ -4208,14 +4342,16 @@</span><br><span>      pjmedia_sdp_session *local;</span><br><span>  int i;</span><br><span>       int stream;</span><br><span style="color: hsl(120, 100%, 40%);">+   SCOPE_ENTER(1, "%s Topology: %s\n", ast_sip_session_get_name(session),</span><br><span style="color: hsl(120, 100%, 40%);">+              ast_str_tmp(256, ast_stream_topology_to_str(session->pending_media_state->topology, &STR_TMP)));</span><br><span> </span><br><span>       if (inv->state == PJSIP_INV_STATE_DISCONNECTED) {</span><br><span>                 ast_log(LOG_ERROR, "Failed to create session SDP. Session has been already disconnected\n");</span><br><span style="color: hsl(0, 100%, 40%);">-          return NULL;</span><br><span style="color: hsl(120, 100%, 40%);">+          SCOPE_EXIT_RTN_VALUE(NULL, "Disconnected\n");</span><br><span>      }</span><br><span> </span><br><span>        if (!inv->pool_prov || !(local = PJ_POOL_ZALLOC_T(inv->pool_prov, pjmedia_sdp_session))) {</span><br><span style="color: hsl(0, 100%, 40%);">-                return NULL;</span><br><span style="color: hsl(120, 100%, 40%);">+          SCOPE_EXIT_RTN_VALUE(NULL, "Pool alloc failure\n");</span><br><span>        }</span><br><span> </span><br><span>        if (!offer) {</span><br><span>@@ -4240,7 +4376,7 @@</span><br><span>                        session->pending_media_state->topology = ast_stream_topology_clone(session->endpoint->media.topology);</span><br><span>           }</span><br><span>            if (!session->pending_media_state->topology) {</span><br><span style="color: hsl(0, 100%, 40%);">-                    return NULL;</span><br><span style="color: hsl(120, 100%, 40%);">+                  SCOPE_EXIT_RTN_VALUE(NULL, "No pending topology\n");</span><br><span>               }</span><br><span>    }</span><br><span> </span><br><span>@@ -4257,11 +4393,11 @@</span><br><span> </span><br><span>          session_media = ast_sip_session_media_state_add(session, session->pending_media_state, ast_stream_get_type(stream), i);</span><br><span>           if (!session_media) {</span><br><span style="color: hsl(0, 100%, 40%);">-                   return NULL;</span><br><span style="color: hsl(120, 100%, 40%);">+                  SCOPE_EXIT_RTN_VALUE(NULL, "Couldn't add state\n");</span><br><span>            }</span><br><span> </span><br><span>                if (add_sdp_streams(session_media, session, local, offer, stream)) {</span><br><span style="color: hsl(0, 100%, 40%);">-                    return NULL;</span><br><span style="color: hsl(120, 100%, 40%);">+                  SCOPE_EXIT_RTN_VALUE(NULL, "Couldn't add stream\n");</span><br><span>           }</span><br><span> </span><br><span>                /* If a stream was actually added then add any additional details */</span><br><span>@@ -4285,7 +4421,7 @@</span><br><span> </span><br><span>     /* Add any bundle groups that are present on the media state */</span><br><span>      if (add_bundle_groups(session, inv->pool_prov, local)) {</span><br><span style="color: hsl(0, 100%, 40%);">-             return NULL;</span><br><span style="color: hsl(120, 100%, 40%);">+          SCOPE_EXIT_RTN_VALUE(NULL, "Couldn't add bundled\n");</span><br><span>  }</span><br><span> </span><br><span>        /* Use the connection details of an available media if possible for SDP level */</span><br><span>@@ -4327,27 +4463,31 @@</span><br><span>   pj_strassign(&local->origin.addr_type, &local->conn->addr_type);</span><br><span>    pj_strassign(&local->origin.addr, &local->conn->addr);</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-     return local;</span><br><span style="color: hsl(120, 100%, 40%);">+ SCOPE_EXIT_RTN_VALUE(local);</span><br><span> }</span><br><span> </span><br><span> static void session_inv_on_rx_offer(pjsip_inv_session *inv, const pjmedia_sdp_session *offer)</span><br><span> {</span><br><span style="color: hsl(0, 100%, 40%);">-     struct ast_sip_session *session;</span><br><span>     pjmedia_sdp_session *answer;</span><br><span style="color: hsl(120, 100%, 40%);">+  struct ast_sip_session *session = inv->mod_data[session_module.id];</span><br><span style="color: hsl(120, 100%, 40%);">+        SCOPE_ENTER(1, "%s Inv State: %s\n", ast_sip_session_get_name(session),</span><br><span style="color: hsl(120, 100%, 40%);">+             pjsip_inv_state_name(inv->state));</span><br><span> </span><br><span>    if (ast_shutdown_final()) {</span><br><span style="color: hsl(0, 100%, 40%);">-             return;</span><br><span style="color: hsl(120, 100%, 40%);">+               SCOPE_EXIT_RTN("Shutting down\n");</span><br><span>         }</span><br><span> </span><br><span>        session = inv->mod_data[session_module.id];</span><br><span>       if (handle_incoming_sdp(session, offer)) {</span><br><span>           ast_sip_session_media_state_reset(session->pending_media_state);</span><br><span style="color: hsl(0, 100%, 40%);">-             return;</span><br><span style="color: hsl(120, 100%, 40%);">+               SCOPE_EXIT_RTN("Couldn't handle sdp\n");</span><br><span>       }</span><br><span> </span><br><span>        if ((answer = create_local_sdp(inv, session, offer))) {</span><br><span>              pjsip_inv_set_sdp_answer(inv, answer);</span><br><span>       }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+   SCOPE_EXIT_RTN();</span><br><span> }</span><br><span> </span><br><span> #if 0</span><br><span>@@ -4359,11 +4499,13 @@</span><br><span> </span><br><span> static void session_inv_on_media_update(pjsip_inv_session *inv, pj_status_t status)</span><br><span> {</span><br><span style="color: hsl(0, 100%, 40%);">-   struct ast_sip_session *session;</span><br><span>     const pjmedia_sdp_session *local, *remote;</span><br><span style="color: hsl(120, 100%, 40%);">+    struct ast_sip_session *session = inv->mod_data[session_module.id];</span><br><span style="color: hsl(120, 100%, 40%);">+        SCOPE_ENTER(1, "%s  Inv State: %s\n", ast_sip_session_get_name(session),</span><br><span style="color: hsl(120, 100%, 40%);">+            pjsip_inv_state_name(inv->state));</span><br><span> </span><br><span>    if (ast_shutdown_final()) {</span><br><span style="color: hsl(0, 100%, 40%);">-             return;</span><br><span style="color: hsl(120, 100%, 40%);">+               SCOPE_EXIT_RTN("Shutting down\n");</span><br><span>         }</span><br><span> </span><br><span>        session = inv->mod_data[session_module.id];</span><br><span>@@ -4373,7 +4515,7 @@</span><br><span>                * don't care about media updates.</span><br><span>                * Just ignore</span><br><span>                */</span><br><span style="color: hsl(0, 100%, 40%);">-             return;</span><br><span style="color: hsl(120, 100%, 40%);">+               SCOPE_EXIT_RTN("No session or channel\n");</span><br><span>         }</span><br><span> </span><br><span>        if (session->endpoint) {</span><br><span>@@ -4408,7 +4550,7 @@</span><br><span>          }</span><br><span> #endif</span><br><span>          if (bail) {</span><br><span style="color: hsl(0, 100%, 40%);">-                     return;</span><br><span style="color: hsl(120, 100%, 40%);">+                       SCOPE_EXIT_RTN("Bail\n");</span><br><span>          }</span><br><span>    }</span><br><span> </span><br><span>@@ -4417,12 +4559,14 @@</span><br><span>              ast_channel_hangupcause_set(session->channel, AST_CAUSE_BEARERCAPABILITY_NOTAVAIL);</span><br><span>               ast_set_hangupsource(session->channel, ast_channel_name(session->channel), 0);</span><br><span>                 ast_queue_hangup(session->channel);</span><br><span style="color: hsl(0, 100%, 40%);">-          return;</span><br><span style="color: hsl(120, 100%, 40%);">+               SCOPE_EXIT_RTN("Couldn't get active local\n");return;</span><br><span>  }</span><br><span> </span><br><span>        if (handle_negotiated_sdp(session, local, remote)) {</span><br><span>                 ast_sip_session_media_state_reset(session->pending_media_state);</span><br><span>  }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+   SCOPE_EXIT_RTN();</span><br><span> }</span><br><span> </span><br><span> static pjsip_redirect_op session_inv_on_redirected(pjsip_inv_session *inv, const pjsip_uri *target, const pjsip_event *e)</span><br><span></span><br></pre><p>To view, visit <a href="https://gerrit.asterisk.org/c/asterisk/+/14631">change 14631</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/+/14631"/><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: Ia83a1a2687ccb96f2bc8a2a3928a5214c4be775c </div>
<div style="display:none"> Gerrit-Change-Number: 14631 </div>
<div style="display:none"> Gerrit-PatchSet: 3 </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: George Joseph <gjoseph@digium.com> </div>
<div style="display:none"> Gerrit-Reviewer: Joshua Colp <jcolp@sangoma.com> </div>
<div style="display:none"> Gerrit-Reviewer: Kevin Harwell <kharwell@digium.com> </div>
<div style="display:none"> Gerrit-MessageType: merged </div>