debugging: Add enough to choke a mule

Added to:
 * bridges/bridge_softmix.c
 * channels/chan_pjsip.c
 * include/asterisk/res_pjsip_session.h
 * main/channel.c
 * res/res_pjsip_session.c

There NO functional changes in this commit.

Change-Id: I06af034d1ff3ea1feb56596fd7bd6d7939dfdcc3
This commit is contained in:
George Joseph
2020-08-20 14:09:25 -06:00
parent d4f3b17dd3
commit ad4f2a8c99
5 changed files with 413 additions and 277 deletions

View File

@@ -1585,8 +1585,11 @@ 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);
SCOPE_ENTER(3, "%s: Received response code %d. PT: %s AT: %s\n", ast_sip_session_get_name(session),
rdata->msg_info.msg->line.status.code,
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)));
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
@@ -1594,27 +1597,33 @@ static int on_topology_change_response(struct ast_sip_session *session, pjsip_rx
*/
if (session->channel) {
ast_queue_control(session->channel, AST_CONTROL_STREAM_TOPOLOGY_CHANGED);
SCOPE_EXIT_RTN_VALUE(0, "%s: Queued topology change frame\n", ast_sip_session_get_name(session));
}
SCOPE_EXIT_RTN_VALUE(0, "%s: No channel? Can't queue topology change frame\n", ast_sip_session_get_name(session));
} else if (300 <= rdata->msg_info.msg->line.status.code) {
/* The topology change failed, so drop the current pending media state */
ast_sip_session_media_state_reset(session->pending_media_state);
SCOPE_EXIT_RTN_VALUE(0, "%s: response code > 300. Resetting pending media state\n", ast_sip_session_get_name(session));
}
SCOPE_EXIT_RTN_VALUE(0);
SCOPE_EXIT_RTN_VALUE(0, "%s: Nothing to do\n", ast_sip_session_get_name(session));
}
static int send_topology_change_refresh(void *data)
{
struct topology_change_refresh_data *refresh_data = data;
struct ast_sip_session *session = refresh_data->session;
int ret;
SCOPE_ENTER(1, "%s\n", ast_sip_session_get_name(refresh_data->session));
SCOPE_ENTER(3, "%s: %s\n", ast_sip_session_get_name(session),
ast_str_tmp(256, ast_stream_topology_to_str(refresh_data->media_state->topology, &STR_TMP)));
ret = ast_sip_session_refresh(refresh_data->session, NULL, NULL, on_topology_change_response,
ret = ast_sip_session_refresh(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);
SCOPE_EXIT_RTN_VALUE(ret, "RC: %d\n", ret);
SCOPE_EXIT_RTN_VALUE(ret, "%s\n", ast_sip_session_get_name(session));
}
static int handle_topology_request_change(struct ast_sip_session *session,
@@ -1647,10 +1656,15 @@ 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));
struct ast_frame f = {
.frametype = AST_FRAME_CONTROL,
.subclass = {
.integer = condition
}
};
char condition_name[256];
SCOPE_ENTER(3, "%s: Indicated %s\n", ast_channel_name(ast),
ast_frame_subclass2str(&f, condition_name, sizeof(condition_name), NULL, 0));
switch (condition) {
case AST_CONTROL_RINGING:
@@ -1755,9 +1769,9 @@ static int chan_pjsip_indicate(struct ast_channel *ast, int condition, const voi
ao2_ref(channel->session, +1);
#ifdef HAVE_PJSIP_INV_SESSION_REF
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);
SCOPE_EXIT_RTN_VALUE(-1, "Couldn't increase the session reference counter\n");
SCOPE_EXIT_LOG_RTN_VALUE(-1, LOG_ERROR, "%s: Couldn't increase the session reference counter\n",
ast_channel_name(ast));
}
#endif
if (ast_sip_push_task(channel->session->serializer, update_connected_line_information, channel->session)) {
@@ -1847,6 +1861,8 @@ static int chan_pjsip_indicate(struct ast_channel *ast, int condition, const voi
break;
case AST_CONTROL_STREAM_TOPOLOGY_REQUEST_CHANGE:
topology = data;
ast_trace(-1, "%s: New topology: %s\n", ast_channel_name(ast),
ast_str_tmp(256, ast_stream_topology_to_str(topology, &STR_TMP)));
res = handle_topology_request_change(channel->session, topology);
break;
case AST_CONTROL_STREAM_TOPOLOGY_CHANGED:
@@ -1866,18 +1882,17 @@ 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) {
SCOPE_EXIT_RTN_VALUE(-1, "Couldn't create indicate data\n");
SCOPE_EXIT_LOG_RTN_VALUE(-1, LOG_ERROR, "%s: Couldn't alloc indicate data\n", ast_channel_name(ast));
}
#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);
SCOPE_EXIT_RTN_VALUE(-1, "Couldn't increase the session reference counter\n");
SCOPE_EXIT_LOG_RTN_VALUE(-1, LOG_ERROR, "%s: Couldn't increase the session reference counter\n", ast_channel_name(ast));
}
#endif
if (ast_sip_push_task(channel->session->serializer, indicate, ind_data)) {
ast_log(LOG_NOTICE, "Cannot send response code %d to endpoint %s. Could not queue task properly\n",
response_code, ast_sorcery_object_get_id(channel->session->endpoint));
ast_log(LOG_ERROR, "%s: Cannot send response code %d to endpoint %s. Could not queue task properly\n",
ast_channel_name(ast), response_code, ast_sorcery_object_get_id(channel->session->endpoint));
#ifdef HAVE_PJSIP_INV_SESSION_REF
pjsip_inv_dec_ref(ind_data->session->inv_session);
#endif
@@ -1886,7 +1901,7 @@ static int chan_pjsip_indicate(struct ast_channel *ast, int condition, const voi
}
}
SCOPE_EXIT_RTN_VALUE(res, "RC: %d\n", res);
SCOPE_EXIT_RTN_VALUE(res, "%s\n", ast_channel_name(ast));
}
struct transfer_data {
@@ -3079,10 +3094,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));
SCOPE_ENTER(3, "%s\n", ast_sip_session_get_name(session));
if (session->channel) {
SCOPE_EXIT_RTN_VALUE(0, "Already have channel\n");
SCOPE_EXIT_RTN_VALUE(0, "%s: No channel\n", ast_sip_session_get_name(session));
}
/* Check for a to-tag to determine if this is a reinvite */
@@ -3098,17 +3113,17 @@ static int chan_pjsip_incoming_request(struct ast_sip_session *session, struct p
*/
session->defer_terminate = 0;
ast_sip_session_terminate(session, 400);
SCOPE_EXIT_RTN_VALUE(-1, "Reinvite without channel\n");
SCOPE_EXIT_RTN_VALUE(-1, "%s: We have a To tag but no channel. Terminating session\n", ast_sip_session_get_name(session));
}
datastore = ast_sip_session_alloc_datastore(&transport_info, "transport_info");
if (!datastore) {
SCOPE_EXIT_RTN_VALUE(-1, "Couldn't create datastore\n");
SCOPE_EXIT_LOG_RTN_VALUE(-1, LOG_ERROR, "%s: Couldn't alloc transport_info datastore\n", ast_sip_session_get_name(session));
}
transport_data = ast_calloc(1, sizeof(*transport_data));
if (!transport_data) {
SCOPE_EXIT_RTN_VALUE(-1, "Couldn't create transport_data\n");
SCOPE_EXIT_LOG_RTN_VALUE(-1, LOG_ERROR, "%s: Couldn't alloc transport_info\n", ast_sip_session_get_name(session));
}
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);
@@ -3121,12 +3136,12 @@ static int chan_pjsip_incoming_request(struct ast_sip_session *session, struct p
ast_sip_session_send_response(session, packet);
}
ast_log(LOG_ERROR, "Failed to allocate new PJSIP channel on incoming SIP INVITE\n");
SCOPE_EXIT_RTN_VALUE(-1, "Couldn't create channel\n");
SCOPE_EXIT_LOG_RTN_VALUE(-1, LOG_ERROR, "%s: Failed to allocate new PJSIP channel on incoming SIP INVITE\n",
ast_sip_session_get_name(session));
}
/* channel gets created on incoming request, but we wait to call start
so other supplements have a chance to run */
SCOPE_EXIT_RTN_VALUE(0);
SCOPE_EXIT_RTN_VALUE(0, "%s\n", ast_sip_session_get_name(session));
}
static int call_pickup_incoming_request(struct ast_sip_session *session, pjsip_rx_data *rdata)
@@ -3225,11 +3240,10 @@ 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);
SCOPE_ENTER(3, "%s: Status: %d\n", ast_sip_session_get_name(session), status.code);
if (!session->channel) {
SCOPE_EXIT_RTN("No channel\n");
SCOPE_EXIT_RTN("%s: No channel\n", ast_sip_session_get_name(session));
}
/* Build and send the tech-specific cause information */
@@ -3249,8 +3263,7 @@ 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_trace(-1, "%s: Queueing RINGING\n", ast_sip_session_get_name(session));
ast_queue_control(session->channel, AST_CONTROL_RINGING);
ast_channel_lock(session->channel);
if (ast_channel_state(session->channel) != AST_STATE_UP) {
@@ -3259,6 +3272,7 @@ static void chan_pjsip_incoming_response(struct ast_sip_session *session, struct
ast_channel_unlock(session->channel);
break;
case 183:
ast_trace(-1, "%s: Queueing PROGRESS\n", ast_sip_session_get_name(session));
if (session->endpoint->ignore_183_without_sdp) {
pjsip_rdata_sdp_info *sdp = pjsip_rdata_get_sdp_info(rdata);
if (sdp && sdp->body.ptr) {
@@ -3273,34 +3287,28 @@ static void chan_pjsip_incoming_response(struct ast_sip_session *session, struct
}
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_trace(-1, "%s: Queueing ANSWER\n", ast_sip_session_get_name(session));
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);
ast_trace(-1, "%s: Not queueing anything\n", ast_sip_session_get_name(session));
break;
}
SCOPE_EXIT_RTN();
SCOPE_EXIT_RTN("%s\n", ast_sip_session_get_name(session));
}
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);
SCOPE_ENTER(3, "%s\n", ast_sip_session_get_name(session));
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_trace(-1, "%s: Queueing SRCCHANGE\n", ast_sip_session_get_name(session));
ast_queue_control(session->channel, AST_CONTROL_SRCCHANGE);
}
}
SCOPE_EXIT_RTN_VALUE(0);
SCOPE_EXIT_RTN_VALUE(0, "%s\n", ast_sip_session_get_name(session));
}
static int update_devstate(void *obj, void *arg, int flags)