FS-8547 #resolve [Add error log into stats to log when quality impacting events begin and end]

This commit is contained in:
Anthony Minessale 2015-11-16 19:31:32 -06:00
parent 91554607da
commit 860a799c1d
3 changed files with 233 additions and 6 deletions

View File

@ -613,6 +613,14 @@ typedef enum {
} switch_vad_flag_enum_t;
typedef uint32_t switch_vad_flag_t;
typedef struct error_period {
int64_t start;
int64_t stop;
struct error_period *next;
} switch_error_period_t;
typedef struct {
switch_size_t raw_bytes;
switch_size_t media_bytes;
@ -648,6 +656,7 @@ typedef struct {
switch_size_t last_flaw;
double R;
double mos;
struct error_period *error_log;
} switch_rtp_numbers_t;
typedef struct {

View File

@ -2490,6 +2490,105 @@ SWITCH_DECLARE(int) switch_ivr_set_xml_profile_data(switch_xml_t xml, switch_cal
return off;
}
#define add_stat(_x, _i, _s) \
switch_snprintf(var_val, sizeof(var_val), "%" SWITCH_SIZE_T_FMT, _i); \
x_tmp = switch_xml_add_child_d(_x, _s, loff++); \
switch_xml_set_txt_d(x_tmp, var_val)
#define add_stat_double(_x, _i, _s) \
switch_snprintf(var_val, sizeof(var_val), "%0.2f", _i); \
x_tmp = switch_xml_add_child_d(_x, _s, loff++); \
switch_xml_set_txt_d(x_tmp, var_val)
SWITCH_DECLARE(int) switch_ivr_set_xml_call_stats(switch_xml_t xml, switch_core_session_t *session, int off, switch_media_type_t type)
{
const char *name = (type == SWITCH_MEDIA_TYPE_VIDEO) ? "video" : "audio";
switch_xml_t x_stat, x_in, x_out, x_tmp = NULL;
int loff = 0;
switch_rtp_stats_t *stats = switch_core_media_get_stats(session, type, NULL);
char var_val[35] = "";
if (!stats) return off;
if (!(x_stat = switch_xml_add_child_d(xml, name, off++))) {
abort();
}
if (!(x_in = switch_xml_add_child_d(x_stat, "inbound", off++))) {
abort();
}
if (!(x_out = switch_xml_add_child_d(x_stat, "outbound", off++))) {
abort();
}
stats->inbound.std_deviation = sqrt(stats->inbound.variance);
add_stat(x_in, stats->inbound.raw_bytes, "raw_bytes");
add_stat(x_in, stats->inbound.media_bytes, "media_bytes");
add_stat(x_in, stats->inbound.packet_count, "packet_count");
add_stat(x_in, stats->inbound.media_packet_count, "media_packet_count");
add_stat(x_in, stats->inbound.skip_packet_count, "skip_packet_count");
add_stat(x_in, stats->inbound.jb_packet_count, "jitter_packet_count");
add_stat(x_in, stats->inbound.dtmf_packet_count, "dtmf_packet_count");
add_stat(x_in, stats->inbound.cng_packet_count, "cng_packet_count");
add_stat(x_in, stats->inbound.flush_packet_count, "flush_packet_count");
add_stat(x_in, stats->inbound.largest_jb_size, "largest_jb_size");
add_stat_double(x_in, stats->inbound.min_variance, "jitter_min_variance");
add_stat_double(x_in, stats->inbound.max_variance, "jitter_max_variance");
add_stat_double(x_in, stats->inbound.lossrate, "jitter_loss_rate");
add_stat_double(x_in, stats->inbound.burstrate, "jitter_burst_rate");
add_stat_double(x_in, stats->inbound.mean_interval, "mean_interval");
add_stat(x_in, stats->inbound.flaws, "flaw_total");
add_stat_double(x_in, stats->inbound.R, "quality_percentage");
add_stat_double(x_in, stats->inbound.mos, "mos");
if (stats->inbound.error_log) {
switch_xml_t x_err_log, x_err;
switch_error_period_t *ep;
int eoff = 0;
if (!(x_err_log = switch_xml_add_child_d(x_stat, "error-log", off++))) {
abort();
}
for(ep = stats->inbound.error_log; ep; ep = ep->next) {
if (!(ep->start && ep->stop)) continue;
if (!(x_err = switch_xml_add_child_d(x_err_log, "error-period", eoff++))) {
abort();
}
switch_snprintf(var_val, sizeof(var_val), "%" SWITCH_TIME_T_FMT, ep->start);
x_tmp = switch_xml_add_child_d(x_err, "start", 0);
switch_xml_set_txt_d(x_tmp, var_val);
switch_snprintf(var_val, sizeof(var_val), "%" SWITCH_TIME_T_FMT, ep->stop);
x_tmp = switch_xml_add_child_d(x_err, "stop", 1);
switch_xml_set_txt_d(x_tmp, var_val);
switch_snprintf(var_val, sizeof(var_val), "%" SWITCH_TIME_T_FMT, (ep->stop - ep->start) / 1000);
x_tmp = switch_xml_add_child_d(x_err, "duration-msec", 2);
switch_xml_set_txt_d(x_tmp, var_val);
}
}
add_stat(x_out, stats->outbound.raw_bytes, "raw_bytes");
add_stat(x_out, stats->outbound.media_bytes, "media_bytes");
add_stat(x_out, stats->outbound.packet_count, "packet_count");
add_stat(x_out, stats->outbound.media_packet_count, "media_packet_count");
add_stat(x_out, stats->outbound.skip_packet_count, "skip_packet_count");
add_stat(x_out, stats->outbound.dtmf_packet_count, "dtmf_packet_count");
add_stat(x_out, stats->outbound.cng_packet_count, "cng_packet_count");
add_stat(x_out, stats->rtcp.packet_count, "rtcp_packet_count");
add_stat(x_out, stats->rtcp.octet_count, "rtcp_octet_count");
return off;
}
static int switch_ivr_set_xml_chan_var(switch_xml_t xml, const char *var, const char *val, int off)
{
char *data;
@ -2584,6 +2683,13 @@ SWITCH_DECLARE(switch_status_t) switch_ivr_generate_xml_cdr(switch_core_session_
free(f);
}
if (!(variables = switch_xml_add_child_d(cdr, "call-stats", cdr_off++))) {
goto error;
}
switch_ivr_set_xml_call_stats(variables, session, v_off, SWITCH_MEDIA_TYPE_AUDIO);
switch_ivr_set_xml_call_stats(variables, session, v_off, SWITCH_MEDIA_TYPE_VIDEO);
if (!(variables = switch_xml_add_child_d(cdr, "variables", cdr_off++))) {
goto error;
@ -2888,6 +2994,80 @@ static void switch_ivr_set_json_profile_data(cJSON *json, switch_caller_profile_
cJSON_AddItemToObject(json, "chan_name", cJSON_CreateString(caller_profile->chan_name));
}
#define add_jstat(_j, _i, _s) \
switch_snprintf(var_val, sizeof(var_val), "%" SWITCH_SIZE_T_FMT, _i); \
cJSON_AddItemToObject(_j, _s, cJSON_CreateNumber(_i))
SWITCH_DECLARE(void) switch_ivr_set_json_call_stats(cJSON *json, switch_core_session_t *session, switch_media_type_t type)
{
const char *name = (type == SWITCH_MEDIA_TYPE_VIDEO) ? "video" : "audio";
cJSON *j_stat, *j_in, *j_out;
switch_rtp_stats_t *stats = switch_core_media_get_stats(session, type, NULL);
char var_val[35] = "";
if (!stats) return;
j_stat = cJSON_CreateObject();
j_in = cJSON_CreateObject();
j_out = cJSON_CreateObject();
cJSON_AddItemToObject(json, name, j_stat);
cJSON_AddItemToObject(j_stat, "inbound", j_in);
cJSON_AddItemToObject(j_stat, "outbound", j_out);
stats->inbound.std_deviation = sqrt(stats->inbound.variance);
add_jstat(j_in, stats->inbound.raw_bytes, "raw_bytes");
add_jstat(j_in, stats->inbound.media_bytes, "media_bytes");
add_jstat(j_in, stats->inbound.packet_count, "packet_count");
add_jstat(j_in, stats->inbound.media_packet_count, "media_packet_count");
add_jstat(j_in, stats->inbound.skip_packet_count, "skip_packet_count");
add_jstat(j_in, stats->inbound.jb_packet_count, "jitter_packet_count");
add_jstat(j_in, stats->inbound.dtmf_packet_count, "dtmf_packet_count");
add_jstat(j_in, stats->inbound.cng_packet_count, "cng_packet_count");
add_jstat(j_in, stats->inbound.flush_packet_count, "flush_packet_count");
add_jstat(j_in, stats->inbound.largest_jb_size, "largest_jb_size");
add_jstat(j_in, stats->inbound.min_variance, "jitter_min_variance");
add_jstat(j_in, stats->inbound.max_variance, "jitter_max_variance");
add_jstat(j_in, stats->inbound.lossrate, "jitter_loss_rate");
add_jstat(j_in, stats->inbound.burstrate, "jitter_burst_rate");
add_jstat(j_in, stats->inbound.mean_interval, "mean_interval");
add_jstat(j_in, stats->inbound.flaws, "flaw_total");
add_jstat(j_in, stats->inbound.R, "quality_percentage");
add_jstat(j_in, stats->inbound.mos, "mos");
if (stats->inbound.error_log) {
cJSON *j_err_log, *j_err;
switch_error_period_t *ep;
j_err_log = cJSON_CreateArray();
cJSON_AddItemToObject(j_in, "errorLog", j_err_log);
for(ep = stats->inbound.error_log; ep; ep = ep->next) {
if (!(ep->start && ep->stop)) continue;
j_err = cJSON_CreateObject();
cJSON_AddItemToObject(j_err, "start", cJSON_CreateNumber(ep->start));
cJSON_AddItemToObject(j_err, "stop", cJSON_CreateNumber(ep->stop));
cJSON_AddItemToObject(j_err, "durationMS", cJSON_CreateNumber((ep->stop - ep->start) / 1000));
cJSON_AddItemToArray(j_err_log, j_err);
}
}
add_jstat(j_out, stats->outbound.raw_bytes, "raw_bytes");
add_jstat(j_out, stats->outbound.media_bytes, "media_bytes");
add_jstat(j_out, stats->outbound.packet_count, "packet_count");
add_jstat(j_out, stats->outbound.media_packet_count, "media_packet_count");
add_jstat(j_out, stats->outbound.skip_packet_count, "skip_packet_count");
add_jstat(j_out, stats->outbound.dtmf_packet_count, "dtmf_packet_count");
add_jstat(j_out, stats->outbound.cng_packet_count, "cng_packet_count");
add_jstat(j_out, stats->rtcp.packet_count, "rtcp_packet_count");
add_jstat(j_out, stats->rtcp.octet_count, "rtcp_octet_count");
}
static void switch_ivr_set_json_chan_vars(cJSON *json, switch_channel_t *channel, switch_bool_t urlencode)
{
switch_event_header_t *hi = switch_channel_variable_first(channel);
@ -2925,7 +3105,7 @@ SWITCH_DECLARE(switch_status_t) switch_ivr_generate_json_cdr(switch_core_session
switch_channel_t *channel = switch_core_session_get_channel(session);
switch_caller_profile_t *caller_profile;
cJSON *variables, *j_main_cp, *j_caller_profile, *j_caller_extension, *j_caller_extension_apps, *j_times, *j_application,
*j_callflow, *j_profile, *j_inner_extension, *j_app_log, *j_apps, *j_o, *j_o_profiles, *j_channel_data;
*j_callflow, *j_profile, *j_inner_extension, *j_app_log, *j_apps, *j_o, *j_o_profiles, *j_channel_data, *callStats;
switch_app_log_t *app_log;
char tmp[512], *f;
@ -2951,9 +3131,13 @@ SWITCH_DECLARE(switch_status_t) switch_ivr_generate_json_cdr(switch_core_session
free(f);
}
callStats = cJSON_CreateObject();
cJSON_AddItemToObject(cdr, "callStats", callStats);
switch_ivr_set_json_call_stats(callStats, session, SWITCH_MEDIA_TYPE_AUDIO);
switch_ivr_set_json_call_stats(callStats, session, SWITCH_MEDIA_TYPE_VIDEO);
variables = cJSON_CreateObject();
cJSON_AddItemToObject(cdr, "variables", variables);
switch_ivr_set_json_chan_vars(variables, channel, urlencode);

View File

@ -419,6 +419,10 @@ struct switch_rtp {
uint32_t cng_count;
switch_rtp_bug_flag_t rtp_bugs;
switch_rtp_stats_t stats;
uint32_t clean_stream;
uint32_t bad_stream;
uint32_t recovering_stream;
uint32_t hot_hits;
uint32_t sync_packets;
int rtcp_interval;
@ -1517,7 +1521,7 @@ static void do_mos(switch_rtp_t *rtp_session, int force) {
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(rtp_session->session), SWITCH_LOG_DEBUG3, "%s %s %d consecutive flaws, adding %d flaw penalty\n",
rtp_session_name(rtp_session), rtp_type(rtp_session),
rtp_session->consecutive_flaws, penalty);
rtp_session->bad_stream++;
rtp_session->stats.inbound.flaws += penalty;
}
@ -1616,12 +1620,12 @@ static void check_jitter(switch_rtp_t *rtp_session)
rtp_session->stats.inbound.loss[rtp_session->stats.inbound.last_loss] += lost;
}
rtp_session->bad_stream++;
rtp_session->stats.inbound.flaws += lost;
} else {
rtp_session->stats.inbound.last_loss = 0;
}
rtp_session->stats.inbound.last_processed_seq = seq;
/* Burst and Packet Loss */
@ -1634,7 +1638,32 @@ static void check_jitter(switch_rtp_t *rtp_session)
} else {
do_mos(rtp_session, SWITCH_FALSE);
}
if (rtp_session->stats.inbound.last_loss || rtp_session->bad_stream) {
if (rtp_session->session && (!rtp_session->stats.inbound.error_log || rtp_session->stats.inbound.error_log->stop)) {
struct error_period *error = switch_core_session_alloc(rtp_session->session, sizeof(*error));
error->start = switch_micro_time_now();
error->next = rtp_session->stats.inbound.error_log;
rtp_session->stats.inbound.error_log = error;
}
if (!rtp_session->stats.inbound.last_loss) {
if (++rtp_session->recovering_stream > (rtp_session->one_second * 3)) {
if (rtp_session->session && rtp_session->stats.inbound.error_log) {
rtp_session->stats.inbound.error_log->stop = switch_micro_time_now();
}
rtp_session->bad_stream = 0;
}
} else {
rtp_session->recovering_stream = 0;
rtp_session->bad_stream++;
}
} else {
rtp_session->recovering_stream = 0;
rtp_session->clean_stream++;
}
if ( diff_time < 0 ) {
diff_time = -diff_time;
@ -4411,6 +4440,10 @@ SWITCH_DECLARE(void) switch_rtp_destroy(switch_rtp_t **rtp_session)
do_mos(*rtp_session, SWITCH_TRUE);
if ((*rtp_session)->stats.inbound.error_log && !(*rtp_session)->stats.inbound.error_log->stop) {
(*rtp_session)->stats.inbound.error_log->stop = switch_micro_time_now();
}
switch_mutex_lock((*rtp_session)->flag_mutex);
switch_rtp_kill_socket(*rtp_session);
@ -6170,6 +6203,7 @@ static int rtp_common_read(switch_rtp_t *rtp_session, switch_payload_t *payload_
rtp_session_name(rtp_session),
rtp_session->sync_packets, rtp_type(rtp_session));
rtp_session->bad_stream++;
rtp_session->stats.inbound.flaws += rtp_session->sync_packets;
}