From 018b1d6aa5bf5951fd40b859b6378867a913d0b2 Mon Sep 17 00:00:00 2001 From: Karn Saheb Date: Fri, 10 Jan 2020 17:58:42 -0500 Subject: [PATCH] Track and notify via an event when packets cross the missed packets event threshold --- src/include/switch_core_media.h | 1 + src/include/switch_rtp.h | 2 +- src/mod/endpoints/mod_sofia/mod_sofia.h | 1 + src/mod/endpoints/mod_sofia/sofia.c | 5 ++ src/mod/endpoints/mod_sofia/sofia_glue.c | 1 + src/switch_core_media.c | 39 +++++++++++++++ src/switch_rtp.c | 61 +++++++++++++++++++++++- 7 files changed, 107 insertions(+), 3 deletions(-) diff --git a/src/include/switch_core_media.h b/src/include/switch_core_media.h index cb454c49836..74c8ca03775 100644 --- a/src/include/switch_core_media.h +++ b/src/include/switch_core_media.h @@ -92,6 +92,7 @@ typedef enum { typedef struct switch_core_media_params_s { uint32_t rtp_timeout_sec; + uint32_t rtp_timeout_warning_event_threshold; uint32_t rtp_hold_timeout_sec; uint32_t dtmf_delay; uint32_t codec_flags; diff --git a/src/include/switch_rtp.h b/src/include/switch_rtp.h index 96ea2135f37..123a628a3dd 100644 --- a/src/include/switch_rtp.h +++ b/src/include/switch_rtp.h @@ -278,8 +278,8 @@ SWITCH_DECLARE(char *) switch_rtp_get_remote_host(switch_rtp_t *rtp_session); SWITCH_DECLARE(switch_port_t) switch_rtp_get_remote_port(switch_rtp_t *rtp_session); SWITCH_DECLARE(void) switch_rtp_reset_media_timer(switch_rtp_t *rtp_session); SWITCH_DECLARE(void) switch_rtp_set_max_missed_packets(switch_rtp_t *rtp_session, uint32_t max); +SWITCH_DECLARE(void) switch_rtp_set_missed_packets_event_threshold(switch_rtp_t *rtp_session, uint32_t threshold); SWITCH_DECLARE(void) switch_rtp_set_media_timeout(switch_rtp_t *rtp_session, uint32_t ms); - SWITCH_DECLARE(switch_status_t) switch_rtp_udptl_mode(switch_rtp_t *rtp_session); SWITCH_DECLARE(void) switch_rtp_reset(switch_rtp_t *rtp_session); diff --git a/src/mod/endpoints/mod_sofia/mod_sofia.h b/src/mod/endpoints/mod_sofia/mod_sofia.h index 05e50c952f2..c2acaff04f4 100644 --- a/src/mod/endpoints/mod_sofia/mod_sofia.h +++ b/src/mod/endpoints/mod_sofia/mod_sofia.h @@ -702,6 +702,7 @@ struct sofia_profile { uint32_t minimum_session_expires; uint32_t max_proceeding; uint32_t rtp_timeout_sec; + uint32_t rtp_timeout_warning_event_threshold; uint32_t rtp_hold_timeout_sec; char *odbc_dsn; char *pre_trans_execute; diff --git a/src/mod/endpoints/mod_sofia/sofia.c b/src/mod/endpoints/mod_sofia/sofia.c index a3344fc323d..ce8a7626472 100644 --- a/src/mod/endpoints/mod_sofia/sofia.c +++ b/src/mod/endpoints/mod_sofia/sofia.c @@ -5227,6 +5227,11 @@ switch_status_t config_sofia(sofia_config_t reload, char *profile_name) switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_WARNING, "rtp-timeout-sec deprecated use media_timeout variable.\n"); } + } else if (!strcasecmp(var, "rtp-timeout-warning-event-threshold") && !zstr(val)) { + int v = atoi(val); + if (v >= 0) { + profile->rtp_timeout_warning_event_threshold = v; + } } else if (!strcasecmp(var, "rtp-hold-timeout-sec") && !zstr(val)) { int v = atoi(val); if (v >= 0) { diff --git a/src/mod/endpoints/mod_sofia/sofia_glue.c b/src/mod/endpoints/mod_sofia/sofia_glue.c index a412f25cd36..47d52ac798c 100644 --- a/src/mod/endpoints/mod_sofia/sofia_glue.c +++ b/src/mod/endpoints/mod_sofia/sofia_glue.c @@ -182,6 +182,7 @@ void sofia_glue_attach_private(switch_core_session_t *session, sofia_profile_t * tech_pvt->mparams.sdp_username = profile->sdp_username; tech_pvt->mparams.cng_pt = tech_pvt->cng_pt; tech_pvt->mparams.rtp_timeout_sec = profile->rtp_timeout_sec; + tech_pvt->mparams.rtp_timeout_warning_event_threshold = profile->rtp_timeout_warning_event_threshold; tech_pvt->mparams.rtp_hold_timeout_sec = profile->rtp_hold_timeout_sec; if (profile->rtp_digit_delay) { diff --git a/src/switch_core_media.c b/src/switch_core_media.c index ca6be2c16df..34245178bbc 100644 --- a/src/switch_core_media.c +++ b/src/switch_core_media.c @@ -130,6 +130,7 @@ typedef struct switch_rtp_engine_s { uint32_t last_codec_ms; uint8_t codec_reinvites; uint32_t max_missed_packets; + uint32_t missed_packets_event_threshold; uint32_t max_missed_hold_packets; uint32_t media_timeout; uint32_t media_hold_timeout; @@ -2967,6 +2968,7 @@ SWITCH_DECLARE(switch_status_t) switch_core_media_read_frame(switch_core_session if (type != SWITCH_MEDIA_TYPE_TEXT && engine->reset_codec > 0) { const char *val; int rtp_timeout_sec = 0; + int rtp_timeout_warning_event_threshold = 0; int rtp_hold_timeout_sec = 0; engine->reset_codec = 0; @@ -2995,6 +2997,13 @@ SWITCH_DECLARE(switch_status_t) switch_core_media_read_frame(switch_core_session } } + if ((val = switch_channel_get_variable(session->channel, "rtp_timeout_warning_event_threshold"))) { + int v = atoi(val); + if (v >= 0) { + rtp_timeout_warning_event_threshold = v; + } + } + if ((val = switch_channel_get_variable(session->channel, "rtp_hold_timeout_sec"))) { int v = atoi(val); if (v >= 0) { @@ -3014,6 +3023,12 @@ SWITCH_DECLARE(switch_status_t) switch_core_media_read_frame(switch_core_session } } + if (rtp_timeout_warning_event_threshold) { + engine->missed_packets_event_threshold = rtp_timeout_warning_event_threshold; + + switch_rtp_set_missed_packets_event_threshold(engine->rtp_session, engine->missed_packets_event_threshold); + } + if (rtp_hold_timeout_sec) { engine->max_missed_hold_packets = (engine->read_impl.samples_per_second * rtp_hold_timeout_sec) / engine->read_impl.samples_per_packet; @@ -5360,13 +5375,16 @@ SWITCH_DECLARE(uint8_t) switch_core_media_negotiate_sdp(switch_core_session_t *s if (switch_rtp_ready(a_engine->rtp_session)) { switch_rtp_set_max_missed_packets(a_engine->rtp_session, 0); + switch_rtp_set_missed_packets_event_threshold(a_engine->rtp_session, 0); a_engine->max_missed_hold_packets = 0; + a_engine->missed_packets_event_threshold = 0; a_engine->max_missed_packets = 0; switch_rtp_set_media_timeout(a_engine->rtp_session, a_engine->media_timeout); } else { switch_channel_set_variable(session->channel, "media_timeout_audio", "0"); switch_channel_set_variable(session->channel, "media_hold_timeout_audio", "0"); switch_channel_set_variable(session->channel, "rtp_timeout_sec", "0"); + switch_channel_set_variable(session->channel, "rtp_timeout_warning_event_threshold", "0"); switch_channel_set_variable(session->channel, "rtp_hold_timeout_sec", "0"); } } else if (sendonly < 2 && !strcasecmp(attr->a_name, "sendrecv")) { @@ -6544,6 +6562,9 @@ SWITCH_DECLARE(int) switch_core_media_toggle_hold(switch_core_session_t *session if (a_engine->max_missed_hold_packets && a_engine->rtp_session) { switch_rtp_set_max_missed_packets(a_engine->rtp_session, a_engine->max_missed_hold_packets); } + if (a_engine->missed_packets_event_threshold && a_engine->rtp_session) { + switch_rtp_set_missed_packets_event_threshold(a_engine->rtp_session, a_engine->missed_packets_event_threshold); + } if (a_engine->media_hold_timeout) { switch_rtp_set_media_timeout(a_engine->rtp_session, a_engine->media_hold_timeout); @@ -6633,6 +6654,9 @@ SWITCH_DECLARE(int) switch_core_media_toggle_hold(switch_core_session_t *session switch_rtp_set_media_timeout(v_engine->rtp_session, v_engine->media_timeout); } } + if (a_engine->missed_packets_event_threshold && a_engine->rtp_session) { + switch_rtp_set_missed_packets_event_threshold(a_engine->rtp_session, a_engine->missed_packets_event_threshold); + } if (b_channel) { if (switch_channel_test_flag(session->channel, CF_HOLD)) { @@ -8951,6 +8975,13 @@ SWITCH_DECLARE(switch_status_t) switch_core_media_activate_rtp(switch_core_sessi } } + if ((val = switch_channel_get_variable(session->channel, "rtp_timeout_warning_event_threshold"))) { + int v = atoi(val); + if (v >= 0) { + smh->mparams->rtp_timeout_warning_event_threshold = v; + } + } + if ((val = switch_channel_get_variable(session->channel, "rtp_hold_timeout_sec"))) { int v = atoi(val); if (v >= 0) { @@ -8969,6 +9000,12 @@ SWITCH_DECLARE(switch_status_t) switch_core_media_activate_rtp(switch_core_sessi } } + if (smh->mparams->rtp_timeout_warning_event_threshold) { + a_engine->missed_packets_event_threshold = smh->mparams->rtp_timeout_warning_event_threshold; + + switch_rtp_set_missed_packets_event_threshold(a_engine->rtp_session, a_engine->missed_packets_event_threshold); + } + if (smh->mparams->rtp_hold_timeout_sec) { a_engine->max_missed_hold_packets = (a_engine->read_impl.samples_per_second * smh->mparams->rtp_hold_timeout_sec) / a_engine->read_impl.samples_per_packet; } @@ -12578,6 +12615,7 @@ SWITCH_DECLARE(switch_status_t) switch_core_media_receive_message(switch_core_se { if (a_engine && a_engine->rtp_session) { switch_rtp_set_max_missed_packets(a_engine->rtp_session, a_engine->max_missed_hold_packets); + switch_rtp_set_missed_packets_event_threshold(a_engine->rtp_session, 0); // Disable missed packets tracking switch_rtp_set_media_timeout(a_engine->rtp_session, a_engine->media_hold_timeout); } @@ -12591,6 +12629,7 @@ SWITCH_DECLARE(switch_status_t) switch_core_media_receive_message(switch_core_se { if (a_engine && a_engine->rtp_session) { switch_rtp_set_max_missed_packets(a_engine->rtp_session, a_engine->max_missed_packets); + switch_rtp_set_missed_packets_event_threshold(a_engine->rtp_session, a_engine->missed_packets_event_threshold); // Renable missed packets tracking switch_rtp_set_media_timeout(a_engine->rtp_session, a_engine->media_timeout); } diff --git a/src/switch_rtp.c b/src/switch_rtp.c index c9485a3aff4..4ef010c0faa 100644 --- a/src/switch_rtp.c +++ b/src/switch_rtp.c @@ -442,6 +442,8 @@ struct switch_rtp { switch_jb_t *vb; switch_jb_t *vbw; uint32_t max_missed_packets; + int are_missed_packets_above_threshold; + uint32_t missed_packets_event_threshold; uint32_t missed_count; switch_time_t last_media; uint32_t media_timeout; @@ -2913,13 +2915,29 @@ SWITCH_DECLARE(void) switch_rtp_set_max_missed_packets(switch_rtp_t *rtp_session if (rtp_session->missed_count >= max) { switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(rtp_session->session), SWITCH_LOG_WARNING, - "new max missed packets(%d->%d) greater than current missed packets(%d). RTP will timeout.\n", - rtp_session->missed_count, max, rtp_session->missed_count); + "new max missed packets(%d->%d) lower than current missed packets(%d). RTP will timeout.\n", + rtp_session->max_missed_packets, max, rtp_session->missed_count); } rtp_session->max_missed_packets = max; } +SWITCH_DECLARE(void) switch_rtp_set_missed_packets_event_threshold(switch_rtp_t *rtp_session, uint32_t threshold) +{ + if (!switch_rtp_ready(rtp_session) || rtp_session->flags[SWITCH_RTP_FLAG_UDPTL]) { + return; + } + + if (rtp_session->missed_count >= threshold) { + + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(rtp_session->session), SWITCH_LOG_WARNING, + "new missed packets event threshold (%d->%d) lower than current missed packets (%d). No event will be fired.\n", + rtp_session->missed_packets_event_threshold, threshold, rtp_session->missed_count); + } + + rtp_session->missed_packets_event_threshold = threshold; +} + SWITCH_DECLARE(void) switch_rtp_reset_jb(switch_rtp_t *rtp_session) { if (switch_rtp_ready(rtp_session)) { @@ -7443,14 +7461,47 @@ static int rtp_common_read(switch_rtp_t *rtp_session, switch_payload_t *payload_ if (rtp_session->max_missed_packets && read_loops == 1 && !rtp_session->flags[SWITCH_RTP_FLAG_VIDEO] && !rtp_session->flags[SWITCH_RTP_FLAG_UDPTL]) { if (bytes && status == SWITCH_STATUS_SUCCESS) { + + if (rtp_session->are_missed_packets_above_threshold) { + switch_event_t *event = NULL; + rtp_session->are_missed_packets_above_threshold = 0; + + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(rtp_session->session), SWITCH_LOG_ERROR, "Starting to receive bytes again\n"); + + if (switch_event_create_subclass(&event, SWITCH_EVENT_CUSTOM, "rtp_packet_missed") == SWITCH_STATUS_SUCCESS) { + switch_channel_t *channel = switch_core_session_get_channel(rtp_session->session); + + switch_event_add_header_string(event, SWITCH_STACK_BOTTOM, "caller-unique-id", switch_channel_get_uuid(channel)); + switch_event_add_header_string(event, SWITCH_STACK_BOTTOM, "caller-partner-id", switch_channel_get_partner_uuid(channel)); + switch_event_add_header_string(event, SWITCH_STACK_BOTTOM, "Type", "Resumed"); + switch_event_fire(&event); + } + } + rtp_session->missed_count = 0; } else { if (rtp_session->media_timeout && rtp_session->last_media) { check_timeout(rtp_session); } else { if (++rtp_session->missed_count >= rtp_session->max_missed_packets) { + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(rtp_session->session), SWITCH_LOG_ERROR, "Exceeded max_missed_packets count\n"); + ret = -2; goto end; + } else if (rtp_session->missed_packets_event_threshold && rtp_session->missed_count == rtp_session->missed_packets_event_threshold) { + switch_event_t *event = NULL; + rtp_session->are_missed_packets_above_threshold = 1; + + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(rtp_session->session), SWITCH_LOG_ERROR, "Updated missed packets count -- total missed %d\n", rtp_session->missed_count); + + if (switch_event_create_subclass(&event, SWITCH_EVENT_CUSTOM, "rtp_packet_missed") == SWITCH_STATUS_SUCCESS) { + switch_channel_t *channel = switch_core_session_get_channel(rtp_session->session); + + switch_event_add_header_string(event, SWITCH_STACK_BOTTOM, "caller-unique-id", switch_channel_get_uuid(channel)); + switch_event_add_header_string(event, SWITCH_STACK_BOTTOM, "caller-partner-id", switch_channel_get_partner_uuid(channel)); + switch_event_add_header_string(event, SWITCH_STACK_BOTTOM, "Type", "Missed"); + switch_event_fire(&event); + } } } } @@ -7506,7 +7557,13 @@ static int rtp_common_read(switch_rtp_t *rtp_session, switch_payload_t *payload_ if (rtp_session->media_timeout && rtp_session->last_media) { check_timeout(rtp_session); } else if (rtp_session->max_missed_packets) { + if (rtp_session->missed_count % 10 == 0) { + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(rtp_session->session), SWITCH_LOG_WARNING, "Updated missed packets count -- total missed %d\n", rtp_session->missed_count); + } + if (rtp_session->missed_count >= rtp_session->max_missed_packets) { + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(rtp_session->session), SWITCH_LOG_WARNING, "Exceeded max_missed_packets count\n"); + ret = -2; goto end; }