static int server_thread(void *arg)
{
pj_time_val timeout = { 0, 1 };
unsigned thread_index = (unsigned)(long)arg;
pj_time_val last_report, next_report;
pj_gettimeofday(&last_report);
next_report = last_report;
next_report.sec++;
while (!app.thread_quit) {
pj_time_val now;
unsigned i;
for (i=0; i<100; ++i) {
unsigned count = 0;
pjsip_endpt_handle_events2(app.sip_endpt, &timeout, &count);
if (count == 0)
break;
}
if (thread_index == 0) {
pj_gettimeofday(&now);
if (PJ_TIME_VAL_GTE(now, next_report)) {
pj_time_val tmp;
unsigned msec;
unsigned stateless, stateful, call;
char str_stateless[32], str_stateful[32], str_call[32];
tmp = now;
PJ_TIME_VAL_SUB(tmp, last_report);
msec = PJ_TIME_VAL_MSEC(tmp);
last_report = now;
next_report = last_report;
next_report.sec++;
stateless = app.server.cur_state.stateless_cnt - app.server.prev_state.stateless_cnt;
stateful = app.server.cur_state.stateful_cnt - app.server.prev_state.stateful_cnt;
call = app.server.cur_state.call_cnt - app.server.prev_state.call_cnt;
good_number(str_stateless, app.server.cur_state.stateless_cnt);
good_number(str_stateful, app.server.cur_state.stateful_cnt);
good_number(str_call, app.server.cur_state.call_cnt);
printf("Total(rate): stateless:%s (%d/s), statefull:%s (%d/s), call:%s (%d/s) \r",
str_stateless, stateless*1000/msec,
str_stateful, stateful*1000/msec,
str_call, call*1000/msec);
fflush(stdout);
app.server.prev_state = app.server.cur_state;
}
}
}
return 0;
}
PJ_DEF(pj_status_t) pjmedia_endpt_dump(pjmedia_endpt *endpt)
{
#if PJ_LOG_MAX_LEVEL >= 3
unsigned i, count;
pjmedia_codec_info codec_info[32];
unsigned prio[32];
PJ_LOG(3,(THIS_FILE, "Dumping PJMEDIA capabilities:"));
count = PJ_ARRAY_SIZE(codec_info);
if (pjmedia_codec_mgr_enum_codecs(&endpt->codec_mgr,
&count, codec_info, prio) != PJ_SUCCESS)
{
PJ_LOG(3,(THIS_FILE, " -error: failed to enum codecs"));
return PJ_SUCCESS;
}
PJ_LOG(3,(THIS_FILE, " Total number of installed codecs: %d", count));
for (i=0; i<count; ++i) {
const char *type;
pjmedia_codec_param param;
char bps[32];
switch (codec_info[i].type) {
case PJMEDIA_TYPE_AUDIO:
type = "Audio"; break;
case PJMEDIA_TYPE_VIDEO:
type = "Video"; break;
default:
type = "Unknown type"; break;
}
if (pjmedia_codec_mgr_get_default_param(&endpt->codec_mgr,
&codec_info[i],
¶m) != PJ_SUCCESS)
{
pj_bzero(¶m, sizeof(pjmedia_codec_param));
}
PJ_LOG(3,(THIS_FILE,
" %s codec #%2d: pt=%d (%.*s @%dKHz/%d, %sbps, %dms%s%s%s%s%s)",
type, i, codec_info[i].pt,
(int)codec_info[i].encoding_name.slen,
codec_info[i].encoding_name.ptr,
codec_info[i].clock_rate/1000,
codec_info[i].channel_cnt,
good_number(bps, param.info.avg_bps),
param.info.frm_ptime * param.setting.frm_per_pkt,
(param.setting.vad ? " vad" : ""),
(param.setting.cng ? " cng" : ""),
(param.setting.plc ? " plc" : ""),
(param.setting.penh ? " penh" : ""),
(prio[i]==PJMEDIA_CODEC_PRIO_DISABLED?" disabled":"")));
}
#endif
return PJ_SUCCESS;
}
static unsigned dump_media_stat(const char *indent,
char *buf, unsigned maxlen,
const pjmedia_rtcp_stat *stat,
const char *rx_info, const char *tx_info)
{
char last_update[64];
char packets[32], bytes[32], ipbytes[32], avg_bps[32], avg_ipbps[32];
pj_time_val media_duration, now;
char *p = buf, *end = buf+maxlen;
int len;
if (stat->rx.update_cnt == 0)
strcpy(last_update, "never");
else {
pj_gettimeofday(&now);
PJ_TIME_VAL_SUB(now, stat->rx.update);
sprintf(last_update, "%02ldh:%02ldm:%02ld.%03lds ago",
now.sec / 3600,
(now.sec % 3600) / 60,
now.sec % 60,
now.msec);
}
pj_gettimeofday(&media_duration);
PJ_TIME_VAL_SUB(media_duration, stat->start);
if (PJ_TIME_VAL_MSEC(media_duration) == 0)
media_duration.msec = 1;
len = pj_ansi_snprintf(p, end-p,
"%s RX %s last update:%s\n"
"%s total %spkt %sB (%sB +IP hdr) @avg=%sbps/%sbps\n"
"%s pkt loss=%d (%3.1f%%), discrd=%d (%3.1f%%), dup=%d (%2.1f%%), reord=%d (%3.1f%%)\n"
"%s (msec) min avg max last dev\n"
"%s loss period: %7.3f %7.3f %7.3f %7.3f %7.3f\n"
"%s jitter : %7.3f %7.3f %7.3f %7.3f %7.3f\n"
#if defined(PJMEDIA_RTCP_STAT_HAS_RAW_JITTER) && PJMEDIA_RTCP_STAT_HAS_RAW_JITTER!=0
"%s raw jitter : %7.3f %7.3f %7.3f %7.3f %7.3f\n"
#endif
#if defined(PJMEDIA_RTCP_STAT_HAS_IPDV) && PJMEDIA_RTCP_STAT_HAS_IPDV!=0
"%s IPDV : %7.3f %7.3f %7.3f %7.3f %7.3f\n"
#endif
"%s",
indent,
rx_info? rx_info : "",
last_update,
indent,
good_number(packets, stat->rx.pkt),
good_number(bytes, stat->rx.bytes),
good_number(ipbytes, stat->rx.bytes + stat->rx.pkt * 40),
good_number(avg_bps, (pj_int32_t)((pj_int64_t)stat->rx.bytes * 8 * 1000 / PJ_TIME_VAL_MSEC(media_duration))),
good_number(avg_ipbps, (pj_int32_t)(((pj_int64_t)stat->rx.bytes + stat->rx.pkt * 40) * 8 * 1000 / PJ_TIME_VAL_MSEC(media_duration))),
indent,
stat->rx.loss,
(stat->rx.loss? stat->rx.loss * 100.0 / (stat->rx.pkt + stat->rx.loss) : 0),
stat->rx.discard,
(stat->rx.discard? stat->rx.discard * 100.0 / (stat->rx.pkt + stat->rx.loss) : 0),
stat->rx.dup,
(stat->rx.dup? stat->rx.dup * 100.0 / (stat->rx.pkt + stat->rx.loss) : 0),
stat->rx.reorder,
(stat->rx.reorder? stat->rx.reorder * 100.0 / (stat->rx.pkt + stat->rx.loss) : 0),
indent, indent,
stat->rx.loss_period.min / 1000.0,
stat->rx.loss_period.mean / 1000.0,
stat->rx.loss_period.max / 1000.0,
stat->rx.loss_period.last / 1000.0,
pj_math_stat_get_stddev(&stat->rx.loss_period) / 1000.0,
indent,
stat->rx.jitter.min / 1000.0,
stat->rx.jitter.mean / 1000.0,
stat->rx.jitter.max / 1000.0,
stat->rx.jitter.last / 1000.0,
pj_math_stat_get_stddev(&stat->rx.jitter) / 1000.0,
#if defined(PJMEDIA_RTCP_STAT_HAS_RAW_JITTER) && PJMEDIA_RTCP_STAT_HAS_RAW_JITTER!=0
indent,
stat->rx_raw_jitter.min / 1000.0,
stat->rx_raw_jitter.mean / 1000.0,
stat->rx_raw_jitter.max / 1000.0,
stat->rx_raw_jitter.last / 1000.0,
pj_math_stat_get_stddev(&stat->rx_raw_jitter) / 1000.0,
#endif
#if defined(PJMEDIA_RTCP_STAT_HAS_IPDV) && PJMEDIA_RTCP_STAT_HAS_IPDV!=0
indent,
stat->rx_ipdv.min / 1000.0,
stat->rx_ipdv.mean / 1000.0,
stat->rx_ipdv.max / 1000.0,
stat->rx_ipdv.last / 1000.0,
pj_math_stat_get_stddev(&stat->rx_ipdv) / 1000.0,
#endif
""
);
if (len < 1 || len > end-p) {
*p = '\0';
return (p-buf);
}
p += len;
if (stat->tx.update_cnt == 0)
strcpy(last_update, "never");
else {
pj_gettimeofday(&now);
PJ_TIME_VAL_SUB(now, stat->tx.update);
sprintf(last_update, "%02ldh:%02ldm:%02ld.%03lds ago",
now.sec / 3600,
(now.sec % 3600) / 60,
now.sec % 60,
now.msec);
}
len = pj_ansi_snprintf(p, end-p,
"%s TX %s last update:%s\n"
"%s total %spkt %sB (%sB +IP hdr) @avg=%sbps/%sbps\n"
"%s pkt loss=%d (%3.1f%%), dup=%d (%3.1f%%), reorder=%d (%3.1f%%)\n"
"%s (msec) min avg max last dev \n"
"%s loss period: %7.3f %7.3f %7.3f %7.3f %7.3f\n"
"%s jitter : %7.3f %7.3f %7.3f %7.3f %7.3f\n",
indent,
tx_info,
last_update,
indent,
good_number(packets, stat->tx.pkt),
good_number(bytes, stat->tx.bytes),
good_number(ipbytes, stat->tx.bytes + stat->tx.pkt * 40),
good_number(avg_bps, (pj_int32_t)((pj_int64_t)stat->tx.bytes * 8 * 1000 / PJ_TIME_VAL_MSEC(media_duration))),
good_number(avg_ipbps, (pj_int32_t)(((pj_int64_t)stat->tx.bytes + stat->tx.pkt * 40) * 8 * 1000 / PJ_TIME_VAL_MSEC(media_duration))),
indent,
stat->tx.loss,
(stat->tx.loss? stat->tx.loss * 100.0 / (stat->tx.pkt + stat->tx.loss) : 0),
stat->tx.dup,
(stat->tx.dup? stat->tx.dup * 100.0 / (stat->tx.pkt + stat->tx.loss) : 0),
stat->tx.reorder,
(stat->tx.reorder? stat->tx.reorder * 100.0 / (stat->tx.pkt + stat->tx.loss) : 0),
indent, indent,
stat->tx.loss_period.min / 1000.0,
stat->tx.loss_period.mean / 1000.0,
stat->tx.loss_period.max / 1000.0,
stat->tx.loss_period.last / 1000.0,
pj_math_stat_get_stddev(&stat->tx.loss_period) / 1000.0,
indent,
stat->tx.jitter.min / 1000.0,
stat->tx.jitter.mean / 1000.0,
stat->tx.jitter.max / 1000.0,
stat->tx.jitter.last / 1000.0,
pj_math_stat_get_stddev(&stat->tx.jitter) / 1000.0
);
if (len < 1 || len > end-p) {
*p = '\0';
return (p-buf);
}
p += len;
len = pj_ansi_snprintf(p, end-p,
"%s RTT msec : %7.3f %7.3f %7.3f %7.3f %7.3f\n",
indent,
stat->rtt.min / 1000.0,
stat->rtt.mean / 1000.0,
stat->rtt.max / 1000.0,
stat->rtt.last / 1000.0,
pj_math_stat_get_stddev(&stat->rtt) / 1000.0
);
if (len < 1 || len > end-p) {
*p = '\0';
return (p-buf);
}
p += len;
return (p-buf);
}
/*
* Print stream statistics
*/
static void print_stream_stat(pjmedia_stream *stream,
const pjmedia_codec_param *codec_param)
{
char duration[80], last_update[80];
char bps[16], ipbps[16], packets[16], bytes[16], ipbytes[16];
pjmedia_port *port;
pjmedia_rtcp_stat stat;
pj_time_val now;
pj_gettimeofday(&now);
pjmedia_stream_get_stat(stream, &stat);
pjmedia_stream_get_port(stream, &port);
puts("Stream statistics:");
/* Print duration */
PJ_TIME_VAL_SUB(now, stat.start);
sprintf(duration, " Duration: %02ld:%02ld:%02ld.%03ld",
now.sec / 3600,
(now.sec % 3600) / 60,
(now.sec % 60),
now.msec);
printf(" Info: audio %dHz, %dms/frame, %sB/s (%sB/s +IP hdr)\n",
PJMEDIA_PIA_SRATE(&port->info),
PJMEDIA_PIA_PTIME(&port->info),
good_number(bps, (codec_param->info.avg_bps+7)/8),
good_number(ipbps, ((codec_param->info.avg_bps+7)/8) +
(40 * 1000 /
codec_param->setting.frm_per_pkt /
codec_param->info.frm_ptime)));
if (stat.rx.update_cnt == 0)
strcpy(last_update, "never");
else {
pj_gettimeofday(&now);
PJ_TIME_VAL_SUB(now, stat.rx.update);
sprintf(last_update, "%02ldh:%02ldm:%02ld.%03lds ago",
now.sec / 3600,
(now.sec % 3600) / 60,
now.sec % 60,
now.msec);
}
printf(" RX stat last update: %s\n"
" total %s packets %sB received (%sB +IP hdr)%s\n"
" pkt loss=%d (%3.1f%%), dup=%d (%3.1f%%), reorder=%d (%3.1f%%)%s\n"
" (msec) min avg max last dev\n"
" loss period: %7.3f %7.3f %7.3f %7.3f %7.3f%s\n"
" jitter : %7.3f %7.3f %7.3f %7.3f %7.3f%s\n",
last_update,
good_number(packets, stat.rx.pkt),
good_number(bytes, stat.rx.bytes),
good_number(ipbytes, stat.rx.bytes + stat.rx.pkt * 32),
"",
stat.rx.loss,
stat.rx.loss * 100.0 / (stat.rx.pkt + stat.rx.loss),
stat.rx.dup,
stat.rx.dup * 100.0 / (stat.rx.pkt + stat.rx.loss),
stat.rx.reorder,
stat.rx.reorder * 100.0 / (stat.rx.pkt + stat.rx.loss),
"",
stat.rx.loss_period.min / 1000.0,
stat.rx.loss_period.mean / 1000.0,
stat.rx.loss_period.max / 1000.0,
stat.rx.loss_period.last / 1000.0,
pj_math_stat_get_stddev(&stat.rx.loss_period) / 1000.0,
"",
stat.rx.jitter.min / 1000.0,
stat.rx.jitter.mean / 1000.0,
stat.rx.jitter.max / 1000.0,
stat.rx.jitter.last / 1000.0,
pj_math_stat_get_stddev(&stat.rx.jitter) / 1000.0,
""
);
if (stat.tx.update_cnt == 0)
strcpy(last_update, "never");
else {
pj_gettimeofday(&now);
PJ_TIME_VAL_SUB(now, stat.tx.update);
sprintf(last_update, "%02ldh:%02ldm:%02ld.%03lds ago",
now.sec / 3600,
(now.sec % 3600) / 60,
now.sec % 60,
now.msec);
}
printf(" TX stat last update: %s\n"
" total %s packets %sB sent (%sB +IP hdr)%s\n"
" pkt loss=%d (%3.1f%%), dup=%d (%3.1f%%), reorder=%d (%3.1f%%)%s\n"
" (msec) min avg max last dev\n"
" loss period: %7.3f %7.3f %7.3f %7.3f %7.3f%s\n"
" jitter : %7.3f %7.3f %7.3f %7.3f %7.3f%s\n",
last_update,
good_number(packets, stat.tx.pkt),
good_number(bytes, stat.tx.bytes),
good_number(ipbytes, stat.tx.bytes + stat.tx.pkt * 32),
"",
stat.tx.loss,
stat.tx.loss * 100.0 / (stat.tx.pkt + stat.tx.loss),
stat.tx.dup,
stat.tx.dup * 100.0 / (stat.tx.pkt + stat.tx.loss),
stat.tx.reorder,
stat.tx.reorder * 100.0 / (stat.tx.pkt + stat.tx.loss),
"",
stat.tx.loss_period.min / 1000.0,
stat.tx.loss_period.mean / 1000.0,
stat.tx.loss_period.max / 1000.0,
stat.tx.loss_period.last / 1000.0,
pj_math_stat_get_stddev(&stat.tx.loss_period) / 1000.0,
"",
stat.tx.jitter.min / 1000.0,
stat.tx.jitter.mean / 1000.0,
stat.tx.jitter.max / 1000.0,
stat.tx.jitter.last / 1000.0,
pj_math_stat_get_stddev(&stat.tx.jitter) / 1000.0,
""
);
printf(" RTT delay : %7.3f %7.3f %7.3f %7.3f %7.3f%s\n",
stat.rtt.min / 1000.0,
stat.rtt.mean / 1000.0,
stat.rtt.max / 1000.0,
stat.rtt.last / 1000.0,
pj_math_stat_get_stddev(&stat.rtt) / 1000.0,
""
);
#if defined(PJMEDIA_HAS_RTCP_XR) && (PJMEDIA_HAS_RTCP_XR != 0)
/* RTCP XR Reports */
do {
char loss[16], dup[16];
char jitter[80];
char toh[80];
char plc[16], jba[16], jbr[16];
char signal_lvl[16], noise_lvl[16], rerl[16];
char r_factor[16], ext_r_factor[16], mos_lq[16], mos_cq[16];
pjmedia_rtcp_xr_stat xr_stat;
if (pjmedia_stream_get_stat_xr(stream, &xr_stat) != PJ_SUCCESS)
break;
puts("\nExtended reports:");
/* Statistics Summary */
puts(" Statistics Summary");
if (xr_stat.rx.stat_sum.l)
sprintf(loss, "%d", xr_stat.rx.stat_sum.lost);
else
sprintf(loss, "(na)");
if (xr_stat.rx.stat_sum.d)
sprintf(dup, "%d", xr_stat.rx.stat_sum.dup);
else
sprintf(dup, "(na)");
if (xr_stat.rx.stat_sum.j) {
unsigned jmin, jmax, jmean, jdev;
SAMPLES_TO_USEC(jmin, xr_stat.rx.stat_sum.jitter.min,
port->info.fmt.det.aud.clock_rate);
SAMPLES_TO_USEC(jmax, xr_stat.rx.stat_sum.jitter.max,
port->info.fmt.det.aud.clock_rate);
SAMPLES_TO_USEC(jmean, xr_stat.rx.stat_sum.jitter.mean,
port->info.fmt.det.aud.clock_rate);
SAMPLES_TO_USEC(jdev,
pj_math_stat_get_stddev(&xr_stat.rx.stat_sum.jitter),
port->info.fmt.det.aud.clock_rate);
sprintf(jitter, "%7.3f %7.3f %7.3f %7.3f",
jmin/1000.0, jmean/1000.0, jmax/1000.0, jdev/1000.0);
} else
sprintf(jitter, "(report not available)");
if (xr_stat.rx.stat_sum.t) {
sprintf(toh, "%11d %11d %11d %11d",
xr_stat.rx.stat_sum.toh.min,
xr_stat.rx.stat_sum.toh.mean,
xr_stat.rx.stat_sum.toh.max,
pj_math_stat_get_stddev(&xr_stat.rx.stat_sum.toh));
} else
sprintf(toh, "(report not available)");
if (xr_stat.rx.stat_sum.update.sec == 0)
strcpy(last_update, "never");
else {
pj_gettimeofday(&now);
PJ_TIME_VAL_SUB(now, xr_stat.rx.stat_sum.update);
sprintf(last_update, "%02ldh:%02ldm:%02ld.%03lds ago",
now.sec / 3600,
(now.sec % 3600) / 60,
now.sec % 60,
now.msec);
}
printf(" RX last update: %s\n"
" begin seq=%d, end seq=%d%s\n"
" pkt loss=%s, dup=%s%s\n"
" (msec) min avg max dev\n"
" jitter : %s\n"
" toh : %s\n",
last_update,
xr_stat.rx.stat_sum.begin_seq, xr_stat.rx.stat_sum.end_seq,
"",
loss, dup,
"",
jitter,
toh
);
if (xr_stat.tx.stat_sum.l)
sprintf(loss, "%d", xr_stat.tx.stat_sum.lost);
else
sprintf(loss, "(na)");
if (xr_stat.tx.stat_sum.d)
sprintf(dup, "%d", xr_stat.tx.stat_sum.dup);
else
sprintf(dup, "(na)");
if (xr_stat.tx.stat_sum.j) {
unsigned jmin, jmax, jmean, jdev;
SAMPLES_TO_USEC(jmin, xr_stat.tx.stat_sum.jitter.min,
port->info.fmt.det.aud.clock_rate);
SAMPLES_TO_USEC(jmax, xr_stat.tx.stat_sum.jitter.max,
port->info.fmt.det.aud.clock_rate);
SAMPLES_TO_USEC(jmean, xr_stat.tx.stat_sum.jitter.mean,
port->info.fmt.det.aud.clock_rate);
SAMPLES_TO_USEC(jdev,
pj_math_stat_get_stddev(&xr_stat.tx.stat_sum.jitter),
port->info.fmt.det.aud.clock_rate);
sprintf(jitter, "%7.3f %7.3f %7.3f %7.3f",
jmin/1000.0, jmean/1000.0, jmax/1000.0, jdev/1000.0);
} else
sprintf(jitter, "(report not available)");
if (xr_stat.tx.stat_sum.t) {
sprintf(toh, "%11d %11d %11d %11d",
xr_stat.tx.stat_sum.toh.min,
xr_stat.tx.stat_sum.toh.mean,
xr_stat.tx.stat_sum.toh.max,
pj_math_stat_get_stddev(&xr_stat.rx.stat_sum.toh));
} else
sprintf(toh, "(report not available)");
if (xr_stat.tx.stat_sum.update.sec == 0)
strcpy(last_update, "never");
else {
pj_gettimeofday(&now);
PJ_TIME_VAL_SUB(now, xr_stat.tx.stat_sum.update);
sprintf(last_update, "%02ldh:%02ldm:%02ld.%03lds ago",
now.sec / 3600,
(now.sec % 3600) / 60,
now.sec % 60,
now.msec);
}
printf(" TX last update: %s\n"
" begin seq=%d, end seq=%d%s\n"
" pkt loss=%s, dup=%s%s\n"
" (msec) min avg max dev\n"
" jitter : %s\n"
" toh : %s\n",
last_update,
xr_stat.tx.stat_sum.begin_seq, xr_stat.tx.stat_sum.end_seq,
"",
loss, dup,
"",
jitter,
toh
);
/* VoIP Metrics */
puts(" VoIP Metrics");
PRINT_VOIP_MTC_VAL(signal_lvl, xr_stat.rx.voip_mtc.signal_lvl);
PRINT_VOIP_MTC_VAL(noise_lvl, xr_stat.rx.voip_mtc.noise_lvl);
PRINT_VOIP_MTC_VAL(rerl, xr_stat.rx.voip_mtc.rerl);
PRINT_VOIP_MTC_VAL(r_factor, xr_stat.rx.voip_mtc.r_factor);
PRINT_VOIP_MTC_VAL(ext_r_factor, xr_stat.rx.voip_mtc.ext_r_factor);
PRINT_VOIP_MTC_VAL(mos_lq, xr_stat.rx.voip_mtc.mos_lq);
PRINT_VOIP_MTC_VAL(mos_cq, xr_stat.rx.voip_mtc.mos_cq);
switch ((xr_stat.rx.voip_mtc.rx_config>>6) & 3) {
case PJMEDIA_RTCP_XR_PLC_DIS:
sprintf(plc, "DISABLED");
break;
case PJMEDIA_RTCP_XR_PLC_ENH:
sprintf(plc, "ENHANCED");
break;
case PJMEDIA_RTCP_XR_PLC_STD:
sprintf(plc, "STANDARD");
break;
case PJMEDIA_RTCP_XR_PLC_UNK:
default:
sprintf(plc, "UNKNOWN");
break;
}
switch ((xr_stat.rx.voip_mtc.rx_config>>4) & 3) {
case PJMEDIA_RTCP_XR_JB_FIXED:
sprintf(jba, "FIXED");
break;
case PJMEDIA_RTCP_XR_JB_ADAPTIVE:
sprintf(jba, "ADAPTIVE");
break;
default:
sprintf(jba, "UNKNOWN");
break;
}
sprintf(jbr, "%d", xr_stat.rx.voip_mtc.rx_config & 0x0F);
if (xr_stat.rx.voip_mtc.update.sec == 0)
strcpy(last_update, "never");
else {
pj_gettimeofday(&now);
PJ_TIME_VAL_SUB(now, xr_stat.rx.voip_mtc.update);
sprintf(last_update, "%02ldh:%02ldm:%02ld.%03lds ago",
now.sec / 3600,
(now.sec % 3600) / 60,
now.sec % 60,
now.msec);
}
printf(" RX last update: %s\n"
" packets : loss rate=%d (%.2f%%), discard rate=%d (%.2f%%)\n"
" burst : density=%d (%.2f%%), duration=%d%s\n"
" gap : density=%d (%.2f%%), duration=%d%s\n"
" delay : round trip=%d%s, end system=%d%s\n"
" level : signal=%s%s, noise=%s%s, RERL=%s%s\n"
" quality : R factor=%s, ext R factor=%s\n"
" MOS LQ=%s, MOS CQ=%s\n"
" config : PLC=%s, JB=%s, JB rate=%s, Gmin=%d\n"
" JB delay : cur=%d%s, max=%d%s, abs max=%d%s\n",
last_update,
/* pakcets */
xr_stat.rx.voip_mtc.loss_rate, xr_stat.rx.voip_mtc.loss_rate*100.0/256,
xr_stat.rx.voip_mtc.discard_rate, xr_stat.rx.voip_mtc.discard_rate*100.0/256,
/* burst */
xr_stat.rx.voip_mtc.burst_den, xr_stat.rx.voip_mtc.burst_den*100.0/256,
xr_stat.rx.voip_mtc.burst_dur, "ms",
/* gap */
xr_stat.rx.voip_mtc.gap_den, xr_stat.rx.voip_mtc.gap_den*100.0/256,
xr_stat.rx.voip_mtc.gap_dur, "ms",
/* delay */
xr_stat.rx.voip_mtc.rnd_trip_delay, "ms",
xr_stat.rx.voip_mtc.end_sys_delay, "ms",
/* level */
signal_lvl, "dB",
noise_lvl, "dB",
rerl, "",
/* quality */
r_factor, ext_r_factor, mos_lq, mos_cq,
/* config */
plc, jba, jbr, xr_stat.rx.voip_mtc.gmin,
/* JB delay */
xr_stat.rx.voip_mtc.jb_nom, "ms",
xr_stat.rx.voip_mtc.jb_max, "ms",
xr_stat.rx.voip_mtc.jb_abs_max, "ms"
);
PRINT_VOIP_MTC_VAL(signal_lvl, xr_stat.tx.voip_mtc.signal_lvl);
PRINT_VOIP_MTC_VAL(noise_lvl, xr_stat.tx.voip_mtc.noise_lvl);
PRINT_VOIP_MTC_VAL(rerl, xr_stat.tx.voip_mtc.rerl);
PRINT_VOIP_MTC_VAL(r_factor, xr_stat.tx.voip_mtc.r_factor);
PRINT_VOIP_MTC_VAL(ext_r_factor, xr_stat.tx.voip_mtc.ext_r_factor);
PRINT_VOIP_MTC_VAL(mos_lq, xr_stat.tx.voip_mtc.mos_lq);
PRINT_VOIP_MTC_VAL(mos_cq, xr_stat.tx.voip_mtc.mos_cq);
switch ((xr_stat.tx.voip_mtc.rx_config>>6) & 3) {
case PJMEDIA_RTCP_XR_PLC_DIS:
sprintf(plc, "DISABLED");
break;
case PJMEDIA_RTCP_XR_PLC_ENH:
sprintf(plc, "ENHANCED");
break;
case PJMEDIA_RTCP_XR_PLC_STD:
sprintf(plc, "STANDARD");
break;
case PJMEDIA_RTCP_XR_PLC_UNK:
default:
sprintf(plc, "unknown");
break;
}
switch ((xr_stat.tx.voip_mtc.rx_config>>4) & 3) {
case PJMEDIA_RTCP_XR_JB_FIXED:
sprintf(jba, "FIXED");
break;
case PJMEDIA_RTCP_XR_JB_ADAPTIVE:
sprintf(jba, "ADAPTIVE");
break;
default:
sprintf(jba, "unknown");
break;
}
sprintf(jbr, "%d", xr_stat.tx.voip_mtc.rx_config & 0x0F);
if (xr_stat.tx.voip_mtc.update.sec == 0)
strcpy(last_update, "never");
else {
pj_gettimeofday(&now);
PJ_TIME_VAL_SUB(now, xr_stat.tx.voip_mtc.update);
sprintf(last_update, "%02ldh:%02ldm:%02ld.%03lds ago",
now.sec / 3600,
(now.sec % 3600) / 60,
now.sec % 60,
now.msec);
}
printf(" TX last update: %s\n"
" packets : loss rate=%d (%.2f%%), discard rate=%d (%.2f%%)\n"
" burst : density=%d (%.2f%%), duration=%d%s\n"
" gap : density=%d (%.2f%%), duration=%d%s\n"
" delay : round trip=%d%s, end system=%d%s\n"
" level : signal=%s%s, noise=%s%s, RERL=%s%s\n"
" quality : R factor=%s, ext R factor=%s\n"
" MOS LQ=%s, MOS CQ=%s\n"
" config : PLC=%s, JB=%s, JB rate=%s, Gmin=%d\n"
" JB delay : cur=%d%s, max=%d%s, abs max=%d%s\n",
last_update,
/* pakcets */
xr_stat.tx.voip_mtc.loss_rate, xr_stat.tx.voip_mtc.loss_rate*100.0/256,
xr_stat.tx.voip_mtc.discard_rate, xr_stat.tx.voip_mtc.discard_rate*100.0/256,
/* burst */
xr_stat.tx.voip_mtc.burst_den, xr_stat.tx.voip_mtc.burst_den*100.0/256,
xr_stat.tx.voip_mtc.burst_dur, "ms",
/* gap */
xr_stat.tx.voip_mtc.gap_den, xr_stat.tx.voip_mtc.gap_den*100.0/256,
xr_stat.tx.voip_mtc.gap_dur, "ms",
/* delay */
xr_stat.tx.voip_mtc.rnd_trip_delay, "ms",
xr_stat.tx.voip_mtc.end_sys_delay, "ms",
/* level */
signal_lvl, "dB",
noise_lvl, "dB",
rerl, "",
/* quality */
r_factor, ext_r_factor, mos_lq, mos_cq,
/* config */
plc, jba, jbr, xr_stat.tx.voip_mtc.gmin,
/* JB delay */
xr_stat.tx.voip_mtc.jb_nom, "ms",
xr_stat.tx.voip_mtc.jb_max, "ms",
xr_stat.tx.voip_mtc.jb_abs_max, "ms"
);
/* RTT delay (by receiver side) */
printf(" (msec) min avg max last dev\n");
printf(" RTT delay : %7.3f %7.3f %7.3f %7.3f %7.3f%s\n",
xr_stat.rtt.min / 1000.0,
xr_stat.rtt.mean / 1000.0,
xr_stat.rtt.max / 1000.0,
xr_stat.rtt.last / 1000.0,
pj_math_stat_get_stddev(&xr_stat.rtt) / 1000.0,
""
);
} while (0);
#endif /* PJMEDIA_HAS_RTCP_XR */
}
/*
* Print stream statistics
*/
static void print_stream_stat(pjmedia_stream *stream)
{
char duration[80], last_update[80];
char bps[16], ipbps[16], packets[16], bytes[16], ipbytes[16];
pjmedia_port *port;
pjmedia_rtcp_stat stat;
pj_time_val now;
pj_gettimeofday(&now);
pjmedia_stream_get_stat(stream, &stat);
pjmedia_stream_get_port(stream, &port);
puts("Stream statistics:");
/* Print duration */
PJ_TIME_VAL_SUB(now, stat.start);
sprintf(duration, " Duration: %02ld:%02ld:%02ld.%03ld",
now.sec / 3600,
(now.sec % 3600) / 60,
(now.sec % 60),
now.msec);
printf(" Info: audio %.*s@%dHz, %dms/frame, %sB/s (%sB/s +IP hdr)\n",
(int)port->info.encoding_name.slen,
port->info.encoding_name.ptr,
port->info.clock_rate,
port->info.samples_per_frame * 1000 / port->info.clock_rate,
good_number(bps, port->info.bytes_per_frame * port->info.clock_rate /
port->info.samples_per_frame),
good_number(ipbps, (port->info.bytes_per_frame+32) *
port->info.clock_rate / port->info.clock_rate));
if (stat.rx.update_cnt == 0)
strcpy(last_update, "never");
else {
pj_gettimeofday(&now);
PJ_TIME_VAL_SUB(now, stat.rx.update);
sprintf(last_update, "%02ldh:%02ldm:%02ld.%03lds ago",
now.sec / 3600,
(now.sec % 3600) / 60,
now.sec % 60,
now.msec);
}
printf(" RX stat last update: %s\n"
" total %s packets %sB received (%sB +IP hdr)%s\n"
" pkt loss=%d (%3.1f%%), dup=%d (%3.1f%%), reorder=%d (%3.1f%%)%s\n"
" (msec) min avg max last\n"
" loss period: %7.3f %7.3f %7.3f %7.3f%s\n"
" jitter : %7.3f %7.3f %7.3f %7.3f%s\n",
last_update,
good_number(packets, stat.rx.pkt),
good_number(bytes, stat.rx.bytes),
good_number(ipbytes, stat.rx.bytes + stat.rx.pkt * 32),
"",
stat.rx.loss,
stat.rx.loss * 100.0 / (stat.rx.pkt + stat.rx.loss),
stat.rx.dup,
stat.rx.dup * 100.0 / (stat.rx.pkt + stat.rx.loss),
stat.rx.reorder,
stat.rx.reorder * 100.0 / (stat.rx.pkt + stat.rx.loss),
"",
stat.rx.loss_period.min / 1000.0,
stat.rx.loss_period.avg / 1000.0,
stat.rx.loss_period.max / 1000.0,
stat.rx.loss_period.last / 1000.0,
"",
stat.rx.jitter.min / 1000.0,
stat.rx.jitter.avg / 1000.0,
stat.rx.jitter.max / 1000.0,
stat.rx.jitter.last / 1000.0,
""
);
if (stat.tx.update_cnt == 0)
strcpy(last_update, "never");
else {
pj_gettimeofday(&now);
PJ_TIME_VAL_SUB(now, stat.tx.update);
sprintf(last_update, "%02ldh:%02ldm:%02ld.%03lds ago",
now.sec / 3600,
(now.sec % 3600) / 60,
now.sec % 60,
now.msec);
}
printf(" TX stat last update: %s\n"
" total %s packets %sB sent (%sB +IP hdr)%s\n"
" pkt loss=%d (%3.1f%%), dup=%d (%3.1f%%), reorder=%d (%3.1f%%)%s\n"
" (msec) min avg max last\n"
" loss period: %7.3f %7.3f %7.3f %7.3f%s\n"
" jitter : %7.3f %7.3f %7.3f %7.3f%s\n",
last_update,
good_number(packets, stat.tx.pkt),
good_number(bytes, stat.tx.bytes),
good_number(ipbytes, stat.tx.bytes + stat.tx.pkt * 32),
"",
stat.tx.loss,
stat.tx.loss * 100.0 / (stat.tx.pkt + stat.tx.loss),
stat.tx.dup,
stat.tx.dup * 100.0 / (stat.tx.pkt + stat.tx.loss),
stat.tx.reorder,
stat.tx.reorder * 100.0 / (stat.tx.pkt + stat.tx.loss),
"",
stat.tx.loss_period.min / 1000.0,
stat.tx.loss_period.avg / 1000.0,
stat.tx.loss_period.max / 1000.0,
stat.tx.loss_period.last / 1000.0,
"",
stat.tx.jitter.min / 1000.0,
stat.tx.jitter.avg / 1000.0,
stat.tx.jitter.max / 1000.0,
stat.tx.jitter.last / 1000.0,
""
);
printf(" RTT delay : %7.3f %7.3f %7.3f %7.3f%s\n",
stat.rtt.min / 1000.0,
stat.rtt.avg / 1000.0,
stat.rtt.max / 1000.0,
stat.rtt.last / 1000.0,
""
);
}
static void print_call(int call_index)
{
struct call *call = &app.call[call_index];
int len;
pjsip_inv_session *inv = call->inv;
pjsip_dialog *dlg = inv->dlg;
struct media_stream *audio = &call->media[0];
char userinfo[128];
char duration[80], last_update[80];
char bps[16], ipbps[16], packets[16], bytes[16], ipbytes[16];
unsigned decor;
pj_time_val now;
decor = pj_log_get_decor();
pj_log_set_decor(PJ_LOG_HAS_NEWLINE);
pj_gettimeofday(&now);
if (app.report_filename)
puts(app.report_filename);
/* Print duration */
if (inv->state >= PJSIP_INV_STATE_CONFIRMED && call->connect_time.sec) {
PJ_TIME_VAL_SUB(now, call->connect_time);
sprintf(duration, " [duration: %02ld:%02ld:%02ld.%03ld]",
now.sec / 3600,
(now.sec % 3600) / 60,
(now.sec % 60),
now.msec);
} else {
duration[0] = '\0';
}
/* Call number and state */
PJ_LOG(3, (THIS_FILE,
"Call #%d: %s%s",
call_index, pjsip_inv_state_name(inv->state),
duration));
/* Call identification */
len = pjsip_hdr_print_on(dlg->remote.info, userinfo, sizeof(userinfo));
if (len < 0)
pj_ansi_strcpy(userinfo, "<--uri too long-->");
else
userinfo[len] = '\0';
PJ_LOG(3, (THIS_FILE, " %s", userinfo));
if (call->inv == NULL || call->inv->state < PJSIP_INV_STATE_CONFIRMED ||
call->connect_time.sec == 0)
{
pj_log_set_decor(decor);
return;
}
/* Signaling quality */
{
char pdd[64], connectdelay[64];
pj_time_val t;
if (call->response_time.sec) {
t = call->response_time;
PJ_TIME_VAL_SUB(t, call->start_time);
sprintf(pdd, "got 1st response in %ld ms", PJ_TIME_VAL_MSEC(t));
} else {
pdd[0] = '\0';
}
if (call->connect_time.sec) {
t = call->connect_time;
PJ_TIME_VAL_SUB(t, call->start_time);
sprintf(connectdelay, ", connected after: %ld ms",
PJ_TIME_VAL_MSEC(t));
} else {
connectdelay[0] = '\0';
}
PJ_LOG(3, (THIS_FILE,
" Signaling quality: %s%s", pdd, connectdelay));
}
PJ_LOG(3, (THIS_FILE,
" Stream #0: audio %.*s@%dHz, %dms/frame, %sB/s (%sB/s +IP hdr)",
(int)audio->si.fmt.encoding_name.slen,
audio->si.fmt.encoding_name.ptr,
audio->clock_rate,
audio->samples_per_frame * 1000 / audio->clock_rate,
good_number(bps, audio->bytes_per_frame * audio->clock_rate / audio->samples_per_frame),
good_number(ipbps, (audio->bytes_per_frame+32) * audio->clock_rate / audio->samples_per_frame)));
if (audio->rtcp.stat.rx.update_cnt == 0)
strcpy(last_update, "never");
else {
pj_gettimeofday(&now);
PJ_TIME_VAL_SUB(now, audio->rtcp.stat.rx.update);
sprintf(last_update, "%02ldh:%02ldm:%02ld.%03lds ago",
now.sec / 3600,
(now.sec % 3600) / 60,
now.sec % 60,
now.msec);
}
PJ_LOG(3, (THIS_FILE,
" RX stat last update: %s\n"
" total %s packets %sB received (%sB +IP hdr)%s\n"
" pkt loss=%d (%3.1f%%), dup=%d (%3.1f%%), reorder=%d (%3.1f%%)%s\n"
" (msec) min avg max last\n"
" loss period: %7.3f %7.3f %7.3f %7.3f%s\n"
" jitter : %7.3f %7.3f %7.3f %7.3f%s",
last_update,
good_number(packets, audio->rtcp.stat.rx.pkt),
good_number(bytes, audio->rtcp.stat.rx.bytes),
good_number(ipbytes, audio->rtcp.stat.rx.bytes + audio->rtcp.stat.rx.pkt * 32),
"",
audio->rtcp.stat.rx.loss,
audio->rtcp.stat.rx.loss * 100.0 / (audio->rtcp.stat.rx.pkt + audio->rtcp.stat.rx.loss),
audio->rtcp.stat.rx.dup,
audio->rtcp.stat.rx.dup * 100.0 / (audio->rtcp.stat.rx.pkt + audio->rtcp.stat.rx.loss),
audio->rtcp.stat.rx.reorder,
audio->rtcp.stat.rx.reorder * 100.0 / (audio->rtcp.stat.rx.pkt + audio->rtcp.stat.rx.loss),
"",
audio->rtcp.stat.rx.loss_period.min / 1000.0,
audio->rtcp.stat.rx.loss_period.mean / 1000.0,
audio->rtcp.stat.rx.loss_period.max / 1000.0,
audio->rtcp.stat.rx.loss_period.last / 1000.0,
"",
audio->rtcp.stat.rx.jitter.min / 1000.0,
audio->rtcp.stat.rx.jitter.mean / 1000.0,
audio->rtcp.stat.rx.jitter.max / 1000.0,
audio->rtcp.stat.rx.jitter.last / 1000.0,
""
));
if (audio->rtcp.stat.tx.update_cnt == 0)
strcpy(last_update, "never");
else {
pj_gettimeofday(&now);
PJ_TIME_VAL_SUB(now, audio->rtcp.stat.tx.update);
sprintf(last_update, "%02ldh:%02ldm:%02ld.%03lds ago",
now.sec / 3600,
(now.sec % 3600) / 60,
now.sec % 60,
now.msec);
}
PJ_LOG(3, (THIS_FILE,
" TX stat last update: %s\n"
" total %s packets %sB sent (%sB +IP hdr)%s\n"
" pkt loss=%d (%3.1f%%), dup=%d (%3.1f%%), reorder=%d (%3.1f%%)%s\n"
" (msec) min avg max last\n"
" loss period: %7.3f %7.3f %7.3f %7.3f%s\n"
" jitter : %7.3f %7.3f %7.3f %7.3f%s",
last_update,
good_number(packets, audio->rtcp.stat.tx.pkt),
good_number(bytes, audio->rtcp.stat.tx.bytes),
good_number(ipbytes, audio->rtcp.stat.tx.bytes + audio->rtcp.stat.tx.pkt * 32),
"",
audio->rtcp.stat.tx.loss,
audio->rtcp.stat.tx.loss * 100.0 / (audio->rtcp.stat.tx.pkt + audio->rtcp.stat.tx.loss),
audio->rtcp.stat.tx.dup,
audio->rtcp.stat.tx.dup * 100.0 / (audio->rtcp.stat.tx.pkt + audio->rtcp.stat.tx.loss),
audio->rtcp.stat.tx.reorder,
audio->rtcp.stat.tx.reorder * 100.0 / (audio->rtcp.stat.tx.pkt + audio->rtcp.stat.tx.loss),
"",
audio->rtcp.stat.tx.loss_period.min / 1000.0,
audio->rtcp.stat.tx.loss_period.mean / 1000.0,
audio->rtcp.stat.tx.loss_period.max / 1000.0,
audio->rtcp.stat.tx.loss_period.last / 1000.0,
"",
audio->rtcp.stat.tx.jitter.min / 1000.0,
audio->rtcp.stat.tx.jitter.mean / 1000.0,
audio->rtcp.stat.tx.jitter.max / 1000.0,
audio->rtcp.stat.tx.jitter.last / 1000.0,
""
));
PJ_LOG(3, (THIS_FILE,
" RTT delay : %7.3f %7.3f %7.3f %7.3f%s\n",
audio->rtcp.stat.rtt.min / 1000.0,
audio->rtcp.stat.rtt.mean / 1000.0,
audio->rtcp.stat.rtt.max / 1000.0,
audio->rtcp.stat.rtt.last / 1000.0,
""
));
pj_log_set_decor(decor);
}
