sysmocom
/
asterisk
11
0
Fork 0
Code Issues Pull Requests Packages Projects Releases Wiki Activity

ACN: Add tracing to existing code 

Prior to making any modifications to the pjsip infrastructure
for ACN, I've added the tracing functions to the existing code.
This should make the final commit easier to review, but we can also
now run a "before and after" trace.

No functional changes were made with this commit.

Change-Id: Ia83a1a2687ccb96f2bc8a2a3928a5214c4be775c
This commit is contained in:
George Joseph 2020-07-06 13:23:24 -06:00
parent 2d22e34206
commit 9bd1d686a1
9 changed files with 438 additions and 179 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

3
apps/app_dial.c
View File

@ -1223,6 +1223,7 @@ static struct ast_channel *wait_for_answer(struct ast_channel *in,
int sent_ring = 0;
int sent_progress = 0;
struct timeval start = ast_tvnow();
SCOPE_TRACE(1, "%s\n", ast_channel_name(in));
if (single) {
/* Turn off hold music, etc */
@ -1389,6 +1390,7 @@ static struct ast_channel *wait_for_answer(struct ast_channel *in,
case AST_CONTROL_ANSWER:
/* This is our guy if someone answered. */
if (!peer) {
ast_trace(1, "%s answered %s\n", ast_channel_name(c), ast_channel_name(in));
ast_verb(3, "%s answered %s\n", ast_channel_name(c), ast_channel_name(in));
if (o->orig_chan_name
&& strcmp(o->orig_chan_name, ast_channel_name(c))) {
@ -2269,6 +2271,7 @@ static int dial_exec_full(struct ast_channel *chan, const char *data, struct ast
*/
struct ast_party_caller caller;
int max_forwards;
SCOPE_TRACE(1, "%s Data: %s\n", ast_channel_name(chan), data);
/* Reset all DIAL variables back to blank, to prevent confusion (in case we don't reset all of them). */
ast_channel_lock(chan);

197
channels/chan_pjsip.c
View File

@ -241,7 +241,10 @@ static enum ast_rtp_glue_result chan_pjsip_get_vrtp_peer(struct ast_channel *cha
/*! \brief Function called by RTP engine to get peer capabilities */
static void chan_pjsip_get_codec(struct ast_channel *chan, struct ast_format_cap *result)
{
SCOPE_ENTER(1, "%s Native formats %s\n", ast_channel_name(chan),
ast_str_tmp(AST_FORMAT_CAP_NAMES_LEN, ast_format_cap_get_names(ast_channel_nativeformats(chan), &STR_TMP)));
ast_format_cap_append_from_cap(result, ast_channel_nativeformats(chan), AST_MEDIA_TYPE_UNKNOWN);
SCOPE_EXIT_RTN();
}
/*! \brief Destructor function for \ref transport_info_data */
@ -450,21 +453,23 @@ static int chan_pjsip_set_rtp_peer(struct ast_channel *chan,
struct ast_sip_channel_pvt *channel = ast_channel_tech_pvt(chan);
struct ast_sip_session *session = channel->session;
struct rtp_direct_media_data *cdata;
SCOPE_ENTER(1, "%s %s\n", ast_channel_name(chan),
ast_str_tmp(AST_FORMAT_CAP_NAMES_LEN, ast_format_cap_get_names(cap, &STR_TMP)));
/* Don't try to do any direct media shenanigans on early bridges */
if ((rtp || vrtp || tpeer) && !ast_channel_is_bridged(chan)) {
ast_debug(4, "Disregarding setting RTP on %s: channel is not bridged\n", ast_channel_name(chan));
return 0;
SCOPE_EXIT_RTN_VALUE(0, "Channel not bridged\n");
}
if (nat_active && session->endpoint->media.direct_media.disable_on_nat) {
ast_debug(4, "Disregarding setting RTP on %s: NAT is active\n", ast_channel_name(chan));
return 0;
SCOPE_EXIT_RTN_VALUE(0, "NAT is active\n");
}
cdata = rtp_direct_media_data_create(chan, rtp, vrtp, cap, session);
if (!cdata) {
return 0;
SCOPE_EXIT_RTN_VALUE(0);
}
if (ast_sip_push_task(session->serializer, send_direct_media_request, cdata)) {
@ -472,7 +477,7 @@ static int chan_pjsip_set_rtp_peer(struct ast_channel *chan,
ao2_ref(cdata, -1);
}
return 0;
SCOPE_EXIT_RTN_VALUE(0);
}
/*! \brief Local glue for interacting with the RTP engine core */
@ -520,17 +525,20 @@ static int compatible_formats_exist(struct ast_stream_topology *top, struct ast_
{
struct ast_format_cap *cap_from_top;
int res;
SCOPE_ENTER(1, "Topology: %s Formats: %s\n",
ast_str_tmp(AST_FORMAT_CAP_NAMES_LEN, ast_stream_topology_to_str(top, &STR_TMP)),
ast_str_tmp(AST_FORMAT_CAP_NAMES_LEN, ast_format_cap_get_names(cap, &STR_TMP)));
cap_from_top = ast_stream_topology_get_formats(top);
if (!cap_from_top) {
return 0;
SCOPE_EXIT_RTN_VALUE(0, "Topology had no formats\n");
}
res = ast_format_cap_iscompatible(cap_from_top, cap);
ao2_ref(cap_from_top, -1);
return res;
SCOPE_EXIT_RTN_VALUE(res, "Compatible? %s\n", res ? "yes" : "no");
}
/*! \brief Function called to create a new PJSIP Asterisk channel */
@ -542,9 +550,10 @@ static struct ast_channel *chan_pjsip_new(struct ast_sip_session *session, int s
struct ast_sip_channel_pvt *channel;
struct ast_variable *var;
struct ast_stream_topology *topology;
SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(session));
if (!(pvt = ao2_alloc_options(sizeof(*pvt), chan_pjsip_pvt_dtor, AO2_ALLOC_OPT_LOCK_NOLOCK))) {
return NULL;
SCOPE_EXIT_RTN_VALUE(NULL, "Couldn't create pvt\n");
}
chan = ast_channel_alloc_with_endpoint(1, state,
@ -557,7 +566,7 @@ static struct ast_channel *chan_pjsip_new(struct ast_sip_session *session, int s
ast_sorcery_object_get_id(session->endpoint),
(unsigned) ast_atomic_fetchadd_int((int *) &chan_idx, +1));
if (!chan) {
return NULL;
SCOPE_EXIT_RTN_VALUE(NULL, "Couldn't create channel\n");
}
ast_channel_tech_set(chan, &chan_pjsip_tech);
@ -565,7 +574,7 @@ static struct ast_channel *chan_pjsip_new(struct ast_sip_session *session, int s
if (!(channel = ast_sip_channel_pvt_alloc(pvt, session))) {
ast_channel_unlock(chan);
ast_hangup(chan);
return NULL;
SCOPE_EXIT_RTN_VALUE(NULL, "Couldn't create pvt channel\n");
}
ast_channel_tech_pvt_set(chan, channel);
@ -576,7 +585,7 @@ static struct ast_channel *chan_pjsip_new(struct ast_sip_session *session, int s
if (!caps) {
ast_channel_unlock(chan);
ast_hangup(chan);
return NULL;
SCOPE_EXIT_RTN_VALUE(NULL, "Couldn't create caps\n");
}
ast_format_cap_append_from_cap(caps, session->endpoint->media.codecs, AST_MEDIA_TYPE_UNKNOWN);
topology = ast_stream_topology_clone(session->endpoint->media.topology);
@ -590,7 +599,7 @@ static struct ast_channel *chan_pjsip_new(struct ast_sip_session *session, int s
ast_stream_topology_free(topology);
ast_channel_unlock(chan);
ast_hangup(chan);
return NULL;
SCOPE_EXIT_RTN_VALUE(NULL, "Couldn't get caps or clone topology\n");
}
ast_channel_stage_snapshot(chan);
@ -660,14 +669,21 @@ static struct ast_channel *chan_pjsip_new(struct ast_sip_session *session, int s
set_channel_on_rtp_instance(session, ast_channel_uniqueid(chan));
return chan;
SCOPE_EXIT_RTN_VALUE(chan);
}
struct answer_data {
struct ast_sip_session *session;
unsigned long indent;
};
static int answer(void *data)
{
struct answer_data *ans_data = data;
pj_status_t status = PJ_SUCCESS;
pjsip_tx_data *packet = NULL;
struct ast_sip_session *session = data;
struct ast_sip_session *session = ans_data->session;
SCOPE_ENTER_TASK(1, ans_data->indent, "%s\n", ast_sip_session_get_name(session));
if (session->inv_session->state == PJSIP_INV_STATE_DISCONNECTED) {
ast_log(LOG_ERROR, "Session already DISCONNECTED [reason=%d (%s)]\n",
@ -676,7 +692,7 @@ static int answer(void *data)
#ifdef HAVE_PJSIP_INV_SESSION_REF
pjsip_inv_dec_ref(session->inv_session);
#endif
return 0;
SCOPE_EXIT_RTN_VALUE(0, "Disconnected\n");
}
pjsip_dlg_inc_lock(session->inv_session->dlg);
@ -706,9 +722,9 @@ static int answer(void *data)
* Return this value so we can distinguish between this
* failure and the threadpool synchronous push failing.
*/
return -2;
SCOPE_EXIT_RTN_VALUE(-2, "pjproject failure\n");
}
return 0;
SCOPE_EXIT_RTN_VALUE(0);
}
/*! \brief Function called by core when we should answer a PJSIP session */
@ -716,9 +732,12 @@ static int chan_pjsip_answer(struct ast_channel *ast)
{
struct ast_sip_channel_pvt *channel = ast_channel_tech_pvt(ast);
struct ast_sip_session *session;
struct answer_data ans_data = { 0, };
int res;
SCOPE_ENTER(1, "%s\n", ast_channel_name(ast));
if (ast_channel_state(ast) == AST_STATE_UP) {
SCOPE_EXIT_RTN_VALUE(0, "Already up\n");
return 0;
}
@ -727,9 +746,9 @@ static int chan_pjsip_answer(struct ast_channel *ast)
#ifdef HAVE_PJSIP_INV_SESSION_REF
if (pjsip_inv_add_ref(session->inv_session) != PJ_SUCCESS) {
ast_log(LOG_ERROR, "Can't increase the session reference counter\n");
ast_log(LOG_ERROR, "Couldn't increase the session reference counter\n");
ao2_ref(session, -1);
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Couldn't increase the session reference counter\n");
}
#endif
@ -737,7 +756,9 @@ static int chan_pjsip_answer(struct ast_channel *ast)
can occur between this thread and bridging (specifically when native bridging
attempts to do direct media) */
ast_channel_unlock(ast);
res = ast_sip_push_task_wait_serializer(session->serializer, answer, session);
ans_data.session = session;
ans_data.indent = ast_trace_get_indent();
res = ast_sip_push_task_wait_serializer(session->serializer, answer, &ans_data);
if (res) {
if (res == -1) {
ast_log(LOG_ERROR,"Cannot answer '%s': Unable to push answer task to the threadpool.\n",
@ -748,12 +769,12 @@ static int chan_pjsip_answer(struct ast_channel *ast)
}
ao2_ref(session, -1);
ast_channel_lock(ast);
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Couldn't push task\n");
}
ao2_ref(session, -1);
ast_channel_lock(ast);
return 0;
SCOPE_EXIT_RTN_VALUE(0);
}
/*! \brief Internal helper function called when CNG tone is detected */
@ -1564,6 +1585,9 @@ static struct topology_change_refresh_data *topology_change_refresh_data_alloc(
static int on_topology_change_response(struct ast_sip_session *session, pjsip_rx_data *rdata)
{
SCOPE_ENTER(1, "%s Status code: %d\n", ast_sip_session_get_name(session),
rdata->msg_info.msg->line.status.code);
if (PJSIP_IS_STATUS_IN_CLASS(rdata->msg_info.msg->line.status.code, 200)) {
/* The topology was changed to something new so give notice to what requested
* it so it queries the channel and updates accordingly.
@ -1576,20 +1600,21 @@ static int on_topology_change_response(struct ast_sip_session *session, pjsip_rx
ast_sip_session_media_state_reset(session->pending_media_state);
}
return 0;
SCOPE_EXIT_RTN_VALUE(0);
}
static int send_topology_change_refresh(void *data)
{
struct topology_change_refresh_data *refresh_data = data;
int ret;
SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(refresh_data->session));
ret = ast_sip_session_refresh(refresh_data->session, NULL, NULL, on_topology_change_response,
AST_SIP_SESSION_REFRESH_METHOD_INVITE, 1, refresh_data->media_state);
refresh_data->media_state = NULL;
topology_change_refresh_data_free(refresh_data);
return ret;
SCOPE_EXIT_RTN_VALUE(ret, "RC: %d\n", ret);
}
static int handle_topology_request_change(struct ast_sip_session *session,
@ -1597,17 +1622,18 @@ static int handle_topology_request_change(struct ast_sip_session *session,
{
struct topology_change_refresh_data *refresh_data;
int res;
SCOPE_ENTER(1);
refresh_data = topology_change_refresh_data_alloc(session, proposed);
if (!refresh_data) {
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Couldn't create refresh_data\n");
}
res = ast_sip_push_task(session->serializer, send_topology_change_refresh, refresh_data);
if (res) {
topology_change_refresh_data_free(refresh_data);
}
return res;
SCOPE_EXIT_RTN_VALUE(res, "RC: %d\n", res);
}
/*! \brief Function called by core to ask the channel to indicate some sort of condition */
@ -1621,6 +1647,10 @@ static int chan_pjsip_indicate(struct ast_channel *ast, int condition, const voi
size_t device_buf_size;
int i;
const struct ast_stream_topology *topology;
struct ast_frame f = { .frametype = AST_FRAME_CONTROL, .subclass = { .integer = condition } };
char subclass[40] = "";
SCOPE_ENTER(1, "%s Handling %s\n", ast_channel_name(ast),
ast_frame_subclass2str(&f, subclass, sizeof(subclass), NULL, 0));
switch (condition) {
case AST_CONTROL_RINGING:
@ -1727,7 +1757,7 @@ static int chan_pjsip_indicate(struct ast_channel *ast, int condition, const voi
if (pjsip_inv_add_ref(channel->session->inv_session) != PJ_SUCCESS) {
ast_log(LOG_ERROR, "Can't increase the session reference counter\n");
ao2_cleanup(channel->session);
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Couldn't increase the session reference counter\n");
}
#endif
if (ast_sip_push_task(channel->session->serializer, update_connected_line_information, channel->session)) {
@ -1836,13 +1866,13 @@ static int chan_pjsip_indicate(struct ast_channel *ast, int condition, const voi
struct indicate_data *ind_data = indicate_data_alloc(channel->session, condition, response_code, data, datalen);
if (!ind_data) {
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Couldn't create indicate data\n");
}
#ifdef HAVE_PJSIP_INV_SESSION_REF
if (pjsip_inv_add_ref(ind_data->session->inv_session) != PJ_SUCCESS) {
ast_log(LOG_ERROR, "Can't increase the session reference counter\n");
ao2_cleanup(ind_data);
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Couldn't increase the session reference counter\n");
}
#endif
if (ast_sip_push_task(channel->session->serializer, indicate, ind_data)) {
@ -1856,7 +1886,7 @@ static int chan_pjsip_indicate(struct ast_channel *ast, int condition, const voi
}
}
return res;
SCOPE_EXIT_RTN_VALUE(res, "RC: %d\n", res);
}
struct transfer_data {
@ -2397,8 +2427,14 @@ static int call(void *data)
struct ast_sip_channel_pvt *channel = data;
struct ast_sip_session *session = channel->session;
pjsip_tx_data *tdata;
int res = 0;
SCOPE_ENTER(1, "%s Topology: %s\n",
ast_sip_session_get_name(session),
ast_str_tmp(256, ast_stream_topology_to_str(channel->session->pending_media_state->topology, &STR_TMP))
);
int res = ast_sip_session_create_invite(session, &tdata);
res = ast_sip_session_create_invite(session, &tdata);
if (res) {
ast_set_hangupsource(session->channel, ast_channel_name(session->channel), 0);
@ -2409,22 +2445,24 @@ static int call(void *data)
ast_sip_session_send_request(session, tdata);
}
ao2_ref(channel, -1);
return res;
SCOPE_EXIT_RTN_VALUE(res, "RC: %d\n", res);
}
/*! \brief Function called by core to actually start calling a remote party */
static int chan_pjsip_call(struct ast_channel *ast, const char *dest, int timeout)
{
struct ast_sip_channel_pvt *channel = ast_channel_tech_pvt(ast);
SCOPE_ENTER(1, "%s Topology: %s\n", ast_sip_session_get_name(channel->session),
ast_str_tmp(256, ast_stream_topology_to_str(channel->session->pending_media_state->topology, &STR_TMP)));
ao2_ref(channel, +1);
if (ast_sip_push_task(channel->session->serializer, call, channel)) {
ast_log(LOG_WARNING, "Error attempting to place outbound call to '%s'\n", dest);
ao2_cleanup(channel);
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Couldn't push task\n");
}
return 0;
SCOPE_EXIT_RTN_VALUE(0, "'call' task pushed\n");
}
/*! \brief Internal function which translates from Asterisk cause codes to SIP response codes */
@ -2514,6 +2552,8 @@ static int hangup(void *data)
struct hangup_data *h_data = data;
struct ast_channel *ast = h_data->chan;
struct ast_sip_channel_pvt *channel = ast_channel_tech_pvt(ast);
SCOPE_ENTER(1, "%s\n", ast_channel_name(ast));
/*
* Before cleaning we have to ensure that channel or its session is not NULL
* we have seen rare case when taskprocessor calls hangup but channel is NULL
@ -2536,7 +2576,7 @@ static int hangup(void *data)
ao2_cleanup(channel);
}
ao2_cleanup(h_data);
return 0;
SCOPE_EXIT_RTN_VALUE(0);
}
/*! \brief Function called by core to hang up a PJSIP session */
@ -2545,9 +2585,10 @@ static int chan_pjsip_hangup(struct ast_channel *ast)
struct ast_sip_channel_pvt *channel = ast_channel_tech_pvt(ast);
int cause;
struct hangup_data *h_data;
SCOPE_ENTER(1, "%s\n", ast_channel_name(ast));
if (!channel || !channel->session) {
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "No channel or session\n");
}
cause = hangup_cause2sip(ast_channel_hangupcause(channel->session->channel));
@ -2562,7 +2603,7 @@ static int chan_pjsip_hangup(struct ast_channel *ast)
goto failure;
}
return 0;
SCOPE_EXIT_RTN_VALUE(0, "Cause: %d\n", cause);
failure:
/* Go ahead and do our cleanup of the session and channel even if we're not going
@ -2572,7 +2613,7 @@ failure:
ao2_cleanup(channel);
ao2_cleanup(h_data);
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Cause: %d\n", cause);
}
struct request_data {
@ -2593,11 +2634,12 @@ static int request(void *obj)
AST_APP_ARG(endpoint);
AST_APP_ARG(aor);
);
SCOPE_ENTER(1, "%s\n",tmp);
if (ast_strlen_zero(tmp)) {
ast_log(LOG_ERROR, "Unable to create PJSIP channel with empty destination\n");
req_data->cause = AST_CAUSE_CHANNEL_UNACCEPTABLE;
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Empty destination\n");
}
AST_NONSTANDARD_APP_ARGS(args, tmp, '/');
@ -2619,14 +2661,14 @@ static int request(void *obj)
ast_log(LOG_ERROR, "Unable to create PJSIP channel with empty endpoint name\n");
}
req_data->cause = AST_CAUSE_CHANNEL_UNACCEPTABLE;
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Empty endpoint name\n");
}
endpoint = ast_sorcery_retrieve_by_id(ast_sip_get_sorcery(), "endpoint",
endpoint_name);
if (!endpoint) {
ast_log(LOG_ERROR, "Unable to create PJSIP channel - endpoint '%s' was not found\n", endpoint_name);
req_data->cause = AST_CAUSE_NO_ROUTE_DESTINATION;
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Endpoint not found\n");
}
} else {
/* First try to find an exact endpoint match, for single (user) or multi-domain (user@domain) */
@ -2634,7 +2676,7 @@ static int request(void *obj)
if (ast_strlen_zero(endpoint_name)) {
ast_log(LOG_ERROR, "Unable to create PJSIP channel with empty endpoint name\n");
req_data->cause = AST_CAUSE_CHANNEL_UNACCEPTABLE;
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Empty endpoint name\n");
}
endpoint = ast_sorcery_retrieve_by_id(ast_sip_get_sorcery(), "endpoint",
endpoint_name);
@ -2652,7 +2694,7 @@ static int request(void *obj)
ast_log(LOG_ERROR, "Unable to create PJSIP channel - endpoint '%s' was not found\n",
args.endpoint);
req_data->cause = AST_CAUSE_NO_ROUTE_DESTINATION;
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Endpoint not found\n");
}
request_user = args.endpoint;
*endpoint_name++ = '\0';
@ -2661,7 +2703,7 @@ static int request(void *obj)
ast_log(LOG_ERROR, "Unable to create PJSIP channel with empty endpoint name: %s@<endpoint-name>\n",
request_user);
req_data->cause = AST_CAUSE_CHANNEL_UNACCEPTABLE;
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Empty endpoint name\n");
}
endpoint = ast_sorcery_retrieve_by_id(ast_sip_get_sorcery(), "endpoint",
@ -2669,7 +2711,7 @@ static int request(void *obj)
if (!endpoint) {
ast_log(LOG_ERROR, "Unable to create PJSIP channel - endpoint '%s' was not found\n", endpoint_name);
req_data->cause = AST_CAUSE_NO_ROUTE_DESTINATION;
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Endpoint not found\n");
}
}
}
@ -2680,12 +2722,12 @@ static int request(void *obj)
if (!session) {
ast_log(LOG_ERROR, "Failed to create outgoing session to endpoint '%s'\n", endpoint_name);
req_data->cause = AST_CAUSE_NO_ROUTE_DESTINATION;
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Couldn't create session\n");
}
req_data->session = session;
return 0;
SCOPE_EXIT_RTN_VALUE(0);
}
/*! \brief Function called by core to create a new outgoing PJSIP session */
@ -2693,6 +2735,8 @@ static struct ast_channel *chan_pjsip_request_with_stream_topology(const char *t
{
struct request_data req_data;
RAII_VAR(struct ast_sip_session *, session, NULL, ao2_cleanup);
SCOPE_ENTER(1, "%s Topology: %s\n", data,
ast_str_tmp(256, ast_stream_topology_to_str(topology, &STR_TMP)));
req_data.topology = topology;
req_data.dest = data;
@ -2701,17 +2745,17 @@ static struct ast_channel *chan_pjsip_request_with_stream_topology(const char *t
if (ast_sip_push_task_wait_servant(NULL, request, &req_data)) {
*cause = req_data.cause;
return NULL;
SCOPE_EXIT_RTN_VALUE(NULL, "Couldn't push task\n");
}
session = req_data.session;
if (!(session->channel = chan_pjsip_new(session, AST_STATE_DOWN, NULL, NULL, assignedids, requestor, NULL))) {
/* Session needs to be terminated prematurely */
return NULL;
SCOPE_EXIT_RTN_VALUE(NULL, "Couldn't create channel\n");
}
return session->channel;
SCOPE_EXIT_RTN_VALUE(session->channel, "Channel: %s\n", ast_channel_name(session->channel));
}
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)
@ -2988,27 +3032,31 @@ static int hangup_sip2cause(int cause)
static void chan_pjsip_session_begin(struct ast_sip_session *session)
{
RAII_VAR(struct ast_datastore *, datastore, NULL, ao2_cleanup);
SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(session));
if (session->endpoint->media.direct_media.glare_mitigation ==
AST_SIP_DIRECT_MEDIA_GLARE_MITIGATION_NONE) {
return;
SCOPE_EXIT_RTN("Direct media no glare mitigation\n");
}
datastore = ast_sip_session_alloc_datastore(&direct_media_mitigation_info,
"direct_media_glare_mitigation");
if (!datastore) {
return;
SCOPE_EXIT_RTN("Couldn't create datastore\n");
}
ast_sip_session_add_datastore(session, datastore);
SCOPE_EXIT_RTN();
}
/*! \brief Function called when the session ends */
static void chan_pjsip_session_end(struct ast_sip_session *session)
{
SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(session));
if (!session->channel) {
return;
SCOPE_EXIT_RTN("No channel\n");
}
chan_pjsip_remove_hold(ast_channel_uniqueid(session->channel));
@ -3021,6 +3069,8 @@ static void chan_pjsip_session_end(struct ast_sip_session *session)
} else {
ast_queue_hangup(session->channel);
}
SCOPE_EXIT_RTN();
}
/*! \brief Function called when a request is received on the session */
@ -3029,9 +3079,10 @@ static int chan_pjsip_incoming_request(struct ast_sip_session *session, struct p
RAII_VAR(struct ast_datastore *, datastore, NULL, ao2_cleanup);
struct transport_info_data *transport_data;
pjsip_tx_data *packet = NULL;
SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(session));
if (session->channel) {
return 0;
SCOPE_EXIT_RTN_VALUE(0, "Already have channel\n");
}
/* Check for a to-tag to determine if this is a reinvite */
@ -3047,17 +3098,17 @@ static int chan_pjsip_incoming_request(struct ast_sip_session *session, struct p
*/
session->defer_terminate = 0;
ast_sip_session_terminate(session, 400);
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Reinvite without channel\n");
}
datastore = ast_sip_session_alloc_datastore(&transport_info, "transport_info");
if (!datastore) {
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Couldn't create datastore\n");
}
transport_data = ast_calloc(1, sizeof(*transport_data));
if (!transport_data) {
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Couldn't create transport_data\n");
}
pj_sockaddr_cp(&transport_data->local_addr, &rdata->tp_info.transport->local_addr);
pj_sockaddr_cp(&transport_data->remote_addr, &rdata->pkt_info.src_addr);
@ -3071,11 +3122,11 @@ static int chan_pjsip_incoming_request(struct ast_sip_session *session, struct p
}
ast_log(LOG_ERROR, "Failed to allocate new PJSIP channel on incoming SIP INVITE\n");
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Couldn't create channel\n");
}
/* channel gets created on incoming request, but we wait to call start
so other supplements have a chance to run */
return 0;
SCOPE_EXIT_RTN_VALUE(0);
}
static int call_pickup_incoming_request(struct ast_sip_session *session, pjsip_rx_data *rdata)
@ -3131,11 +3182,12 @@ static struct ast_sip_session_supplement call_pickup_supplement = {
static int pbx_start_incoming_request(struct ast_sip_session *session, pjsip_rx_data *rdata)
{
int res;
SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(session));
/* Check for a to-tag to determine if this is a reinvite */
if (rdata->msg_info.to->tag.slen) {
/* We don't care about reinvites */
return 0;
SCOPE_EXIT_RTN_VALUE(0, "Reinvite\n");
}
res = ast_pbx_start(session->channel);
@ -3158,7 +3210,7 @@ static int pbx_start_incoming_request(struct ast_sip_session *session, pjsip_rx_
ast_debug(3, "Started PBX on new PJSIP channel %s\n", ast_channel_name(session->channel));
return (res == AST_PBX_SUCCESS) ? 0 : -1;
SCOPE_EXIT_RTN_VALUE((res == AST_PBX_SUCCESS) ? 0 : -1, "RC: %d\n", res);
}
static struct ast_sip_session_supplement pbx_start_supplement = {
@ -3173,9 +3225,11 @@ static void chan_pjsip_incoming_response(struct ast_sip_session *session, struct
struct pjsip_status_line status = rdata->msg_info.msg->line.status;
struct ast_control_pvt_cause_code *cause_code;
int data_size = sizeof(*cause_code);
SCOPE_ENTER(1, "%s Method: %.*s Status: %d\n", ast_sip_session_get_name(session),
(int)rdata->msg_info.cseq->method.name.slen, rdata->msg_info.cseq->method.name.ptr, status.code);
if (!session->channel) {
return;
SCOPE_EXIT_RTN("No channel\n");
}
/* Build and send the tech-specific cause information */
@ -3195,6 +3249,8 @@ static void chan_pjsip_incoming_response(struct ast_sip_session *session, struct
switch (status.code) {
case 180:
ast_trace(1, "%s Method: %.*s Status: %d Queueing RINGING\n", ast_sip_session_get_name(session),
(int)rdata->msg_info.cseq->method.name.slen, rdata->msg_info.cseq->method.name.ptr, status.code);
ast_queue_control(session->channel, AST_CONTROL_RINGING);
ast_channel_lock(session->channel);
if (ast_channel_state(session->channel) != AST_STATE_UP) {
@ -3206,28 +3262,45 @@ static void chan_pjsip_incoming_response(struct ast_sip_session *session, struct
if (session->endpoint->ignore_183_without_sdp) {
pjsip_rdata_sdp_info *sdp = pjsip_rdata_get_sdp_info(rdata);
if (sdp && sdp->body.ptr) {
ast_trace(1, "%s Method: %.*s Status: %d Queueing PROGRESS with SDP\n", ast_sip_session_get_name(session),
(int)rdata->msg_info.cseq->method.name.slen, rdata->msg_info.cseq->method.name.ptr, status.code);
ast_queue_control(session->channel, AST_CONTROL_PROGRESS);
}
} else {
ast_trace(1, "%s Method: %.*s Status: %d Queueing PROGRESS without SDP\n", ast_sip_session_get_name(session),
(int)rdata->msg_info.cseq->method.name.slen, rdata->msg_info.cseq->method.name.ptr, status.code);
ast_queue_control(session->channel, AST_CONTROL_PROGRESS);
}
break;
case 200:
ast_trace(1, "%s Method: %.*s Status: %d Queueing ANSWER\n", ast_sip_session_get_name(session),
(int)rdata->msg_info.cseq->method.name.slen, rdata->msg_info.cseq->method.name.ptr, status.code);
ast_queue_control(session->channel, AST_CONTROL_ANSWER);
break;
default:
ast_trace(1, "%s Method: %.*s Status: %d Ignored\n", ast_sip_session_get_name(session),
(int)rdata->msg_info.cseq->method.name.slen, rdata->msg_info.cseq->method.name.ptr, status.code);
break;
}
SCOPE_EXIT_RTN();
}
static int chan_pjsip_incoming_ack(struct ast_sip_session *session, struct pjsip_rx_data *rdata)
{
SCOPE_ENTER(1, "%s Method: %.*s Status: %d After Media\n", ast_sip_session_get_name(session),
(int)rdata->msg_info.cseq->method.name.slen, rdata->msg_info.cseq->method.name.ptr,
rdata->msg_info.msg->line.status.code);
if (rdata->msg_info.msg->line.req.method.id == PJSIP_ACK_METHOD) {
if (session->endpoint->media.direct_media.enabled && session->channel) {
ast_trace(1, "%s Method: %.*s Queueing SRCCHANGE\n", ast_sip_session_get_name(session),
(int)rdata->msg_info.cseq->method.name.slen, rdata->msg_info.cseq->method.name.ptr);
ast_queue_control(session->channel, AST_CONTROL_SRCCHANGE);
}
}
return 0;
SCOPE_EXIT_RTN_VALUE(0);
}
static int update_devstate(void *obj, void *arg, int flags)

9
include/asterisk/res_pjsip_session.h
View File

@ -926,4 +926,13 @@ int ast_sip_session_media_set_write_callback(struct ast_sip_session *session, st
*/
struct ast_sip_session_media *ast_sip_session_media_get_transport(struct ast_sip_session *session, struct ast_sip_session_media *session_media);
/*!
* \brief Get the channel or endpoint name associated with the session
* \since 18.0.0
*
* \param session
* \retval Channel name or endpoint name or "unknown"
*/
const char *ast_sip_session_get_name(const struct ast_sip_session *session);
#endif /* _RES_PJSIP_SESSION_H */

3
main/bridge.c
View File

@ -1673,6 +1673,7 @@ int ast_bridge_join(struct ast_bridge *bridge,
{
struct ast_bridge_channel *bridge_channel;
int res = 0;
SCOPE_TRACE(1, "%s Bridge: %s\n", ast_channel_name(chan), bridge->uniqueid);
bridge_channel = bridge_channel_internal_alloc(bridge);
if (flags & AST_BRIDGE_JOIN_PASS_REFERENCE) {
@ -1921,6 +1922,7 @@ int ast_bridge_impart(struct ast_bridge *bridge,
.done = 0,
};
int res;
SCOPE_TRACE(1, "%s Bridge: %s\n", ast_channel_name(chan), bridge->uniqueid);
ast_mutex_init(&cond.lock);
ast_cond_init(&cond.cond, NULL);
@ -1942,6 +1944,7 @@ int ast_bridge_depart(struct ast_channel *chan)
{
struct ast_bridge_channel *bridge_channel;
int departable;
SCOPE_TRACE(1, "%s\n", ast_channel_name(chan));
ast_channel_lock(chan);
bridge_channel = ast_channel_internal_bridge_channel(chan);

3
main/channel.c
View File

@ -2622,6 +2622,7 @@ static void set_channel_answer_time(struct ast_channel *chan)
int ast_raw_answer(struct ast_channel *chan)
{
int res = 0;
SCOPE_TRACE(1, "%s\n", ast_channel_name(chan));
ast_channel_lock(chan);
@ -2670,6 +2671,7 @@ int __ast_answer(struct ast_channel *chan, unsigned int delay)
{
int res = 0;
enum ast_channel_state old_state;
SCOPE_TRACE(1, "%s\n", ast_channel_name(chan));
old_state = ast_channel_state(chan);
if ((res = ast_raw_answer(chan))) {
@ -2777,6 +2779,7 @@ int __ast_answer(struct ast_channel *chan, unsigned int delay)
int ast_answer(struct ast_channel *chan)
{
SCOPE_TRACE(1, "%s\n", ast_channel_name(chan));
return __ast_answer(chan, 0);
}

12
main/channel_internal_api.c
View File

@ -677,6 +677,10 @@ void *ast_channel_get_stream_topology_change_source(struct ast_channel *chan)
void ast_channel_nativeformats_set(struct ast_channel *chan,
struct ast_format_cap *value)
{
SCOPE_ENTER(2, "%s: %sFormats: %s\n", S_OR(ast_channel_name(chan), "<initializing>"),
S_COR(ast_channel_is_multistream(chan), "Multistream", ""),
ast_str_tmp(128, ast_format_cap_get_names(value, &STR_TMP)));
ast_assert(chan != NULL);
ao2_replace(chan->nativeformats, value);
@ -685,7 +689,7 @@ void ast_channel_nativeformats_set(struct ast_channel *chan,
* and topology is destroyed.
*/
if (!chan->stream_topology) {
return;
SCOPE_EXIT_RTN("Channel is being initialized or destroyed\n");
}
if (!ast_channel_is_multistream(chan) || !value) {
@ -693,7 +697,9 @@ void ast_channel_nativeformats_set(struct ast_channel *chan,
new_topology = ast_stream_topology_create_from_format_cap(value);
ast_channel_internal_set_stream_topology(chan, new_topology);
SCOPE_EXIT_RTN("New %stopology set\n", value ? "" : "empty ");
}
SCOPE_EXIT_RTN("Set native formats but not topology\n");
}
struct ast_framehook_list *ast_channel_framehooks(const struct ast_channel *chan)
@ -1586,6 +1592,8 @@ struct ast_stream_topology *ast_channel_set_stream_topology(struct ast_channel *
struct ast_stream_topology *topology)
{
struct ast_stream_topology *new_topology;
SCOPE_ENTER(1, "%s: %s\n", ast_channel_name(chan),
ast_str_tmp(256, ast_stream_topology_to_str(topology, &STR_TMP)));
ast_assert(chan != NULL);
@ -1605,7 +1613,7 @@ struct ast_stream_topology *ast_channel_set_stream_topology(struct ast_channel *
ast_channel_internal_set_stream_topology(chan, new_topology);
}
return new_topology;
SCOPE_EXIT_RTN_VALUE(new_topology, "Used %s topology\n", topology ? "provided" : "empty");
}
struct ast_stream *ast_channel_get_default_stream(struct ast_channel *chan,

2
main/features.c
View File

@ -536,6 +536,7 @@ static int pre_bridge_setup(struct ast_channel *chan, struct ast_channel *peer,
struct ast_bridge_features *chan_features, struct ast_bridge_features *peer_features)
{
int res;
SCOPE_TRACE(1, "%s Peer: %s\n", ast_channel_name(chan), ast_channel_name(peer));
set_bridge_features_on_config(config, pbx_builtin_getvar_helper(chan, "BRIDGE_FEATURES"));
add_features_datastores(chan, peer, config);
@ -629,6 +630,7 @@ int ast_bridge_call_with_flags(struct ast_channel *chan, struct ast_channel *pee
struct ast_bridge *bridge;
struct ast_bridge_features chan_features;
struct ast_bridge_features *peer_features;
SCOPE_TRACE(1, "%s Peer: %s\n", ast_channel_name(chan), ast_channel_name(peer));
/* Setup features. */
res = ast_bridge_features_init(&chan_features);

80
res/res_pjsip_sdp_rtp.c
View File

@ -324,6 +324,7 @@ static void get_codecs(struct ast_sip_session *session, const struct pjmedia_sdp
char fmt_param[256];
enum ast_rtp_options options = session->endpoint->media.g726_non_standard ?
AST_RTP_OPT_G726_NONSTANDARD : 0;
SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(session));
ast_rtp_codecs_payloads_initialize(codecs);
@ -395,6 +396,8 @@ static void get_codecs(struct ast_sip_session *session, const struct pjmedia_sdp
ast_rtp_codecs_set_framing(codecs, framing);
}
}
SCOPE_EXIT_RTN();
}
static int apply_cap_to_bundled(struct ast_sip_session_media *session_media,
@ -436,12 +439,14 @@ static struct ast_format_cap *set_incoming_call_offer_cap(
struct ast_format_cap *remote;
struct ast_rtp_codecs codecs = AST_RTP_CODECS_NULL_INIT;
int fmts = 0;
SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(session));
remote = ast_format_cap_alloc(AST_FORMAT_CAP_FLAG_DEFAULT);
if (!remote) {
ast_log(LOG_ERROR, "Failed to allocate %s incoming remote capabilities\n",
ast_codec_media_type2str(session_media->type));
return NULL;
SCOPE_EXIT_RTN_VALUE(NULL, "Couldn't allocate caps\n");
}
/* Get the peer's capabilities*/
@ -456,7 +461,7 @@ static struct ast_format_cap *set_incoming_call_offer_cap(
if (!incoming_call_offer_cap || ast_format_cap_empty(incoming_call_offer_cap)) {
ao2_cleanup(incoming_call_offer_cap);
ast_rtp_codecs_payloads_destroy(&codecs);
return NULL;
SCOPE_EXIT_RTN_VALUE(NULL, "No incoming call offer caps\n");
}
/*
@ -470,7 +475,7 @@ static struct ast_format_cap *set_incoming_call_offer_cap(
ast_rtp_codecs_payloads_destroy(&codecs);
return incoming_call_offer_cap;
SCOPE_EXIT_RTN_VALUE(incoming_call_offer_cap);
}
static int set_caps(struct ast_sip_session *session,
@ -488,13 +493,15 @@ static int set_caps(struct ast_sip_session *session,
int direct_media_enabled = !ast_sockaddr_isnull(&session_media->direct_media_addr) &&
ast_format_cap_count(session->direct_media_cap);
int dsp_features = 0;
SCOPE_ENTER(1, "%s %s\n", ast_sip_session_get_name(session), is_offer ? "OFFER" : "ANSWER");
if (!(caps = ast_format_cap_alloc(AST_FORMAT_CAP_FLAG_DEFAULT)) ||
!(peer = ast_format_cap_alloc(AST_FORMAT_CAP_FLAG_DEFAULT)) ||
!(joint = ast_format_cap_alloc(AST_FORMAT_CAP_FLAG_DEFAULT))) {
ast_log(LOG_ERROR, "Failed to allocate %s capabilities\n",
ast_codec_media_type2str(session_media->type));
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Couldn't create %s capabilities\n",
ast_codec_media_type2str(session_media->type));
}
/* get the endpoint capabilities */
@ -519,7 +526,10 @@ static int set_caps(struct ast_sip_session *session,
ast_codec_media_type2str(session_media->type),
ast_format_cap_get_names(caps, &usbuf),
ast_format_cap_get_names(peer, &thembuf));
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "No joint capabilities for '%s' media stream between our configuration(%s) and incoming SDP(%s)\n",
ast_codec_media_type2str(session_media->type),
ast_format_cap_get_names(caps, &usbuf),
ast_format_cap_get_names(peer, &thembuf));
}
if (is_offer) {
@ -594,7 +604,7 @@ static int set_caps(struct ast_sip_session *session,
}
ast_rtp_codecs_payloads_destroy(&codecs);
return 0;
SCOPE_EXIT_RTN_VALUE(0);
}
static pjmedia_sdp_attr* generate_rtpmap_attr(struct ast_sip_session *session, pjmedia_sdp_media *media, pj_pool_t *pool,
@ -1416,12 +1426,13 @@ static int negotiate_incoming_sdp_stream(struct ast_sip_session *session,
enum ast_sip_session_media_encryption encryption = AST_SIP_MEDIA_ENCRYPT_NONE;
struct ast_format_cap *joint;
int res;
SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(session));
/* If no type formats have been configured reject this stream */
if (!ast_format_cap_has_type(session->endpoint->media.codecs, media_type)) {
ast_debug(3, "Endpoint has no codecs for media type '%s', declining stream\n",
ast_codec_media_type2str(session_media->type));
return 0;
SCOPE_EXIT_RTN_VALUE(0, "Endpoint has no codecs\n");
}
/* Ensure incoming transport is compatible with the endpoint's configuration */
@ -1429,7 +1440,7 @@ static int negotiate_incoming_sdp_stream(struct ast_sip_session *session,
encryption = check_endpoint_media_transport(session->endpoint, stream);
if (encryption == AST_SIP_MEDIA_TRANSPORT_INVALID) {
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Incompatible transport\n");
}
}
@ -1438,12 +1449,12 @@ static int negotiate_incoming_sdp_stream(struct ast_sip_session *session,
/* Ensure that the address provided is valid */
if (ast_sockaddr_resolve(&addrs, host, PARSE_PORT_FORBID, AST_AF_UNSPEC) <= 0) {
/* The provided host was actually invalid so we error out this negotiation */
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Invalid host\n");
}
/* Using the connection information create an appropriate RTP instance */
if (!session_media->rtp && create_rtp(session, session_media, sdp)) {
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Couldn't create rtp\n");
}
process_ssrc_attributes(session, session_media, stream);
@ -1465,7 +1476,7 @@ static int negotiate_incoming_sdp_stream(struct ast_sip_session *session,
* but was not this session must fail. This must also fail if crypto was
* required in the offer but could not be set up.
*/
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Incompatible crypto\n");
}
/* There is no encryption, sad. */
session_media->encryption = AST_SIP_MEDIA_ENCRYPT_NONE;
@ -1510,10 +1521,10 @@ static int negotiate_incoming_sdp_stream(struct ast_sip_session *session,
res = apply_cap_to_bundled(session_media, session_media_transport, asterisk_stream, joint);
ao2_cleanup(joint);
if (res != 0) {
return 0;
SCOPE_EXIT_RTN_VALUE(0, "Something failed\n");
}
return 1;
SCOPE_EXIT_RTN_VALUE(1);
}
static int add_crypto_to_stream(struct ast_sip_session *session,
@ -1666,13 +1677,14 @@ static int create_outgoing_sdp_stream(struct ast_sip_session *session, struct as
enum ast_media_type media_type = session_media->type;
struct ast_sip_session_media *session_media_transport;
pj_sockaddr ip;
int direct_media_enabled = !ast_sockaddr_isnull(&session_media->direct_media_addr) &&
ast_format_cap_count(session->direct_media_cap);
SCOPE_ENTER(1, "%s Type: %s %s\n", ast_sip_session_get_name(session),
ast_codec_media_type2str(media_type), ast_str_tmp(128, ast_stream_to_str(stream, &STR_TMP)));
media = pj_pool_zalloc(pool, sizeof(struct pjmedia_sdp_media));
if (!media) {
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Pool alloc failure\n");
}
pj_strdup2(pool, &media->desc.media, ast_codec_media_type2str(session_media->type));
@ -1702,11 +1714,11 @@ static int create_outgoing_sdp_stream(struct ast_sip_session *session, struct as
sdp->media[sdp->media_count++] = media;
ast_stream_set_state(stream, AST_STREAM_STATE_REMOVED);
return 1;
SCOPE_EXIT_RTN_VALUE(1, "Stream removed or no formats\n");
}
if (!session_media->rtp && create_rtp(session, session_media, sdp)) {
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Couldn't create rtp\n");
}
/* If this stream has not been bundled already it is new and we need to ensure there is no SSRC conflict */
@ -1738,7 +1750,7 @@ static int create_outgoing_sdp_stream(struct ast_sip_session *session, struct as
* set up according to the configuration. This ends up changing the media transport.
*/
if (add_crypto_to_stream(session, session_media, pool, media)) {
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Couldn't add crypto\n");
}
if (pj_strlen(&session_media->transport)) {
@ -1755,7 +1767,7 @@ static int create_outgoing_sdp_stream(struct ast_sip_session *session, struct as
media->conn = pj_pool_zalloc(pool, sizeof(struct pjmedia_sdp_conn));
if (!media->conn) {
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Pool alloc failure\n");
}
/* Add connection level details */
@ -1770,7 +1782,7 @@ static int create_outgoing_sdp_stream(struct ast_sip_session *session, struct as
if (ast_strlen_zero(hostip)) {
ast_log(LOG_ERROR, "No local host IP available for stream %s\n",
ast_codec_media_type2str(session_media->type));
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "No local host ip\n");
}
media->conn->net_type = STR_IN;
@ -1798,7 +1810,7 @@ static int create_outgoing_sdp_stream(struct ast_sip_session *session, struct as
media->desc.port = bundle_group_stream->desc.port;
if (add_crypto_to_stream(session, session_media_transport, pool, media)) {
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Couldn't add crypto\n");
}
add_ice_to_stream(session, session_media_transport, pool, media, 0);
@ -1809,7 +1821,7 @@ static int create_outgoing_sdp_stream(struct ast_sip_session *session, struct as
if (!(caps = ast_format_cap_alloc(AST_FORMAT_CAP_FLAG_DEFAULT))) {
ast_log(LOG_ERROR, "Failed to allocate %s capabilities\n",
ast_codec_media_type2str(session_media->type));
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Couldn't create caps\n");
}
if (direct_media_enabled) {
@ -1896,7 +1908,7 @@ static int create_outgoing_sdp_stream(struct ast_sip_session *session, struct as
/* If no formats were actually added to the media stream don't add it to the SDP */
if (!media->desc.fmt_count) {
return 1;
SCOPE_EXIT_RTN_VALUE(1, "No formats added to stream\n");
}
/* If ptime is set add it as an attribute */
@ -1952,7 +1964,7 @@ static int create_outgoing_sdp_stream(struct ast_sip_session *session, struct as
/* Add the media stream to the SDP */
sdp->media[sdp->media_count++] = media;
return 1;
SCOPE_EXIT_RTN_VALUE(1, "RC: 1\n");
}
static struct ast_frame *media_session_rtp_read_callback(struct ast_sip_session *session, struct ast_sip_session_media *session_media)
@ -2010,20 +2022,22 @@ static int apply_negotiated_sdp_stream(struct ast_sip_session *session,
char host[NI_MAXHOST];
int res;
struct ast_sip_session_media *session_media_transport;
SCOPE_ENTER(1, "%s Stream: %s\n", ast_sip_session_get_name(session),
ast_str_tmp(128, ast_stream_to_str(asterisk_stream, &STR_TMP)));
if (!session->channel) {
return 1;
SCOPE_EXIT_RTN_VALUE(1, "No channel\n");
}
/* Ensure incoming transport is compatible with the endpoint's configuration */
if (!session->endpoint->media.rtp.use_received_transport &&
check_endpoint_media_transport(session->endpoint, remote_stream) == AST_SIP_MEDIA_TRANSPORT_INVALID) {
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Incompatible transport\n");
}
/* Create an RTP instance if need be */
if (!session_media->rtp && create_rtp(session, session_media, local)) {
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Couldn't create rtp\n");
}
process_ssrc_attributes(session, session_media, remote_stream);
@ -2042,11 +2056,11 @@ static int apply_negotiated_sdp_stream(struct ast_sip_session *session,
/* If optimistic encryption is disabled and crypto should have been enabled but was not
* this session must fail.
*/
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Incompatible crypto\n");
}
if (!remote_stream->conn && !remote->conn) {
return 1;
SCOPE_EXIT_RTN_VALUE(1, "No connection info\n");
}
ast_copy_pj_str(host, remote_stream->conn ? &remote_stream->conn->addr : &remote->conn->addr, sizeof(host));
@ -2054,7 +2068,7 @@ static int apply_negotiated_sdp_stream(struct ast_sip_session *session,
/* Ensure that the address provided is valid */
if (ast_sockaddr_resolve(&addrs, host, PARSE_PORT_FORBID, AST_AF_UNSPEC) <= 0) {
/* The provided host was actually invalid so we error out this negotiation */
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Host invalid\n");
}
/* Apply connection information to the RTP instance */
@ -2079,7 +2093,7 @@ static int apply_negotiated_sdp_stream(struct ast_sip_session *session,
}
if (set_caps(session, session_media, session_media_transport, remote_stream, 0, asterisk_stream)) {
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "set_caps failed\n");
}
/* Set the channel uniqueid on the RTP instance now that it is becoming active */
@ -2097,7 +2111,7 @@ static int apply_negotiated_sdp_stream(struct ast_sip_session *session,
&& (session->inv_session->state == PJSIP_INV_STATE_CONFIRMED)) {
ast_queue_control(session->channel, AST_CONTROL_UPDATE_RTP_PEER);
}
return 1;
SCOPE_EXIT_RTN_VALUE(1, "moh\n");
}
if (session_media->remotely_held_changed) {
@ -2155,7 +2169,7 @@ static int apply_negotiated_sdp_stream(struct ast_sip_session *session,
session_media, 1);
}
return 1;
SCOPE_EXIT_RTN_VALUE(1, "Handled\n");
}
/*! \brief Function which updates the media stream with external media address, if applicable */

308
res/res_pjsip_session.c
View File

@ -111,6 +111,20 @@ static int sdp_handler_list_hash(const void *obj, int flags)
return ast_str_hash(stream_type);
}
const char *ast_sip_session_get_name(const struct ast_sip_session *session)
{
if (!session) {
return "(null session)";
}
if (session->channel) {
return ast_channel_name(session->channel);
} else if (session->endpoint) {
return ast_sorcery_object_get_id(session->endpoint);
} else {
return "unknown";
}
}
static int sdp_handler_list_cmp(void *obj, void *arg, int flags)
{
struct sdp_handler_list *handler_list1 = obj;
@ -713,17 +727,18 @@ static int handle_incoming_sdp(struct ast_sip_session *session, const pjmedia_sd
int i;
int handled = 0;
int type_streams[AST_MEDIA_TYPE_END] = {0};
SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(session));
if (session->inv_session && session->inv_session->state == PJSIP_INV_STATE_DISCONNECTED) {
ast_log(LOG_ERROR, "Failed to handle incoming SDP. Session has been already disconnected\n");
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Already disconnected\n");
}
/* It is possible for SDP deferral to have already created a pending topology */
if (!session->pending_media_state->topology) {
session->pending_media_state->topology = ast_stream_topology_alloc();
if (!session->pending_media_state->topology) {
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "No topology\n");
}
}
@ -756,11 +771,11 @@ static int handle_incoming_sdp(struct ast_sip_session *session, const pjmedia_sd
stream = ast_stream_alloc(existing_stream ? ast_stream_get_name(existing_stream) : ast_codec_media_type2str(type), type);
if (!stream) {
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Couldn't create stream\n");
}
if (ast_stream_topology_set_stream(session->pending_media_state->topology, i, stream)) {
ast_stream_free(stream);
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Couldn't set stream\n");
}
if (existing_stream) {
const char *stream_label = ast_stream_get_metadata(existing_stream, "SDP:LABEL");
@ -792,7 +807,7 @@ static int handle_incoming_sdp(struct ast_sip_session *session, const pjmedia_sd
session_media = ast_sip_session_media_state_add(session, session->pending_media_state, ast_media_type_from_str(media), i);
if (!session_media) {
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Couldn't add session media\n");
}
/* If this stream is already declined mark it as such, or mark it as such if we've reached the limit */
@ -814,7 +829,7 @@ static int handle_incoming_sdp(struct ast_sip_session *session, const pjmedia_sd
res = handler->negotiate_incoming_sdp_stream(session, session_media, sdp, i, stream);
if (res < 0) {
/* Catastrophic failure. Abort! */
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Couldn't negotiate incoming sdp stream\n");
} else if (res == 0) {
ast_debug(1, "Declining incoming SDP media stream '%s' at position '%d'\n",
ast_codec_media_type2str(type), i);
@ -865,9 +880,12 @@ static int handle_incoming_sdp(struct ast_sip_session *session, const pjmedia_sd
}
}
if (!handled) {
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Not handled\n");
}
return 0;
SCOPE_EXIT_RTN_VALUE(0, "Handled. Active: %s Pending: %s\n",
ast_str_tmp(256, ast_stream_topology_to_str(session->active_media_state->topology, &STR_TMP)),
ast_str_tmp(256, ast_stream_topology_to_str(session->pending_media_state->topology, &STR_TMP))
);
}
static int handle_negotiated_sdp_session_media(struct ast_sip_session_media *session_media,
@ -880,6 +898,7 @@ static int handle_negotiated_sdp_session_media(struct ast_sip_session_media *ses
struct ast_sip_session_sdp_handler *handler;
RAII_VAR(struct sdp_handler_list *, handler_list, NULL, ao2_cleanup);
int res;
SCOPE_ENTER(1, "%s\n", session ? ast_sip_session_get_name(session) : "unknown");
/* We need a null-terminated version of the media string */
ast_copy_pj_str(media, &local->media[index]->desc.media, sizeof(media));
@ -918,15 +937,20 @@ static int handle_negotiated_sdp_session_media(struct ast_sip_session_media *ses
ast_debug(1, "Applied negotiated SDP media stream '%s' using %s SDP handler\n",
ast_codec_media_type2str(session_media->type),
handler->id);
return 0;
SCOPE_EXIT_RTN_VALUE(0, "%s: Applied negotiated SDP media stream '%s' using %s SDP handler\n",
ast_sip_session_get_name(session), ast_codec_media_type2str(session_media->type),
handler->id);
}
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "%s: Failed to apply negotiated SDP media stream '%s' using %s SDP handler\n",
ast_sip_session_get_name(session), ast_codec_media_type2str(session_media->type),
handler->id);
}
handler_list = ao2_find(sdp_handlers, media, OBJ_KEY);
if (!handler_list) {
ast_debug(1, "No registered SDP handlers for media type '%s'\n", media);
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "%s: No registered SDP handlers for media type '%s'\n",
ast_sip_session_get_name(session), media);
}
AST_LIST_TRAVERSE(&handler_list->list, handler, next) {
if (handler == session_media->handler) {
@ -938,7 +962,8 @@ static int handle_negotiated_sdp_session_media(struct ast_sip_session_media *ses
res = handler->apply_negotiated_sdp_stream(session, session_media, local, remote, index, asterisk_stream);
if (res < 0) {
/* Catastrophic failure. Abort! */
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "%s: Handler '%s' returned %d\n",
ast_sip_session_get_name(session), handler->id, res);
}
if (res > 0) {
ast_debug(1, "Applied negotiated SDP media stream '%s' using %s SDP handler\n",
@ -946,17 +971,22 @@ static int handle_negotiated_sdp_session_media(struct ast_sip_session_media *ses
handler->id);
/* Handled by this handler. Move to the next stream */
session_media_set_handler(session_media, handler);
return 0;
SCOPE_EXIT_RTN_VALUE(0, "%s: Handler '%s' handled this sdp stream\n",
ast_sip_session_get_name(session), handler->id);
}
}
res = 0;
if (session_media->handler && session_media->handler->stream_stop) {
res = 1;
ast_debug(1, "Stopping SDP media stream '%s' as it is not currently negotiated\n",
ast_codec_media_type2str(session_media->type));
session_media->handler->stream_stop(session_media);
}
return 0;
SCOPE_EXIT_RTN_VALUE(0, "%s: Media type '%s' %s\n",
ast_sip_session_get_name(session), ast_codec_media_type2str(session_media->type),
res ? "not negotiated. Stopped" : "handled");
}
static int handle_negotiated_sdp(struct ast_sip_session *session, const pjmedia_sdp_session *local, const pjmedia_sdp_session *remote)
@ -964,6 +994,7 @@ static int handle_negotiated_sdp(struct ast_sip_session *session, const pjmedia_
int i;
struct ast_stream_topology *topology;
unsigned int changed = 0; /* 0 = unchanged, 1 = new source, 2 = new topology */
SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(session));
if (!session->pending_media_state->topology) {
if (session->active_media_state->topology) {
@ -979,7 +1010,7 @@ static int handle_negotiated_sdp(struct ast_sip_session *session, const pjmedia_
if (!active_media_state_clone) {
ast_log(LOG_WARNING, "Unable to clone active media state for channel '%s'\n",
session->channel ? ast_channel_name(session->channel) : "unknown");
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Unable to clone active media state\n");
}
ast_sip_session_media_state_free(session->pending_media_state);
@ -987,7 +1018,7 @@ static int handle_negotiated_sdp(struct ast_sip_session *session, const pjmedia_
} else {
ast_log(LOG_WARNING, "No pending or active media state for channel '%s'\n",
session->channel ? ast_channel_name(session->channel) : "unknown");
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "No media state\n");
}
}
@ -1001,7 +1032,7 @@ static int handle_negotiated_sdp(struct ast_sip_session *session, const pjmedia_
ast_log(LOG_WARNING, "Local SDP for channel '%s' contains %d media streams while we expected it to contain %u\n",
session->channel ? ast_channel_name(session->channel) : "unknown",
ast_stream_topology_get_count(session->pending_media_state->topology), local->media_count);
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Media stream count mismatch\n");
}
for (i = 0; i < local->media_count; ++i) {
@ -1038,7 +1069,7 @@ static int handle_negotiated_sdp(struct ast_sip_session *session, const pjmedia_
}
if (handle_negotiated_sdp_session_media(session_media, session, local, remote, i, stream)) {
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Unable to handle negotiated session media\n");
}
changed |= session_media->changed;
@ -1118,7 +1149,7 @@ static int handle_negotiated_sdp(struct ast_sip_session *session, const pjmedia_
ast_queue_frame(session->channel, &ast_null_frame);
}
return 0;
SCOPE_EXIT_RTN_VALUE(0);
}
#define DATASTORE_BUCKETS 53
@ -1499,6 +1530,7 @@ static pjmedia_sdp_session *generate_session_refresh_sdp(struct ast_sip_session
{
pjsip_inv_session *inv_session = session->inv_session;
const pjmedia_sdp_session *previous_sdp = NULL;
SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(session));
if (inv_session->neg) {
if (pjmedia_sdp_neg_was_answer_remote(inv_session->neg)) {
@ -1507,7 +1539,7 @@ static pjmedia_sdp_session *generate_session_refresh_sdp(struct ast_sip_session
pjmedia_sdp_neg_get_active_local(inv_session->neg, &previous_sdp);
}
}
return create_local_sdp(inv_session, session, previous_sdp);
SCOPE_EXIT_RTN_VALUE(create_local_sdp(inv_session, session, previous_sdp));
}
static void set_from_header(struct ast_sip_session *session)
@ -1878,13 +1910,14 @@ int ast_sip_session_regenerate_answer(struct ast_sip_session *session,
pjsip_inv_session *inv_session = session->inv_session;
pjmedia_sdp_session *new_answer = NULL;
const pjmedia_sdp_session *previous_offer = NULL;
SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(session));
/* The SDP answer can only be regenerated if it is still pending to be sent */
if (!inv_session->neg || (pjmedia_sdp_neg_get_state(inv_session->neg) != PJMEDIA_SDP_NEG_STATE_REMOTE_OFFER &&
pjmedia_sdp_neg_get_state(inv_session->neg) != PJMEDIA_SDP_NEG_STATE_WAIT_NEGO)) {
ast_log(LOG_WARNING, "Requested to regenerate local SDP answer for channel '%s' but negotiation in state '%s'\n",
ast_channel_name(session->channel), pjmedia_sdp_neg_state_str(pjmedia_sdp_neg_get_state(inv_session->neg)));
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Bad negotiation state\n");
}
pjmedia_sdp_neg_get_neg_remote(inv_session->neg, &previous_offer);
@ -1898,18 +1931,18 @@ int ast_sip_session_regenerate_answer(struct ast_sip_session *session,
if (!new_answer) {
ast_log(LOG_WARNING, "Could not create a new local SDP answer for channel '%s'\n",
ast_channel_name(session->channel));
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Couldn't create new SDP\n");
}
if (on_sdp_creation) {
if (on_sdp_creation(session, new_answer)) {
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Callback failed\n");
}
}
pjsip_inv_set_sdp_answer(inv_session, new_answer);
return 0;
SCOPE_EXIT_RTN_VALUE(0);
}
void ast_sip_session_send_response(struct ast_sip_session *session, pjsip_tx_data *tdata)
@ -1920,11 +1953,15 @@ void ast_sip_session_send_response(struct ast_sip_session *session, pjsip_tx_dat
}
static pj_bool_t session_on_rx_request(pjsip_rx_data *rdata);
static pj_bool_t session_on_rx_response(pjsip_rx_data *rdata);
static void session_on_tsx_state(pjsip_transaction *tsx, pjsip_event *e);
static pjsip_module session_module = {
.name = {"Session Module", 14},
.priority = PJSIP_MOD_PRIORITY_APPLICATION,
.on_rx_request = session_on_rx_request,
.on_rx_response = session_on_rx_response,
.on_tsx_state = session_on_tsx_state,
};
/*! \brief Determine whether the SDP provided requires deferral of negotiating or not
@ -2226,10 +2263,11 @@ void ast_sip_session_send_request(struct ast_sip_session *session, pjsip_tx_data
int ast_sip_session_create_invite(struct ast_sip_session *session, pjsip_tx_data **tdata)
{
pjmedia_sdp_session *offer;
SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(session));
if (!(offer = create_local_sdp(session->inv_session, session, NULL))) {
pjsip_inv_terminate(session->inv_session, 500, PJ_FALSE);
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Couldn't create offer\n");
}
pjsip_inv_set_local_sdp(session->inv_session, offer);
@ -2247,10 +2285,10 @@ int ast_sip_session_create_invite(struct ast_sip_session *session, pjsip_tx_data
set_from_header(session);
if (pjsip_inv_invite(session->inv_session, tdata) != PJ_SUCCESS) {
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "pjsip_inv_invite failed\n");
}
return 0;
SCOPE_EXIT_RTN_VALUE(0);
}
static int datastore_hash(const void *obj, int flags)
@ -2668,6 +2706,8 @@ struct ast_sip_session *ast_sip_session_create_outgoing(struct ast_sip_endpoint
struct pjsip_inv_session *inv_session;
RAII_VAR(struct ast_sip_session *, session, NULL, ao2_cleanup);
struct ast_sip_session *ret_session;
SCOPE_ENTER(1, "%s %s Topology: %s\n", ast_sorcery_object_get_id(endpoint), request_user,
ast_str_tmp(256, ast_stream_topology_to_str(req_topology, &STR_TMP)));
/* If no location has been provided use the AOR list from the endpoint itself */
if (location || !contact) {
@ -2688,21 +2728,21 @@ struct ast_sip_session *ast_sip_session_create_outgoing(struct ast_sip_endpoint
if (ast_strlen_zero(uri)) {
ast_log(LOG_ERROR, "Endpoint '%s': No URI available. Is endpoint registered?\n",
ast_sorcery_object_get_id(endpoint));
return NULL;
SCOPE_EXIT_RTN_VALUE(NULL, "No URI\n");
}
if (!(dlg = ast_sip_create_dialog_uac(endpoint, uri, request_user))) {
return NULL;
SCOPE_EXIT_RTN_VALUE(NULL, "Couldn't create dialog\n");
}
if (setup_outbound_invite_auth(dlg)) {
pjsip_dlg_terminate(dlg);
return NULL;
SCOPE_EXIT_RTN_VALUE(NULL, "Couldn't setup auth\n");
}
if (pjsip_inv_create_uac(dlg, NULL, endpoint->extensions.flags, &inv_session) != PJ_SUCCESS) {
pjsip_dlg_terminate(dlg);
return NULL;
SCOPE_EXIT_RTN_VALUE(NULL, "Couldn't create uac\n");
}
#if defined(HAVE_PJSIP_REPLACE_MEDIA_STREAM) || defined(PJMEDIA_SDP_NEG_ALLOW_MEDIA_CHANGE)
inv_session->sdp_neg_flags = PJMEDIA_SDP_NEG_ALLOW_MEDIA_CHANGE;
@ -2749,7 +2789,7 @@ struct ast_sip_session *ast_sip_session_create_outgoing(struct ast_sip_endpoint
if (!session->pending_media_state->topology) {
pjsip_inv_terminate(inv_session, 500, PJ_FALSE);
ao2_ref(session, -1);
return NULL;
SCOPE_EXIT_RTN_VALUE(NULL, "Couldn't create topology\n");
}
}
@ -2766,7 +2806,7 @@ struct ast_sip_session *ast_sip_session_create_outgoing(struct ast_sip_endpoint
if (!session->pending_media_state->topology) {
pjsip_inv_terminate(inv_session, 500, PJ_FALSE);
ao2_ref(session, -1);
return NULL;
SCOPE_EXIT_RTN_VALUE(NULL, "Couldn't clone topology\n");
}
}
@ -2776,13 +2816,13 @@ struct ast_sip_session *ast_sip_session_create_outgoing(struct ast_sip_endpoint
* we need to manually drop its reference to session
*/
ao2_ref(session, -1);
return NULL;
SCOPE_EXIT_RTN_VALUE(NULL, "Couldn't add usage\n");
}
/* Avoid unnecessary ref manipulation to return a session */
ret_session = session;
session = NULL;
return ret_session;
SCOPE_EXIT_RTN_VALUE(ret_session);
}
static int session_end(void *vsession);
@ -2792,10 +2832,11 @@ void ast_sip_session_terminate(struct ast_sip_session *session, int response)
{
pj_status_t status;
pjsip_tx_data *packet = NULL;
SCOPE_ENTER(1, "%s Response %d\n", ast_sip_session_get_name(session), response);
if (session->defer_terminate) {
session->terminate_while_deferred = 1;
return;
SCOPE_EXIT_RTN("Deferred\n");
}
if (!response) {
@ -2863,6 +2904,7 @@ void ast_sip_session_terminate(struct ast_sip_session *session, int response)
}
break;
}
SCOPE_EXIT_RTN();
}
static int session_termination_task(void *data)
@ -3175,6 +3217,7 @@ static int new_invite(struct new_invite *invite)
pjsip_rdata_sdp_info *sdp_info;
pjmedia_sdp_session *local = NULL;
char buffer[AST_SOCKADDR_BUFLEN];
SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(invite->session));
/* From this point on, any calls to pjsip_inv_terminate have the last argument as PJ_TRUE
* so that we will be notified so we can destroy the session properly
@ -3187,7 +3230,7 @@ static int new_invite(struct new_invite *invite)
#ifdef HAVE_PJSIP_INV_SESSION_REF
pjsip_inv_dec_ref(invite->session->inv_session);
#endif
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Already disconnected\n");
}
switch (get_destination(invite->session, invite->rdata)) {
@ -3297,7 +3340,10 @@ end:
#ifdef HAVE_PJSIP_INV_SESSION_REF
pjsip_inv_dec_ref(invite->session->inv_session);
#endif
return 0;
SCOPE_EXIT_RTN_VALUE(0, "Handled. Active: %s Pending: %s\n",
ast_str_tmp(256, ast_stream_topology_to_str(invite->session->active_media_state->topology, &STR_TMP)),
ast_str_tmp(256, ast_stream_topology_to_str(invite->session->pending_media_state->topology, &STR_TMP))
);
}
static void handle_new_invite_request(pjsip_rx_data *rdata)
@ -3308,13 +3354,16 @@ static void handle_new_invite_request(pjsip_rx_data *rdata)
pjsip_inv_session *inv_session = NULL;
struct ast_sip_session *session;
struct new_invite invite;
char *req_uri = TRACE_ATLEAST(1) ? ast_alloca(256) : "";
int res = TRACE_ATLEAST(1) ? pjsip_uri_print(PJSIP_URI_IN_REQ_URI, rdata->msg_info.msg->line.req.uri, req_uri, 256) : 0;
SCOPE_ENTER(1, "Request: %s\n", res ? req_uri : "");
ast_assert(endpoint != NULL);
inv_session = pre_session_setup(rdata, endpoint);
if (!inv_session) {
/* pre_session_setup() returns a response on failure */
return;
SCOPE_EXIT_RTN("Failure in pre session setup\n");
}
#ifdef HAVE_PJSIP_INV_SESSION_REF
@ -3327,7 +3376,7 @@ static void handle_new_invite_request(pjsip_rx_data *rdata)
pjsip_inv_send_msg(inv_session, tdata);
}
}
return;
SCOPE_EXIT_RTN("Couldn't add invite session reference\n");
}
#endif
@ -3341,7 +3390,7 @@ static void handle_new_invite_request(pjsip_rx_data *rdata)
#ifdef HAVE_PJSIP_INV_SESSION_REF
pjsip_inv_dec_ref(inv_session);
#endif
return;
SCOPE_EXIT_RTN("Couldn't create session\n");
}
session->call_direction = AST_SIP_SESSION_INCOMING_CALL;
@ -3356,6 +3405,7 @@ static void handle_new_invite_request(pjsip_rx_data *rdata)
invite.rdata = rdata;
new_invite(&invite);
SCOPE_EXIT("Request: %s Session: %s\n", req_uri, ast_sip_session_get_name(session));
ao2_ref(session, -1);
}
@ -3388,6 +3438,46 @@ static pj_bool_t has_supplement(const struct ast_sip_session *session, const pjs
}
return PJ_FALSE;
}
/*!
* \internal
* Added for debugging purposes
*/
static void session_on_tsx_state(pjsip_transaction *tsx, pjsip_event *e)
{
pjsip_dialog *dlg = pjsip_tsx_get_dlg(tsx);
pjsip_inv_session *inv_session = (dlg ? pjsip_dlg_get_inv_session(dlg) : NULL);
struct ast_sip_session *session = (inv_session ? inv_session->mod_data[session_module.id] : NULL);
SCOPE_ENTER(1, "%s TSX State: %s Inv State: %s\n", ast_sip_session_get_name(session),
pjsip_tsx_state_str(tsx->state), inv_session ? pjsip_inv_state_name(inv_session->state) : "unknown");
if (session) {
ast_trace(2, "Topology: Pending: %s Active: %s\n",
ast_str_tmp(256, ast_stream_topology_to_str(session->pending_media_state->topology, &STR_TMP)),
ast_str_tmp(256, ast_stream_topology_to_str(session->active_media_state->topology, &STR_TMP)));
}
SCOPE_EXIT_RTN();
}
/*!
* \internal
* Added for debugging purposes
*/
static pj_bool_t session_on_rx_response(pjsip_rx_data *rdata)
{
struct pjsip_status_line status = rdata->msg_info.msg->line.status;
pjsip_dialog *dlg = pjsip_rdata_get_dlg(rdata);
pjsip_inv_session *inv_session = pjsip_dlg_get_inv_session(dlg);
struct ast_sip_session *session = (inv_session ? inv_session->mod_data[session_module.id] : NULL);
SCOPE_ENTER(1, "%s Method: %.*s Status: %d\n", ast_sip_session_get_name(session),
(int)rdata->msg_info.cseq->method.name.slen, rdata->msg_info.cseq->method.name.ptr, status.code);
SCOPE_EXIT_RTN_VALUE(PJ_FALSE);
}
/*!
* \brief Called when a new SIP request comes into PJSIP
*
@ -3408,10 +3498,16 @@ static pj_bool_t has_supplement(const struct ast_sip_session *session, const pjs
static pj_bool_t session_on_rx_request(pjsip_rx_data *rdata)
{
pj_status_t handled = PJ_FALSE;
struct pjsip_request_line req = rdata->msg_info.msg->line.req;
pjsip_dialog *dlg = pjsip_rdata_get_dlg(rdata);
pjsip_inv_session *inv_session;
pjsip_inv_session *inv_session = (dlg ? pjsip_dlg_get_inv_session(dlg) : NULL);
struct ast_sip_session *session = (inv_session ? inv_session->mod_data[session_module.id] : NULL);
char *req_uri = TRACE_ATLEAST(1) ? ast_alloca(256) : "";
int res = TRACE_ATLEAST(1) ? pjsip_uri_print(PJSIP_URI_IN_REQ_URI, rdata->msg_info.msg->line.req.uri, req_uri, 256) : 0;
SCOPE_ENTER(1, "%s Request: %.*s %s\n", ast_sip_session_get_name(session),
(int) pj_strlen(&req.method.name), pj_strbuf(&req.method.name), res ? req_uri : "");
switch (rdata->msg_info.msg->line.req.method.id) {
switch (req.method.id) {
case PJSIP_INVITE_METHOD:
if (dlg) {
ast_log(LOG_WARNING, "on_rx_request called for INVITE in mid-dialog?\n");
@ -3427,7 +3523,9 @@ static pj_bool_t session_on_rx_request(pjsip_rx_data *rdata)
break;
}
return handled;
SCOPE_EXIT_RTN_VALUE(handled, "%s Handled request %.*s %s ? %s\n", ast_sip_session_get_name(session),
(int) pj_strlen(&req.method.name), pj_strbuf(&req.method.name), req_uri,
handled == PJ_TRUE ? "yes" : "no");
}
static void resend_reinvite(pj_timer_heap_t *timer, pj_timer_entry *entry)
@ -3541,6 +3639,8 @@ static void handle_incoming_request(struct ast_sip_session *session, pjsip_rx_da
{
struct ast_sip_session_supplement *supplement;
struct pjsip_request_line req = rdata->msg_info.msg->line.req;
SCOPE_ENTER(1, "%s Method: %.*s\n", ast_sip_session_get_name(session),
(int) pj_strlen(&req.method.name), pj_strbuf(&req.method.name));
ast_debug(3, "Method is %.*s\n", (int) pj_strlen(&req.method.name), pj_strbuf(&req.method.name));
AST_LIST_TRAVERSE(&session->supplements, supplement, next) {
@ -3550,6 +3650,8 @@ static void handle_incoming_request(struct ast_sip_session *session, pjsip_rx_da
}
}
}
SCOPE_EXIT_RTN();
}
static void handle_session_begin(struct ast_sip_session *session)
@ -3591,6 +3693,10 @@ static void handle_incoming_response(struct ast_sip_session *session, pjsip_rx_d
{
struct ast_sip_session_supplement *supplement;
struct pjsip_status_line status = rdata->msg_info.msg->line.status;
SCOPE_ENTER(1, "%s Method: %.*s Status: %d Priority %s\n", ast_sip_session_get_name(session),
(int)rdata->msg_info.cseq->method.name.slen, rdata->msg_info.cseq->method.name.ptr,
rdata->msg_info.msg->line.status.code,
response_priority == AST_SIP_SESSION_AFTER_MEDIA ? "after" : "before");
ast_debug(3, "Response is %d %.*s\n", status.code, (int) pj_strlen(&status.reason),
pj_strbuf(&status.reason));
@ -3603,11 +3709,14 @@ static void handle_incoming_response(struct ast_sip_session *session, pjsip_rx_d
supplement->incoming_response(session, rdata);
}
}
SCOPE_EXIT_RTN();
}
static int handle_incoming(struct ast_sip_session *session, pjsip_rx_data *rdata,
enum ast_sip_session_response_priority response_priority)
{
SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(session));
ast_debug(3, "Received %s\n", rdata->msg_info.msg->type == PJSIP_REQUEST_MSG ?
"request" : "response");
@ -3617,13 +3726,16 @@ static int handle_incoming(struct ast_sip_session *session, pjsip_rx_data *rdata
handle_incoming_response(session, rdata, response_priority);
}
return 0;
SCOPE_EXIT_RTN_VALUE(0);
}
static void handle_outgoing_request(struct ast_sip_session *session, pjsip_tx_data *tdata)
{
struct ast_sip_session_supplement *supplement;
struct pjsip_request_line req = tdata->msg->line.req;
SCOPE_ENTER(1, "%s Method: %.*s\n", ast_sip_session_get_name(session),
(int) pj_strlen(&req.method.name),
pj_strbuf(&req.method.name));
ast_debug(3, "Method is %.*s\n", (int) pj_strlen(&req.method.name), pj_strbuf(&req.method.name));
@ -3634,6 +3746,8 @@ static void handle_outgoing_request(struct ast_sip_session *session, pjsip_tx_da
supplement->outgoing_request(session, tdata);
}
}
SCOPE_EXIT_RTN();
}
static void handle_outgoing_response(struct ast_sip_session *session, pjsip_tx_data *tdata)
@ -3641,10 +3755,14 @@ static void handle_outgoing_response(struct ast_sip_session *session, pjsip_tx_d
struct ast_sip_session_supplement *supplement;
struct pjsip_status_line status = tdata->msg->line.status;
pjsip_cseq_hdr *cseq = pjsip_msg_find_hdr(tdata->msg, PJSIP_H_CSEQ, NULL);
SCOPE_ENTER(1, "%s Method is %.*s, Response is %d %.*s\n", ast_sip_session_get_name(session),
(int) pj_strlen(&cseq->method.name),
pj_strbuf(&cseq->method.name), status.code, (int) pj_strlen(&status.reason),
pj_strbuf(&status.reason));
if (!cseq) {
ast_log(LOG_ERROR, "Cannot send response due to missing sequence header");
return;
SCOPE_EXIT_RTN("Missing cseq\n");
}
ast_debug(3, "Method is %.*s, Response is %d %.*s\n", (int) pj_strlen(&cseq->method.name),
@ -3658,6 +3776,8 @@ static void handle_outgoing_response(struct ast_sip_session *session, pjsip_tx_d
supplement->outgoing_response(session, tdata);
}
}
SCOPE_EXIT_RTN();
}
static int session_end(void *vsession)
@ -3722,6 +3842,7 @@ static void handle_incoming_before_media(pjsip_inv_session *inv,
struct ast_sip_session *session, pjsip_rx_data *rdata)
{
pjsip_msg *msg;
SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(session));
handle_incoming(session, rdata, AST_SIP_SESSION_BEFORE_MEDIA);
msg = rdata->msg_info.msg;
@ -3746,15 +3867,19 @@ static void handle_incoming_before_media(pjsip_inv_session *inv,
ast_sip_session_send_request(session, tdata);
}
}
SCOPE_EXIT_RTN();
}
static void session_inv_on_state_changed(pjsip_inv_session *inv, pjsip_event *e)
{
struct ast_sip_session *session;
pjsip_event_id_e type;
struct ast_sip_session *session = inv->mod_data[session_module.id];
SCOPE_ENTER(1, "%s Event: %s Inv State: %s\n", ast_sip_session_get_name(session),
pjsip_event_str(e->type), pjsip_inv_state_name(inv->state));
if (ast_shutdown_final()) {
return;
SCOPE_EXIT_RTN("Shutting down\n");
}
if (e) {
@ -3766,7 +3891,7 @@ static void session_inv_on_state_changed(pjsip_inv_session *inv, pjsip_event *e)
session = inv->mod_data[session_module.id];
if (!session) {
return;
SCOPE_EXIT_RTN("No session\n");
}
switch(type) {
@ -3814,7 +3939,7 @@ static void session_inv_on_state_changed(pjsip_inv_session *inv, pjsip_event *e)
if (session->defer_end) {
ast_debug(3, "Deferring session (%p) end\n", session);
session->ended_while_deferred = 1;
return;
SCOPE_EXIT_RTN("Deferring\n");
}
if (ast_sip_push_task(session->serializer, session_end, session)) {
@ -3822,6 +3947,8 @@ static void session_inv_on_state_changed(pjsip_inv_session *inv, pjsip_event *e)
session_end(session);
}
}
SCOPE_EXIT_RTN();
}
static void session_inv_on_new_session(pjsip_inv_session *inv, pjsip_event *e)
@ -3863,11 +3990,13 @@ static void session_inv_on_tsx_state_changed(pjsip_inv_session *inv, pjsip_trans
{
ast_sip_session_response_cb cb;
int id = session_module.id;
struct ast_sip_session *session;
pjsip_tx_data *tdata;
struct ast_sip_session *session = inv->mod_data[session_module.id];
SCOPE_ENTER(1, "%s TSX State: %s Inv State: %s\n", ast_sip_session_get_name(session),
pjsip_tsx_state_str(tsx->state), pjsip_inv_state_name(inv->state));
if (ast_shutdown_final()) {
return;
SCOPE_EXIT_RTN("Shutting down\n");
}
session = inv->mod_data[id];
@ -3875,7 +4004,7 @@ static void session_inv_on_tsx_state_changed(pjsip_inv_session *inv, pjsip_trans
print_debug_details(inv, tsx, e);
if (!session) {
/* The session has ended. Ignore the transaction change. */
return;
SCOPE_EXIT_RTN("Session ended\n");
}
/*
@ -3885,7 +4014,7 @@ static void session_inv_on_tsx_state_changed(pjsip_inv_session *inv, pjsip_trans
* state but the BYE request transaction has not yet completed.
*/
if (tsx->method.id != PJSIP_BYE_METHOD && session_end_if_disconnected(id, inv)) {
return;
SCOPE_EXIT_RTN("Disconnected\n");
}
switch (e->body.tsx_state.type) {
@ -3915,7 +4044,7 @@ static void session_inv_on_tsx_state_changed(pjsip_inv_session *inv, pjsip_trans
/* This means we got a non 2XX final response to our outgoing INVITE */
if (tsx->status_code == PJSIP_SC_REQUEST_PENDING) {
reschedule_reinvite(session, cb);
return;
SCOPE_EXIT_RTN("Non 2XX final response\n");
}
if (inv->state == PJSIP_INV_STATE_CONFIRMED) {
ast_debug(1, "reINVITE received final response code %d\n",
@ -3926,7 +4055,7 @@ static void session_inv_on_tsx_state_changed(pjsip_inv_session *inv, pjsip_trans
e->body.tsx_state.src.rdata, tsx->last_tx, &tdata)) {
/* Send authed reINVITE */
ast_sip_session_send_request_with_cb(session, tdata, cb);
return;
SCOPE_EXIT_RTN("Sending authed reinvite\n");
}
if (tsx->status_code != 488 && tsx->status_code != 500) {
/* Other reinvite failures (except 488 and 500) result in destroying the session. */
@ -3956,7 +4085,7 @@ static void session_inv_on_tsx_state_changed(pjsip_inv_session *inv, pjsip_trans
session->channel ? ast_channel_name(session->channel) : "",
pjsip_rx_data_get_info(e->body.tsx_state.src.rdata));
pjsip_inv_end_session(session->inv_session, 503, NULL, &tdata);
return;
SCOPE_EXIT_RTN("Incomplete SDP negotiation\n");
}
if (inv->cancelling && tsx->status_code == PJSIP_SC_OK) {
@ -4017,7 +4146,8 @@ static void session_inv_on_tsx_state_changed(pjsip_inv_session *inv, pjsip_trans
e->body.tsx_state.src.rdata, tsx->last_tx, &tdata)) {
/* Send authed version of the method */
ast_sip_session_send_request_with_cb(session, tdata, cb);
return;
SCOPE_EXIT_RTN("Sending authed %.*s\n",
(int) pj_strlen(&tsx->method.name), pj_strbuf(&tsx->method.name));
}
}
}
@ -4033,7 +4163,7 @@ static void session_inv_on_tsx_state_changed(pjsip_inv_session *inv, pjsip_trans
* by the session serializer.
*/
if (session_end_if_disconnected(id, inv)) {
return;
SCOPE_EXIT_RTN("Disconnected\n");
}
break;
case PJSIP_EVENT_USER:
@ -4045,7 +4175,7 @@ static void session_inv_on_tsx_state_changed(pjsip_inv_session *inv, pjsip_trans
if (AST_LIST_EMPTY(&session->delayed_requests)) {
/* No delayed request pending, so just return */
return;
SCOPE_EXIT_RTN("Nothing delayed\n");
}
if (tsx->method.id == PJSIP_INVITE_METHOD) {
@ -4076,6 +4206,8 @@ static void session_inv_on_tsx_state_changed(pjsip_inv_session *inv, pjsip_trans
pjsip_tsx_state_str(tsx->state));
check_delayed_requests(session, update_completed);
}
SCOPE_EXIT_RTN();
}
static int add_sdp_streams(struct ast_sip_session_media *session_media,
@ -4085,20 +4217,22 @@ static int add_sdp_streams(struct ast_sip_session_media *session_media,
{
struct ast_sip_session_sdp_handler *handler = session_media->handler;
RAII_VAR(struct sdp_handler_list *, handler_list, NULL, ao2_cleanup);
int res;
int res = 0;
SCOPE_ENTER(1, "%s Stream: %s\n", ast_sip_session_get_name(session),
ast_str_tmp(128, ast_stream_to_str(stream, &STR_TMP)));
if (handler) {
/* if an already assigned handler reports a catastrophic error, fail */
res = handler->create_outgoing_sdp_stream(session, session_media, answer, remote, stream);
if (res < 0) {
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Coudn't create sdp stream\n");
}
return 0;
SCOPE_EXIT_RTN_VALUE(0, "Had handler\n");
}
handler_list = ao2_find(sdp_handlers, ast_codec_media_type2str(session_media->type), OBJ_KEY);
if (!handler_list) {
return 0;
SCOPE_EXIT_RTN_VALUE(0, "No handlers\n");
}
/* no handler for this stream type and we have a list to search */
@ -4109,17 +4243,17 @@ static int add_sdp_streams(struct ast_sip_session_media *session_media,
res = handler->create_outgoing_sdp_stream(session, session_media, answer, remote, stream);
if (res < 0) {
/* catastrophic error */
return -1;
SCOPE_EXIT_RTN_VALUE(-1, "Coudn't create sdp stream\n");
}
if (res > 0) {
/* Handled by this handler. Move to the next stream */
session_media_set_handler(session_media, handler);
return 0;
SCOPE_EXIT_RTN_VALUE(0, "Handled\n");
}
}
/* streams that weren't handled won't be included in generated outbound SDP */
return 0;
SCOPE_EXIT_RTN_VALUE(0, "Not handled\n");
}
/*! \brief Bundle group building structure */
@ -4208,14 +4342,16 @@ static struct pjmedia_sdp_session *create_local_sdp(pjsip_inv_session *inv, stru
pjmedia_sdp_session *local;
int i;
int stream;
SCOPE_ENTER(1, "%s Topology: %s\n", ast_sip_session_get_name(session),
ast_str_tmp(256, ast_stream_topology_to_str(session->pending_media_state->topology, &STR_TMP)));
if (inv->state == PJSIP_INV_STATE_DISCONNECTED) {
ast_log(LOG_ERROR, "Failed to create session SDP. Session has been already disconnected\n");
return NULL;
SCOPE_EXIT_RTN_VALUE(NULL, "Disconnected\n");
}
if (!inv->pool_prov || !(local = PJ_POOL_ZALLOC_T(inv->pool_prov, pjmedia_sdp_session))) {
return NULL;
SCOPE_EXIT_RTN_VALUE(NULL, "Pool alloc failure\n");
}
if (!offer) {
@ -4240,7 +4376,7 @@ static struct pjmedia_sdp_session *create_local_sdp(pjsip_inv_session *inv, stru
session->pending_media_state->topology = ast_stream_topology_clone(session->endpoint->media.topology);
}
if (!session->pending_media_state->topology) {
return NULL;
SCOPE_EXIT_RTN_VALUE(NULL, "No pending topology\n");
}
}
@ -4257,11 +4393,11 @@ static struct pjmedia_sdp_session *create_local_sdp(pjsip_inv_session *inv, stru
session_media = ast_sip_session_media_state_add(session, session->pending_media_state, ast_stream_get_type(stream), i);
if (!session_media) {
return NULL;
SCOPE_EXIT_RTN_VALUE(NULL, "Couldn't add state\n");
}
if (add_sdp_streams(session_media, session, local, offer, stream)) {
return NULL;
SCOPE_EXIT_RTN_VALUE(NULL, "Couldn't add stream\n");
}
/* If a stream was actually added then add any additional details */
@ -4285,7 +4421,7 @@ static struct pjmedia_sdp_session *create_local_sdp(pjsip_inv_session *inv, stru
/* Add any bundle groups that are present on the media state */
if (add_bundle_groups(session, inv->pool_prov, local)) {
return NULL;
SCOPE_EXIT_RTN_VALUE(NULL, "Couldn't add bundled\n");
}
/* Use the connection details of an available media if possible for SDP level */
@ -4327,27 +4463,31 @@ static struct pjmedia_sdp_session *create_local_sdp(pjsip_inv_session *inv, stru
pj_strassign(&local->origin.addr_type, &local->conn->addr_type);
pj_strassign(&local->origin.addr, &local->conn->addr);
return local;
SCOPE_EXIT_RTN_VALUE(local);
}
static void session_inv_on_rx_offer(pjsip_inv_session *inv, const pjmedia_sdp_session *offer)
{
struct ast_sip_session *session;
pjmedia_sdp_session *answer;
struct ast_sip_session *session = inv->mod_data[session_module.id];
SCOPE_ENTER(1, "%s Inv State: %s\n", ast_sip_session_get_name(session),
pjsip_inv_state_name(inv->state));
if (ast_shutdown_final()) {
return;
SCOPE_EXIT_RTN("Shutting down\n");
}
session = inv->mod_data[session_module.id];
if (handle_incoming_sdp(session, offer)) {
ast_sip_session_media_state_reset(session->pending_media_state);
return;
SCOPE_EXIT_RTN("Couldn't handle sdp\n");
}
if ((answer = create_local_sdp(inv, session, offer))) {
pjsip_inv_set_sdp_answer(inv, answer);
}
SCOPE_EXIT_RTN();
}
#if 0
@ -4359,11 +4499,13 @@ static void session_inv_on_create_offer(pjsip_inv_session *inv, pjmedia_sdp_sess
static void session_inv_on_media_update(pjsip_inv_session *inv, pj_status_t status)
{
struct ast_sip_session *session;
const pjmedia_sdp_session *local, *remote;
struct ast_sip_session *session = inv->mod_data[session_module.id];
SCOPE_ENTER(1, "%s Inv State: %s\n", ast_sip_session_get_name(session),
pjsip_inv_state_name(inv->state));
if (ast_shutdown_final()) {
return;
SCOPE_EXIT_RTN("Shutting down\n");
}
session = inv->mod_data[session_module.id];
@ -4373,7 +4515,7 @@ static void session_inv_on_media_update(pjsip_inv_session *inv, pj_status_t stat
* don't care about media updates.
* Just ignore
*/
return;
SCOPE_EXIT_RTN("No session or channel\n");
}
if (session->endpoint) {
@ -4408,7 +4550,7 @@ static void session_inv_on_media_update(pjsip_inv_session *inv, pj_status_t stat
}
#endif
if (bail) {
return;
SCOPE_EXIT_RTN("Bail\n");
}
}
@ -4417,12 +4559,14 @@ static void session_inv_on_media_update(pjsip_inv_session *inv, pj_status_t stat
ast_channel_hangupcause_set(session->channel, AST_CAUSE_BEARERCAPABILITY_NOTAVAIL);
ast_set_hangupsource(session->channel, ast_channel_name(session->channel), 0);
ast_queue_hangup(session->channel);
return;
SCOPE_EXIT_RTN("Couldn't get active local\n");return;
}
if (handle_negotiated_sdp(session, local, remote)) {
ast_sip_session_media_state_reset(session->pending_media_state);
}
SCOPE_EXIT_RTN();
}
static pjsip_redirect_op session_inv_on_redirected(pjsip_inv_session *inv, const pjsip_uri *target, const pjsip_event *e)