/* Stop sound */
static pj_status_t snd_stop()
{
pj_time_val now;
pj_status_t status;
if (strm == NULL) {
app_perror("snd not open", PJ_EINVALIDOP);
return PJ_EINVALIDOP;
}
status = pjmedia_aud_stream_stop(strm);
if (status != PJ_SUCCESS) {
app_perror("snd failed to stop", status);
}
status = pjmedia_aud_stream_destroy(strm);
strm = NULL;
pj_gettimeofday(&now);
PJ_TIME_VAL_SUB(now, t_start);
PJ_LOG(3,(THIS_FILE, "Duration: %d.%03d", now.sec, now.msec));
PJ_LOG(3,(THIS_FILE, "Captured: %d", rec_cnt));
PJ_LOG(3,(THIS_FILE, "Played: %d", play_cnt));
return status;
}
PJ_DEF(pj_status_t) pjsip_regc_get_info( pjsip_regc *regc,
pjsip_regc_info *info )
{
PJ_ASSERT_RETURN(regc && info, PJ_EINVAL);
pj_lock_acquire(regc->lock);
info->server_uri = regc->str_srv_url;
info->client_uri = regc->from_uri;
info->is_busy = (pj_atomic_get(regc->busy_ctr) || regc->has_tsx);
info->auto_reg = regc->auto_reg;
info->interval = regc->expires;
info->transport = regc->last_transport;
if (regc->has_tsx)
info->next_reg = 0;
else if (regc->auto_reg == 0)
info->next_reg = 0;
else if (regc->expires < 0)
info->next_reg = regc->expires;
else {
pj_time_val now, next_reg;
next_reg = regc->next_reg;
pj_gettimeofday(&now);
PJ_TIME_VAL_SUB(next_reg, now);
info->next_reg = next_reg.sec;
}
pj_lock_release(regc->lock);
return PJ_SUCCESS;
}
/*
* Let the AEC knows that a frame has been captured from the microphone.
*/
PJ_DEF(pj_status_t) echo_supp_capture( void *state,
pj_int16_t *rec_frm,
unsigned options )
{
echo_supp *ec = state;
pj_time_val now;
unsigned delay_ms;
PJ_UNUSED_ARG(options);
pj_gettimeofday(&now);
PJ_TIME_VAL_SUB(now, ec->last_signal);
delay_ms = PJ_TIME_VAL_MSEC(now);
if (delay_ms < ec->tail_ms) {
#if defined(PJMEDIA_ECHO_SUPPRESS_FACTOR) && PJMEDIA_ECHO_SUPPRESS_FACTOR!=0
unsigned i;
for (i=0; i<ec->samples_per_frame; ++i) {
rec_frm[i] = (pj_int16_t)(rec_frm[i] >>
PJMEDIA_ECHO_SUPPRESS_FACTOR);
}
#else
pjmedia_zero_samples(rec_frm, ec->samples_per_frame);
#endif
}
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;
}
static int timestamp_accuracy()
{
pj_timestamp freq, t1, t2;
pj_time_val tv1, tv2, tvtmp;
pj_uint32_t msec, tics;
pj_int64_t diff;
PJ_LOG(3,(THIS_FILE, "...testing frequency accuracy (pls wait)"));
pj_get_timestamp_freq(&freq);
/* Get the start time */
pj_gettimeofday(&tvtmp);
do {
pj_gettimeofday(&tv1);
} while (PJ_TIME_VAL_EQ(tvtmp, tv1));
pj_get_timestamp(&t1);
/* Sleep for 5 seconds */
pj_thread_sleep(10000);
/* Get end time */
pj_gettimeofday(&tvtmp);
do {
pj_gettimeofday(&tv2);
} while (PJ_TIME_VAL_EQ(tvtmp, tv2));
pj_get_timestamp(&t2);
/* Get the elapsed time */
PJ_TIME_VAL_SUB(tv2, tv1);
msec = PJ_TIME_VAL_MSEC(tv2);
/* Check that the frequency match the elapsed time */
tics = (unsigned)(t2.u64 - t1.u64);
diff = tics - (msec * freq.u64 / 1000);
if (diff < 0)
diff = -diff;
/* Only allow 1 msec mismatch */
if (diff > (pj_int64_t)(freq.u64 / 1000)) {
PJ_LOG(3,(THIS_FILE, "....error: timestamp drifted by %d usec after "
"%d msec",
(pj_uint32_t)(diff * 1000000 / freq.u64),
msec));
return -2000;
/* Otherwise just print warning if timestamp drifted by >1 usec */
} else if (diff > (pj_int64_t)(freq.u64 / 1000000)) {
PJ_LOG(3,(THIS_FILE, "....warning: timestamp drifted by %d usec after "
"%d msec",
(pj_uint32_t)(diff * 1000000 / freq.u64),
msec));
} else {
PJ_LOG(3,(THIS_FILE, "....good. Timestamp is accurate down to"
" nearest usec."));
}
return 0;
}
int echo_srv_common_loop(pj_atomic_t *bytes_counter)
{
pj_highprec_t last_received, avg_bw, highest_bw;
pj_time_val last_print;
unsigned count;
const char *ioqueue_name;
last_received = 0;
pj_gettimeofday(&last_print);
avg_bw = highest_bw = 0;
count = 0;
ioqueue_name = pj_ioqueue_name();
for (;;) {
pj_highprec_t received, cur_received, bw;
unsigned msec;
pj_time_val now, duration;
pj_thread_sleep(1000);
received = cur_received = pj_atomic_get(bytes_counter);
cur_received = cur_received - last_received;
pj_gettimeofday(&now);
duration = now;
PJ_TIME_VAL_SUB(duration, last_print);
msec = PJ_TIME_VAL_MSEC(duration);
bw = cur_received;
pj_highprec_mul(bw, 1000);
pj_highprec_div(bw, msec);
last_print = now;
last_received = received;
avg_bw = avg_bw + bw;
count++;
PJ_LOG(3,("", "%s UDP (%d threads): %u KB/s (avg=%u KB/s) %s",
ioqueue_name,
ECHO_SERVER_MAX_THREADS,
(unsigned)(bw / 1000),
(unsigned)(avg_bw / count / 1000),
(count==20 ? "<ses avg>" : "")));
if (count==20) {
if (avg_bw/count > highest_bw)
highest_bw = avg_bw/count;
count = 0;
avg_bw = 0;
PJ_LOG(3,("", "Highest average bandwidth=%u KB/s",
(unsigned)(highest_bw/1000)));
}
}
PJ_UNREACHED(return 0;)
}
PJ_DEF(unsigned) pj_timer_heap_poll( pj_timer_heap_t *ht,
pj_time_val *next_delay )
{
pj_time_val now;
unsigned count;
PJ_ASSERT_RETURN(ht, 0);
lock_timer_heap(ht);
if (!ht->cur_size && next_delay) {
next_delay->sec = next_delay->msec = PJ_MAXINT32;
unlock_timer_heap(ht);
return 0;
}
count = 0;
pj_gettickcount(&now);
while ( ht->cur_size &&
PJ_TIME_VAL_LTE(ht->heap[0]->_timer_value, now) &&
count < ht->max_entries_per_poll )
{
pj_timer_entry *node = remove_node(ht, 0);
pj_grp_lock_t *grp_lock;
++count;
grp_lock = node->_grp_lock;
node->_grp_lock = NULL;
unlock_timer_heap(ht);
PJ_RACE_ME(5);
if (node->cb)
(*node->cb)(ht, node);
if (grp_lock)
pj_grp_lock_dec_ref(grp_lock);
lock_timer_heap(ht);
}
if (ht->cur_size && next_delay) {
*next_delay = ht->heap[0]->_timer_value;
PJ_TIME_VAL_SUB(*next_delay, now);
if (next_delay->sec < 0 || next_delay->msec < 0)
next_delay->sec = next_delay->msec = 0;
} else if (next_delay) {
next_delay->sec = next_delay->msec = PJ_MAXINT32;
}
unlock_timer_heap(ht);
return count;
}
int main(int argc, char *argv[])
{
pj_caching_pool cp;
pj_time_val t0, t1;
pj_status_t status;
if (argc != 4) {
puts(desc);
return 1;
}
CHECK( pj_init() );
pj_caching_pool_init(&cp, NULL, 0);
CHECK( pjmedia_endpt_create(&cp.factory, NULL, 1, &mept) );
/* Register all codecs */
#if PJMEDIA_HAS_G711_CODEC
CHECK( pjmedia_codec_g711_init(mept) );
#endif
#if PJMEDIA_HAS_GSM_CODEC
CHECK( pjmedia_codec_gsm_init(mept) );
#endif
#if PJMEDIA_HAS_ILBC_CODEC
CHECK( pjmedia_codec_ilbc_init(mept, 30) );
#endif
#if PJMEDIA_HAS_SPEEX_CODEC
CHECK( pjmedia_codec_speex_init(mept, 0, 5, 5) );
#endif
#if PJMEDIA_HAS_G722_CODEC
CHECK( pjmedia_codec_g722_init(mept) );
#endif
pj_gettimeofday(&t0);
status = enc_dec_test(argv[1], argv[2], argv[3]);
pj_gettimeofday(&t1);
PJ_TIME_VAL_SUB(t1, t0);
pjmedia_endpt_destroy(mept);
pj_caching_pool_destroy(&cp);
pj_shutdown();
if (status == PJ_SUCCESS) {
puts("");
puts("Success");
printf("Duration: %ds.%03d\n", file_msec_duration/1000,
file_msec_duration%1000);
printf("Time: %lds.%03ld\n", t1.sec, t1.msec);
}
return 0;
}
/* get frame from mmap */
static pj_status_t vid4lin_stream_get_frame_mmap(vid4lin_stream *stream,
pjmedia_frame *frame)
{
struct v4l2_buffer buf;
pj_time_val time;
pj_status_t status = PJ_SUCCESS;
unsigned tmp_idx;
pj_bzero(&buf, sizeof(buf));
buf.type = V4L2_BUF_TYPE_VIDEO_CAPTURE;
buf.memory = V4L2_MEMORY_MMAP;
status = xioctl(stream->fd, VIDIOC_DQBUF, &buf);
if (status != PJ_SUCCESS)
return status;
if (frame->size < buf.bytesused) {
/* supplied buffer is too small */
pj_assert(!"frame buffer is too small for v4l2");
status = PJ_ETOOSMALL;
goto on_return;
}
time.sec = buf.timestamp.tv_sec;
time.msec = buf.timestamp.tv_usec / 1000;
PJ_TIME_VAL_SUB(time, stream->start_time);
frame->type = PJMEDIA_FRAME_TYPE_VIDEO;
frame->bit_info = 0;
frame->size = buf.bytesused;
frame->timestamp.u64 = PJ_UINT64(1) * PJ_TIME_VAL_MSEC(time) *
stream->param.clock_rate / PJ_UINT64(1000);
pj_memcpy(frame->buf, stream->buffers[buf.index].start, buf.bytesused);
on_return:
tmp_idx = buf.index;
pj_bzero(&buf, sizeof(buf));
buf.type = V4L2_BUF_TYPE_VIDEO_CAPTURE;
buf.memory = V4L2_MEMORY_MMAP;
buf.index = tmp_idx;
xioctl(stream->fd, VIDIOC_QBUF, &buf);
return status;
}
PJ_DEF(void) pj_timer_heap_dump(pj_timer_heap_t *ht)
{
lock_timer_heap(ht);
PJ_LOG(3,(THIS_FILE, "Dumping timer heap:"));
PJ_LOG(3,(THIS_FILE, " Cur size: %d entries, max: %d",
(int)ht->cur_size, (int)ht->max_size));
if (ht->cur_size) {
unsigned i;
pj_time_val now;
PJ_LOG(3,(THIS_FILE, " Entries: "));
PJ_LOG(3,(THIS_FILE, " _id\tId\tElapsed\tSource"));
PJ_LOG(3,(THIS_FILE, " ----------------------------------"));
pj_gettickcount(&now);
for (i=0; i<(unsigned)ht->cur_size; ++i) {
pj_timer_entry *e = ht->heap[i];
pj_time_val delta;
if (PJ_TIME_VAL_LTE(e->_timer_value, now))
delta.sec = delta.msec = 0;
else {
delta = e->_timer_value;
PJ_TIME_VAL_SUB(delta, now);
}
PJ_LOG(3,(THIS_FILE, " %d\t%d\t%d.%03d\t%s:%d",
e->_timer_id, e->id,
(int)delta.sec, (int)delta.msec,
e->src_file, e->src_line));
}
}
unlock_timer_heap(ht);
}
static int sdp_perform_test(pj_pool_factory *pf)
{
pj_pool_t *pool;
int inputlen, len;
pjsdp_session_desc *ses;
char buf[1500];
enum { LOOP=1000000 };
int i;
pj_time_val start, end;
printf("Parsing and printing %d SDP messages..\n", LOOP);
pool = pj_pool_create(pf, "", 4096, 0, NULL);
inputlen = strlen(sdp[0]);
pj_gettimeofday(&start);
for (i=0; i<LOOP; ++i) {
ses = pjsdp_parse(sdp[0], inputlen, pool);
len = pjsdp_print(ses, buf, sizeof(buf));
buf[len] = '\0';
pj_pool_reset(pool);
}
pj_gettimeofday(&end);
printf("Original:\n%s\n", sdp[0]);
printf("Parsed:\n%s\n", buf);
PJ_TIME_VAL_SUB(end, start);
printf("Time: %ld:%03lds\n", end.sec, end.msec);
if (end.msec==0 && end.sec==0) end.msec=1;
printf("Performance: %ld msg/sec\n", LOOP*1000/PJ_TIME_VAL_MSEC(end));
puts("");
pj_pool_release(pool);
return 0;
}
/*
* The generic test framework, used by most of the tests.
*/
static int perform_tsx_test(int dummy, char *target_uri, char *from_uri,
char *branch_param, int test_time,
const pjsip_method *method)
{
pjsip_tx_data *tdata;
pjsip_transaction *tsx;
pj_str_t target, from, tsx_key;
pjsip_via_hdr *via;
pj_time_val timeout;
pj_status_t status;
PJ_LOG(3,(THIS_FILE,
" please standby, this will take at most %d seconds..",
test_time));
/* Reset test. */
recv_count = 0;
test_complete = 0;
/* Init headers. */
target = pj_str(target_uri);
from = pj_str(from_uri);
/* Create request. */
status = pjsip_endpt_create_request( endpt, method, &target,
&from, &target, NULL, NULL, -1,
NULL, &tdata);
if (status != PJ_SUCCESS) {
app_perror(" Error: unable to create request", status);
return -100;
}
/* Set the branch param for test 1. */
via = pjsip_msg_find_hdr(tdata->msg, PJSIP_H_VIA, NULL);
via->branch_param = pj_str(branch_param);
/* Add additional reference to tdata to prevent transaction from
* deleting it.
*/
pjsip_tx_data_add_ref(tdata);
/* Create transaction. */
status = pjsip_tsx_create_uac( &tsx_user, tdata, &tsx);
if (status != PJ_SUCCESS) {
app_perror(" Error: unable to create UAC transaction", status);
pjsip_tx_data_dec_ref(tdata);
return -110;
}
/* Get transaction key. */
pj_strdup(tdata->pool, &tsx_key, &tsx->transaction_key);
/* Send the message. */
status = pjsip_tsx_send_msg(tsx, NULL);
// Ignore send result. Some tests do deliberately triggers error
// when sending message.
if (status != PJ_SUCCESS) {
// app_perror(" Error: unable to send request", status);
pjsip_tx_data_dec_ref(tdata);
// return -120;
}
/* Set test completion time. */
pj_gettimeofday(&timeout);
timeout.sec += test_time;
/* Wait until test complete. */
while (!test_complete) {
pj_time_val now, poll_delay = {0, 10};
pjsip_endpt_handle_events(endpt, &poll_delay);
pj_gettimeofday(&now);
if (now.sec > timeout.sec) {
PJ_LOG(3,(THIS_FILE, " Error: test has timed out"));
pjsip_tx_data_dec_ref(tdata);
return -130;
}
}
if (test_complete < 0) {
tsx = pjsip_tsx_layer_find_tsx(&tsx_key, PJ_TRUE);
if (tsx) {
pjsip_tsx_terminate(tsx, PJSIP_SC_REQUEST_TERMINATED);
pj_mutex_unlock(tsx->mutex);
flush_events(1000);
}
pjsip_tx_data_dec_ref(tdata);
return test_complete;
} else {
pj_time_val now;
/* Allow transaction to destroy itself */
flush_events(500);
/* Wait until test completes */
pj_gettimeofday(&now);
if (PJ_TIME_VAL_LT(now, timeout)) {
pj_time_val interval;
interval = timeout;
PJ_TIME_VAL_SUB(interval, now);
flush_events(PJ_TIME_VAL_MSEC(interval));
}
}
/* Make sure transaction has been destroyed. */
if (pjsip_tsx_layer_find_tsx(&tsx_key, PJ_FALSE) != NULL) {
PJ_LOG(3,(THIS_FILE, " Error: transaction has not been destroyed"));
pjsip_tx_data_dec_ref(tdata);
return -140;
}
/* Check tdata reference counter. */
if (pj_atomic_get(tdata->ref_cnt) != 1) {
PJ_LOG(3,(THIS_FILE, " Error: tdata reference counter is %d",
pj_atomic_get(tdata->ref_cnt)));
pjsip_tx_data_dec_ref(tdata);
return -150;
}
/* Destroy txdata */
pjsip_tx_data_dec_ref(tdata);
return PJ_SUCCESS;
}
/*
* 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,
""
);
}
PJ_DEF(pj_status_t) pjstun_get_mapped_addr( pj_pool_factory *pf,
int sock_cnt, pj_sock_t sock[],
const pj_str_t *srv1, int port1,
const pj_str_t *srv2, int port2,
pj_sockaddr_in mapped_addr[])
{
unsigned srv_cnt;
pj_sockaddr_in srv_addr[2];
int i, j, send_cnt = 0, nfds;
pj_pool_t *pool;
struct query_rec {
struct {
pj_uint32_t mapped_addr;
pj_uint32_t mapped_port;
} srv[2];
} *rec;
void *out_msg;
pj_size_t out_msg_len;
int wait_resp = 0;
pj_status_t status;
PJ_CHECK_STACK();
TRACE_((THIS_FILE, "Entering pjstun_get_mapped_addr()"));
/* Create pool. */
pool = pj_pool_create(pf, "stun%p", 400, 400, NULL);
if (!pool)
return PJ_ENOMEM;
/* Allocate client records */
rec = (struct query_rec*) pj_pool_calloc(pool, sock_cnt, sizeof(*rec));
if (!rec) {
status = PJ_ENOMEM;
goto on_error;
}
TRACE_((THIS_FILE, " Memory allocated."));
/* Create the outgoing BIND REQUEST message template */
status = pjstun_create_bind_req( pool, &out_msg, &out_msg_len,
pj_rand(), pj_rand());
if (status != PJ_SUCCESS)
goto on_error;
TRACE_((THIS_FILE, " Binding request created."));
/* Resolve servers. */
status = pj_sockaddr_in_init(&srv_addr[0], srv1, (pj_uint16_t)port1);
if (status != PJ_SUCCESS)
goto on_error;
srv_cnt = 1;
if (srv2 && port2) {
status = pj_sockaddr_in_init(&srv_addr[1], srv2, (pj_uint16_t)port2);
if (status != PJ_SUCCESS)
goto on_error;
if (srv_addr[1].sin_addr.s_addr != srv_addr[0].sin_addr.s_addr &&
srv_addr[1].sin_port != srv_addr[0].sin_port)
{
srv_cnt++;
}
}
TRACE_((THIS_FILE, " Server initialized, using %d server(s)", srv_cnt));
/* Init mapped addresses to zero */
pj_memset(mapped_addr, 0, sock_cnt * sizeof(pj_sockaddr_in));
/* We need these many responses */
wait_resp = sock_cnt * srv_cnt;
TRACE_((THIS_FILE, " Done initialization."));
#if defined(PJ_SELECT_NEEDS_NFDS) && PJ_SELECT_NEEDS_NFDS!=0
nfds = -1;
for (i=0; i<sock_cnt; ++i) {
if (sock[i] > nfds) {
nfds = sock[i];
}
}
#else
nfds = FD_SETSIZE-1;
#endif
/* Main retransmission loop. */
for (send_cnt=0; send_cnt<MAX_REQUEST; ++send_cnt) {
pj_time_val next_tx, now;
pj_fd_set_t r;
int select_rc;
PJ_FD_ZERO(&r);
/* Send messages to servers that has not given us response. */
for (i=0; i<sock_cnt && status==PJ_SUCCESS; ++i) {
for (j=0; j<srv_cnt && status==PJ_SUCCESS; ++j) {
pjstun_msg_hdr *msg_hdr = (pjstun_msg_hdr*) out_msg;
pj_ssize_t sent_len;
if (rec[i].srv[j].mapped_port != 0)
continue;
/* Modify message so that we can distinguish response. */
msg_hdr->tsx[2] = pj_htonl(i);
msg_hdr->tsx[3] = pj_htonl(j);
/* Send! */
sent_len = out_msg_len;
status = pj_sock_sendto(sock[i], out_msg, &sent_len, 0,
(pj_sockaddr_t*)&srv_addr[j],
sizeof(pj_sockaddr_in));
}
}
/* All requests sent.
* The loop below will wait for responses until all responses have
* been received (i.e. wait_resp==0) or timeout occurs, which then
* we'll go to the next retransmission iteration.
*/
TRACE_((THIS_FILE, " Request(s) sent, counter=%d", send_cnt));
/* Calculate time of next retransmission. */
pj_gettimeofday(&next_tx);
next_tx.sec += (stun_timer[send_cnt]/1000);
next_tx.msec += (stun_timer[send_cnt]%1000);
pj_time_val_normalize(&next_tx);
for (pj_gettimeofday(&now), select_rc=1;
status==PJ_SUCCESS && select_rc>=1 && wait_resp>0
&& PJ_TIME_VAL_LT(now, next_tx);
pj_gettimeofday(&now))
{
pj_time_val timeout;
timeout = next_tx;
PJ_TIME_VAL_SUB(timeout, now);
for (i=0; i<sock_cnt; ++i) {
PJ_FD_SET(sock[i], &r);
}
select_rc = pj_sock_select(nfds+1, &r, NULL, NULL, &timeout);
TRACE_((THIS_FILE, " select() rc=%d", select_rc));
if (select_rc < 1)
continue;
for (i=0; i<sock_cnt; ++i) {
int sock_idx, srv_idx;
pj_ssize_t len;
pjstun_msg msg;
pj_sockaddr_in addr;
int addrlen = sizeof(addr);
pjstun_mapped_addr_attr *attr;
char recv_buf[128];
if (!PJ_FD_ISSET(sock[i], &r))
continue;
len = sizeof(recv_buf);
status = pj_sock_recvfrom( sock[i], recv_buf,
&len, 0,
(pj_sockaddr_t*)&addr,
&addrlen);
if (status != PJ_SUCCESS) {
char errmsg[PJ_ERR_MSG_SIZE];
PJ_LOG(4,(THIS_FILE, "recvfrom() error ignored: %s",
pj_strerror(status, errmsg,sizeof(errmsg)).ptr));
/* Ignore non-PJ_SUCCESS status.
* It possible that other SIP entity is currently
* sending SIP request to us, and because SIP message
* is larger than STUN, we could get EMSGSIZE when
* we call recvfrom().
*/
status = PJ_SUCCESS;
continue;
}
status = pjstun_parse_msg(recv_buf, len, &msg);
if (status != PJ_SUCCESS) {
char errmsg[PJ_ERR_MSG_SIZE];
PJ_LOG(4,(THIS_FILE, "STUN parsing error ignored: %s",
pj_strerror(status, errmsg,sizeof(errmsg)).ptr));
/* Also ignore non-successful parsing. This may not
* be STUN response at all. See the comment above.
*/
status = PJ_SUCCESS;
continue;
}
sock_idx = pj_ntohl(msg.hdr->tsx[2]);
srv_idx = pj_ntohl(msg.hdr->tsx[3]);
if (sock_idx<0 || sock_idx>=sock_cnt || sock_idx!=i ||
srv_idx<0 || srv_idx>=2)
{
status = PJLIB_UTIL_ESTUNININDEX;
continue;
}
if (pj_ntohs(msg.hdr->type) != PJSTUN_BINDING_RESPONSE) {
status = PJLIB_UTIL_ESTUNNOBINDRES;
continue;
}
if (rec[sock_idx].srv[srv_idx].mapped_port != 0) {
/* Already got response */
continue;
}
/* From this part, we consider the packet as a valid STUN
* response for our request.
*/
--wait_resp;
if (pjstun_msg_find_attr(&msg, PJSTUN_ATTR_ERROR_CODE) != NULL) {
status = PJLIB_UTIL_ESTUNRECVERRATTR;
continue;
}
attr = (pjstun_mapped_addr_attr*)
pjstun_msg_find_attr(&msg, PJSTUN_ATTR_MAPPED_ADDR);
if (!attr) {
attr = (pjstun_mapped_addr_attr*)
pjstun_msg_find_attr(&msg, PJSTUN_ATTR_XOR_MAPPED_ADDR);
if (!attr || attr->family != 1) {
status = PJLIB_UTIL_ESTUNNOMAP;
continue;
}
}
rec[sock_idx].srv[srv_idx].mapped_addr = attr->addr;
rec[sock_idx].srv[srv_idx].mapped_port = attr->port;
if (pj_ntohs(attr->hdr.type) == PJSTUN_ATTR_XOR_MAPPED_ADDR) {
rec[sock_idx].srv[srv_idx].mapped_addr ^= pj_htonl(STUN_MAGIC);
rec[sock_idx].srv[srv_idx].mapped_port ^= pj_htons(STUN_MAGIC >> 16);
}
}
}
/* The best scenario is if all requests have been replied.
* Then we don't need to go to the next retransmission iteration.
*/
if (wait_resp <= 0)
break;
}
static int file_test_internal(void)
{
enum { FILE_MAX_AGE = 1000 };
pj_oshandle_t fd = 0;
pj_status_t status;
char readbuf[sizeof(buffer)+16];
pj_file_stat stat;
pj_time_val start_time;
pj_ssize_t size;
pj_off_t pos;
PJ_LOG(3,("", "..file io test.."));
/* Get time. */
pj_gettimeofday(&start_time);
/* Delete original file if exists. */
if (pj_file_exists(FILENAME))
pj_file_delete(FILENAME);
/*
* Write data to the file.
*/
status = pj_file_open(NULL, FILENAME, PJ_O_WRONLY, &fd);
if (status != PJ_SUCCESS) {
app_perror("...file_open() error", status);
return -10;
}
size = sizeof(buffer);
status = pj_file_write(fd, buffer, &size);
if (status != PJ_SUCCESS) {
app_perror("...file_write() error", status);
pj_file_close(fd);
return -20;
}
if (size != sizeof(buffer))
return -25;
status = pj_file_close(fd);
if (status != PJ_SUCCESS) {
app_perror("...file_close() error", status);
return -30;
}
/* Check the file existance and size. */
if (!pj_file_exists(FILENAME))
return -40;
if (pj_file_size(FILENAME) != sizeof(buffer))
return -50;
/* Get file stat. */
status = pj_file_getstat(FILENAME, &stat);
if (status != PJ_SUCCESS)
return -60;
/* Check stat size. */
if (stat.size != sizeof(buffer))
return -70;
#if INCLUDE_FILE_TIME_TEST
/* Check file creation time >= start_time. */
if (!PJ_TIME_VAL_GTE(stat.ctime, start_time))
return -80;
/* Check file creation time is not much later. */
PJ_TIME_VAL_SUB(stat.ctime, start_time);
if (stat.ctime.sec > FILE_MAX_AGE)
return -90;
/* Check file modification time >= start_time. */
if (!PJ_TIME_VAL_GTE(stat.mtime, start_time))
return -80;
/* Check file modification time is not much later. */
PJ_TIME_VAL_SUB(stat.mtime, start_time);
if (stat.mtime.sec > FILE_MAX_AGE)
return -90;
/* Check file access time >= start_time. */
if (!PJ_TIME_VAL_GTE(stat.atime, start_time))
return -80;
/* Check file access time is not much later. */
PJ_TIME_VAL_SUB(stat.atime, start_time);
if (stat.atime.sec > FILE_MAX_AGE)
return -90;
#endif
/*
* Re-open the file and read data.
*/
status = pj_file_open(NULL, FILENAME, PJ_O_RDONLY, &fd);
if (status != PJ_SUCCESS) {
app_perror("...file_open() error", status);
return -100;
}
size = 0;
while (size < (pj_ssize_t)sizeof(readbuf)) {
pj_ssize_t read;
read = 1;
status = pj_file_read(fd, &readbuf[size], &read);
if (status != PJ_SUCCESS) {
PJ_LOG(3,("", "...error reading file after %d bytes (error follows)",
size));
app_perror("...error", status);
return -110;
}
if (read == 0) {
// EOF
break;
}
size += read;
}
if (size != sizeof(buffer))
return -120;
/*
if (!pj_file_eof(fd, PJ_O_RDONLY))
return -130;
*/
if (pj_memcmp(readbuf, buffer, size) != 0)
return -140;
/* Seek test. */
status = pj_file_setpos(fd, 4, PJ_SEEK_SET);
if (status != PJ_SUCCESS) {
app_perror("...file_setpos() error", status);
return -141;
}
/* getpos test. */
status = pj_file_getpos(fd, &pos);
if (status != PJ_SUCCESS) {
app_perror("...file_getpos() error", status);
return -142;
}
if (pos != 4)
return -143;
status = pj_file_close(fd);
if (status != PJ_SUCCESS) {
app_perror("...file_close() error", status);
return -150;
}
/*
* Rename test.
*/
status = pj_file_move(FILENAME, NEWNAME);
if (status != PJ_SUCCESS) {
app_perror("...file_move() error", status);
return -160;
}
if (pj_file_exists(FILENAME))
return -170;
if (!pj_file_exists(NEWNAME))
return -180;
if (pj_file_size(NEWNAME) != sizeof(buffer))
return -190;
/* Delete test. */
status = pj_file_delete(NEWNAME);
if (status != PJ_SUCCESS) {
app_perror("...file_delete() error", status);
return -200;
}
if (pj_file_exists(NEWNAME))
return -210;
PJ_LOG(3,("", "...success"));
return PJ_SUCCESS;
}
int main(int argc, char *argv[])
{
static char report[1024];
printf("PJSIP Performance Measurement Tool v%s\n"
"(c)2006 pjsip.org\n\n",
PJ_VERSION);
if (create_app() != 0)
return 1;
if (init_options(argc, argv) != 0)
return 1;
if (init_sip() != 0)
return 1;
if (init_media() != 0)
return 1;
pj_log_set_level(app.log_level);
if (app.log_level > 4) {
pjsip_endpt_register_module(app.sip_endpt, &msg_logger);
}
/* Misc infos */
if (app.client.dst_uri.slen != 0) {
if (app.client.method.id == PJSIP_INVITE_METHOD) {
if (app.client.stateless) {
PJ_LOG(3,(THIS_FILE,
"Info: --stateless option makes no sense for INVITE,"
" ignored."));
}
}
}
if (app.client.dst_uri.slen) {
/* Client mode */
pj_status_t status;
char test_type[64];
unsigned msec_req, msec_res;
unsigned i;
/* Get the job name */
if (app.client.method.id == PJSIP_INVITE_METHOD) {
pj_ansi_strcpy(test_type, "INVITE calls");
} else if (app.client.stateless) {
pj_ansi_sprintf(test_type, "stateless %.*s requests",
(int)app.client.method.name.slen,
app.client.method.name.ptr);
} else {
pj_ansi_sprintf(test_type, "stateful %.*s requests",
(int)app.client.method.name.slen,
app.client.method.name.ptr);
}
printf("Sending %d %s to '%.*s' with %d maximum outstanding jobs, please wait..\n",
app.client.job_count, test_type,
(int)app.client.dst_uri.slen, app.client.dst_uri.ptr,
app.client.job_window);
for (i=0; i<app.thread_count; ++i) {
status = pj_thread_create(app.pool, NULL, &client_thread,
(void*)(long)i, 0, 0, &app.thread[i]);
if (status != PJ_SUCCESS) {
app_perror(THIS_FILE, "Unable to create thread", status);
return 1;
}
}
for (i=0; i<app.thread_count; ++i) {
pj_thread_join(app.thread[i]);
app.thread[i] = NULL;
}
if (app.client.last_completion.sec) {
pj_time_val duration;
duration = app.client.last_completion;
PJ_TIME_VAL_SUB(duration, app.client.first_request);
msec_res = PJ_TIME_VAL_MSEC(duration);
} else {
msec_res = app.client.timeout * 1000;
}
if (msec_res == 0) msec_res = 1;
if (app.client.requests_sent.sec) {
pj_time_val duration;
duration = app.client.requests_sent;
PJ_TIME_VAL_SUB(duration, app.client.first_request);
msec_req = PJ_TIME_VAL_MSEC(duration);
} else {
msec_req = app.client.timeout * 1000;
}
if (msec_req == 0) msec_req = 1;
if (app.client.job_submitted < app.client.job_count)
puts("\ntimed-out!\n");
else
puts("\ndone.\n");
pj_ansi_snprintf(
report, sizeof(report),
"Total %d %s sent in %d ms at rate of %d/sec\n"
"Total %d responses receieved in %d ms at rate of %d/sec:",
app.client.job_submitted, test_type, msec_req,
app.client.job_submitted * 1000 / msec_req,
app.client.total_responses, msec_res,
app.client.total_responses*1000/msec_res);
write_report(report);
/* Print detailed response code received */
pj_ansi_sprintf(report, "\nDetailed responses received:");
write_report(report);
for (i=0; i<PJ_ARRAY_SIZE(app.client.response_codes); ++i) {
const pj_str_t *reason;
if (app.client.response_codes[i] == 0)
continue;
reason = pjsip_get_status_text(i);
pj_ansi_snprintf( report, sizeof(report),
" - %d responses: %7d (%.*s)",
i, app.client.response_codes[i],
(int)reason->slen, reason->ptr);
write_report(report);
}
/* Total responses and rate */
pj_ansi_snprintf( report, sizeof(report),
" ------\n"
" TOTAL responses: %7d (rate=%d/sec)\n",
app.client.total_responses,
app.client.total_responses*1000/msec_res);
write_report(report);
pj_ansi_sprintf(report, "Maximum outstanding job: %d",
app.client.stat_max_window);
write_report(report);
} else {
/* Server mode */
char s[10], *unused;
pj_status_t status;
unsigned i;
puts("pjsip-perf started in server-mode");
printf("Receiving requests on the following URIs:\n"
" sip:0@%.*s:%d%s for stateless handling\n"
" sip:1@%.*s:%d%s for stateful handling\n"
" sip:2@%.*s:%d%s for call handling\n",
(int)app.local_addr.slen,
app.local_addr.ptr,
app.local_port,
(app.use_tcp ? ";transport=tcp" : ""),
(int)app.local_addr.slen,
app.local_addr.ptr,
app.local_port,
(app.use_tcp ? ";transport=tcp" : ""),
(int)app.local_addr.slen,
app.local_addr.ptr,
app.local_port,
(app.use_tcp ? ";transport=tcp" : ""));
printf("INVITE with non-matching user part will be handled call-statefully\n");
for (i=0; i<app.thread_count; ++i) {
status = pj_thread_create(app.pool, NULL, &server_thread,
(void*)(long)i, 0, 0, &app.thread[i]);
if (status != PJ_SUCCESS) {
app_perror(THIS_FILE, "Unable to create thread", status);
return 1;
}
}
puts("\nPress <ENTER> to quit\n");
fflush(stdout);
unused = fgets(s, sizeof(s), stdin);
PJ_UNUSED_ARG(unused);
app.thread_quit = PJ_TRUE;
for (i=0; i<app.thread_count; ++i) {
pj_thread_join(app.thread[i]);
app.thread[i] = NULL;
}
puts("");
}
destroy_app();
return 0;
}
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);
}
/* Dump media session */
static void dump_media_session(const char *indent,
char *buf, unsigned maxlen,
pjsua_call *call)
{
unsigned i;
char *p = buf, *end = buf+maxlen;
int len;
for (i=0; i<call->med_cnt; ++i) {
pjsua_call_media *call_med = &call->media[i];
pjmedia_rtcp_stat stat;
pj_bool_t has_stat;
pjmedia_transport_info tp_info;
char rem_addr_buf[80];
char codec_info[32] = {'0'};
char rx_info[80] = {'\0'};
char tx_info[80] = {'\0'};
const char *rem_addr;
const char *dir_str;
const char *media_type_str;
switch (call_med->type) {
case PJMEDIA_TYPE_AUDIO:
media_type_str = "audio";
break;
case PJMEDIA_TYPE_VIDEO:
media_type_str = "video";
break;
case PJMEDIA_TYPE_APPLICATION:
media_type_str = "application";
break;
default:
media_type_str = "unknown";
break;
}
/* Check if the stream is deactivated */
if (call_med->tp == NULL ||
(!call_med->strm.a.stream && !call_med->strm.v.stream))
{
len = pj_ansi_snprintf(p, end-p,
"%s #%d %s deactivated\n",
indent, i, media_type_str);
if (len < 1 || len > end-p) {
*p = '\0';
return;
}
p += len;
continue;
}
pjmedia_transport_info_init(&tp_info);
pjmedia_transport_get_info(call_med->tp, &tp_info);
// rem_addr will contain actual address of RTP originator, instead of
// remote RTP address specified by stream which is fetched from the SDP.
// Please note that we are assuming only one stream per call.
//rem_addr = pj_sockaddr_print(&info.stream_info[i].rem_addr,
// rem_addr_buf, sizeof(rem_addr_buf), 3);
if (pj_sockaddr_has_addr(&tp_info.src_rtp_name)) {
rem_addr = pj_sockaddr_print(&tp_info.src_rtp_name, rem_addr_buf,
sizeof(rem_addr_buf), 3);
} else {
pj_ansi_snprintf(rem_addr_buf, sizeof(rem_addr_buf), "-");
rem_addr = rem_addr_buf;
}
if (call_med->dir == PJMEDIA_DIR_NONE) {
/* To handle when the stream that is currently being paused
* (http://trac.pjsip.org/repos/ticket/1079)
*/
dir_str = "inactive";
} else if (call_med->dir == PJMEDIA_DIR_ENCODING)
dir_str = "sendonly";
else if (call_med->dir == PJMEDIA_DIR_DECODING)
dir_str = "recvonly";
else if (call_med->dir == PJMEDIA_DIR_ENCODING_DECODING)
dir_str = "sendrecv";
else
dir_str = "inactive";
if (call_med->type == PJMEDIA_TYPE_AUDIO) {
pjmedia_stream *stream = call_med->strm.a.stream;
pjmedia_stream_info info;
pjmedia_stream_get_stat(stream, &stat);
has_stat = PJ_TRUE;
pjmedia_stream_get_info(stream, &info);
pj_ansi_snprintf(codec_info, sizeof(codec_info), " %.*s @%dkHz",
(int)info.fmt.encoding_name.slen,
info.fmt.encoding_name.ptr,
info.fmt.clock_rate / 1000);
pj_ansi_snprintf(rx_info, sizeof(rx_info), "pt=%d,",
info.rx_pt);
pj_ansi_snprintf(tx_info, sizeof(tx_info), "pt=%d, ptime=%d,",
info.tx_pt,
info.param->setting.frm_per_pkt*
info.param->info.frm_ptime);
#if defined(PJMEDIA_HAS_VIDEO) && (PJMEDIA_HAS_VIDEO != 0)
} else if (call_med->type == PJMEDIA_TYPE_VIDEO) {
pjmedia_vid_stream *stream = call_med->strm.v.stream;
pjmedia_vid_stream_info info;
pjmedia_vid_stream_get_stat(stream, &stat);
has_stat = PJ_TRUE;
pjmedia_vid_stream_get_info(stream, &info);
pj_ansi_snprintf(codec_info, sizeof(codec_info), " %.*s",
(int)info.codec_info.encoding_name.slen,
info.codec_info.encoding_name.ptr);
if (call_med->dir & PJMEDIA_DIR_DECODING) {
pjmedia_video_format_detail *vfd;
vfd = pjmedia_format_get_video_format_detail(
&info.codec_param->dec_fmt, PJ_TRUE);
pj_ansi_snprintf(rx_info, sizeof(rx_info),
"pt=%d, size=%dx%d, fps=%.2f,",
info.rx_pt,
vfd->size.w, vfd->size.h,
vfd->fps.num*1.0/vfd->fps.denum);
}
if (call_med->dir & PJMEDIA_DIR_ENCODING) {
pjmedia_video_format_detail *vfd;
vfd = pjmedia_format_get_video_format_detail(
&info.codec_param->enc_fmt, PJ_TRUE);
pj_ansi_snprintf(tx_info, sizeof(tx_info),
"pt=%d, size=%dx%d, fps=%.2f,",
info.tx_pt,
vfd->size.w, vfd->size.h,
vfd->fps.num*1.0/vfd->fps.denum);
}
#endif /* PJMEDIA_HAS_VIDEO */
} else {
has_stat = PJ_FALSE;
}
len = pj_ansi_snprintf(p, end-p,
"%s #%d %s%s, %s, peer=%s\n",
indent,
call_med->idx,
media_type_str,
codec_info,
dir_str,
rem_addr);
if (len < 1 || len > end-p) {
*p = '\0';
return;
}
p += len;
/* Get and ICE SRTP status */
if (call_med->tp) {
pjmedia_transport_info tp_info;
pjmedia_transport_info_init(&tp_info);
pjmedia_transport_get_info(call_med->tp, &tp_info);
if (tp_info.specific_info_cnt > 0) {
unsigned j;
for (j = 0; j < tp_info.specific_info_cnt; ++j) {
if (tp_info.spc_info[j].type == PJMEDIA_TRANSPORT_TYPE_SRTP)
{
pjmedia_srtp_info *srtp_info =
(pjmedia_srtp_info*) tp_info.spc_info[j].buffer;
len = pj_ansi_snprintf(p, end-p,
" %s SRTP status: %s Crypto-suite: %s",
indent,
(srtp_info->active?"Active":"Not active"),
srtp_info->tx_policy.name.ptr);
if (len > 0 && len < end-p) {
p += len;
*p++ = '\n';
*p = '\0';
}
} else if (tp_info.spc_info[j].type==PJMEDIA_TRANSPORT_TYPE_ICE) {
const pjmedia_ice_transport_info *ii;
unsigned jj;
ii = (const pjmedia_ice_transport_info*)
tp_info.spc_info[j].buffer;
len = pj_ansi_snprintf(p, end-p,
" %s ICE role: %s, state: %s, comp_cnt: %u",
indent,
pj_ice_sess_role_name(ii->role),
pj_ice_strans_state_name(ii->sess_state),
ii->comp_cnt);
if (len > 0 && len < end-p) {
p += len;
*p++ = '\n';
*p = '\0';
}
for (jj=0; ii->sess_state==PJ_ICE_STRANS_STATE_RUNNING && jj<2; ++jj) {
const char *type1 = pj_ice_get_cand_type_name(ii->comp[jj].lcand_type);
const char *type2 = pj_ice_get_cand_type_name(ii->comp[jj].rcand_type);
char addr1[PJ_INET6_ADDRSTRLEN+10];
char addr2[PJ_INET6_ADDRSTRLEN+10];
if (pj_sockaddr_has_addr(&ii->comp[jj].lcand_addr))
pj_sockaddr_print(&ii->comp[jj].lcand_addr, addr1, sizeof(addr1), 3);
else
strcpy(addr1, "0.0.0.0:0");
if (pj_sockaddr_has_addr(&ii->comp[jj].rcand_addr))
pj_sockaddr_print(&ii->comp[jj].rcand_addr, addr2, sizeof(addr2), 3);
else
strcpy(addr2, "0.0.0.0:0");
len = pj_ansi_snprintf(p, end-p,
" %s [%d]: L:%s (%c) --> R:%s (%c)\n",
indent, jj,
addr1, type1[0],
addr2, type2[0]);
if (len > 0 && len < end-p) {
p += len;
*p = '\0';
}
}
}
}
}
}
if (has_stat) {
len = dump_media_stat(indent, p, end-p, &stat,
rx_info, tx_info);
p += len;
}
#if defined(PJMEDIA_HAS_RTCP_XR) && (PJMEDIA_HAS_RTCP_XR != 0)
# define SAMPLES_TO_USEC(usec, samples, clock_rate) \
do { \
if (samples <= 4294) \
usec = samples * 1000000 / clock_rate; \
else { \
usec = samples * 1000 / clock_rate; \
usec *= 1000; \
} \
} while(0)
# define PRINT_VOIP_MTC_VAL(s, v) \
if (v == 127) \
sprintf(s, "(na)"); \
else \
sprintf(s, "%d", v)
# define VALIDATE_PRINT_BUF() \
if (len < 1 || len > end-p) { *p = '\0'; return; } \
p += len; *p++ = '\n'; *p = '\0'
if (call_med->type == PJMEDIA_TYPE_AUDIO) {
pjmedia_stream_info info;
char last_update[64];
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;
unsigned clock_rate;
pj_time_val now;
if (pjmedia_stream_get_stat_xr(call_med->strm.a.stream,
&xr_stat) != PJ_SUCCESS)
{
continue;
}
if (pjmedia_stream_get_info(call_med->strm.a.stream, &info)
!= PJ_SUCCESS)
{
continue;
}
clock_rate = info.fmt.clock_rate;
pj_gettimeofday(&now);
len = pj_ansi_snprintf(p, end-p, "\n%s Extended reports:", indent);
VALIDATE_PRINT_BUF();
/* Statistics Summary */
len = pj_ansi_snprintf(p, end-p, "%s Statistics Summary", indent);
VALIDATE_PRINT_BUF();
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,
clock_rate);
SAMPLES_TO_USEC(jmax, xr_stat.rx.stat_sum.jitter.max,
clock_rate);
SAMPLES_TO_USEC(jmean, xr_stat.rx.stat_sum.jitter.mean,
clock_rate);
SAMPLES_TO_USEC(jdev,
pj_math_stat_get_stddev(&xr_stat.rx.stat_sum.jitter),
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);
}
len = pj_ansi_snprintf(p, end-p,
"%s RX last update: %s\n"
"%s begin seq=%d, end seq=%d\n"
"%s pkt loss=%s, dup=%s\n"
"%s (msec) min avg max dev\n"
"%s jitter : %s\n"
"%s toh : %s",
indent, last_update,
indent,
xr_stat.rx.stat_sum.begin_seq, xr_stat.rx.stat_sum.end_seq,
indent, loss, dup,
indent,
indent, jitter,
indent, toh
);
VALIDATE_PRINT_BUF();
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,
clock_rate);
SAMPLES_TO_USEC(jmax, xr_stat.tx.stat_sum.jitter.max,
clock_rate);
SAMPLES_TO_USEC(jmean, xr_stat.tx.stat_sum.jitter.mean,
clock_rate);
SAMPLES_TO_USEC(jdev,
pj_math_stat_get_stddev(&xr_stat.tx.stat_sum.jitter),
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);
}
len = pj_ansi_snprintf(p, end-p,
"%s TX last update: %s\n"
"%s begin seq=%d, end seq=%d\n"
"%s pkt loss=%s, dup=%s\n"
"%s (msec) min avg max dev\n"
"%s jitter : %s\n"
"%s toh : %s",
indent, last_update,
indent,
xr_stat.tx.stat_sum.begin_seq, xr_stat.tx.stat_sum.end_seq,
indent, loss, dup,
indent,
indent, jitter,
indent, toh
);
VALIDATE_PRINT_BUF();
/* VoIP Metrics */
len = pj_ansi_snprintf(p, end-p, "%s VoIP Metrics", indent);
VALIDATE_PRINT_BUF();
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);
}
len = pj_ansi_snprintf(p, end-p,
"%s RX last update: %s\n"
"%s packets : loss rate=%d (%.2f%%), discard rate=%d (%.2f%%)\n"
"%s burst : density=%d (%.2f%%), duration=%d%s\n"
"%s gap : density=%d (%.2f%%), duration=%d%s\n"
"%s delay : round trip=%d%s, end system=%d%s\n"
"%s level : signal=%s%s, noise=%s%s, RERL=%s%s\n"
"%s quality : R factor=%s, ext R factor=%s\n"
"%s MOS LQ=%s, MOS CQ=%s\n"
"%s config : PLC=%s, JB=%s, JB rate=%s, Gmin=%d\n"
"%s JB delay : cur=%d%s, max=%d%s, abs max=%d%s",
indent,
last_update,
/* packets */
indent,
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 */
indent,
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 */
indent,
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 */
indent,
xr_stat.rx.voip_mtc.rnd_trip_delay, "ms",
xr_stat.rx.voip_mtc.end_sys_delay, "ms",
/* level */
indent,
signal_lvl, "dB",
noise_lvl, "dB",
rerl, "",
/* quality */
indent,
r_factor, ext_r_factor,
indent,
mos_lq, mos_cq,
/* config */
indent,
plc, jba, jbr, xr_stat.rx.voip_mtc.gmin,
/* JB delay */
indent,
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"
);
VALIDATE_PRINT_BUF();
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);
}
len = pj_ansi_snprintf(p, end-p,
"%s TX last update: %s\n"
"%s packets : loss rate=%d (%.2f%%), discard rate=%d (%.2f%%)\n"
"%s burst : density=%d (%.2f%%), duration=%d%s\n"
"%s gap : density=%d (%.2f%%), duration=%d%s\n"
"%s delay : round trip=%d%s, end system=%d%s\n"
"%s level : signal=%s%s, noise=%s%s, RERL=%s%s\n"
"%s quality : R factor=%s, ext R factor=%s\n"
"%s MOS LQ=%s, MOS CQ=%s\n"
"%s config : PLC=%s, JB=%s, JB rate=%s, Gmin=%d\n"
"%s JB delay : cur=%d%s, max=%d%s, abs max=%d%s",
indent,
last_update,
/* pakcets */
indent,
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 */
indent,
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 */
indent,
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 */
indent,
xr_stat.tx.voip_mtc.rnd_trip_delay, "ms",
xr_stat.tx.voip_mtc.end_sys_delay, "ms",
/* level */
indent,
signal_lvl, "dB",
noise_lvl, "dB",
rerl, "",
/* quality */
indent,
r_factor, ext_r_factor,
indent,
mos_lq, mos_cq,
/* config */
indent,
plc, jba, jbr, xr_stat.tx.voip_mtc.gmin,
/* JB delay */
indent,
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"
);
VALIDATE_PRINT_BUF();
/* RTT delay (by receiver side) */
len = pj_ansi_snprintf(p, end-p,
"%s RTT (from recv) min avg max last dev",
indent);
VALIDATE_PRINT_BUF();
len = pj_ansi_snprintf(p, end-p,
"%s RTT msec : %7.3f %7.3f %7.3f %7.3f %7.3f",
indent,
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
);
VALIDATE_PRINT_BUF();
} /* if audio */;
#endif
}
/*
* 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 */
}
static int sleep_duration_test(void)
{
enum { MIS = 20};
unsigned duration[] = { 2000, 1000, 500, 200, 100 };
unsigned i;
pj_status_t rc;
PJ_LOG(3,(THIS_FILE, "..running sleep duration test"));
/* Test pj_thread_sleep() and pj_gettimeofday() */
for (i=0; i<PJ_ARRAY_SIZE(duration); ++i) {
pj_time_val start, stop;
pj_uint32_t msec;
/* Mark start of test. */
rc = pj_gettimeofday(&start);
if (rc != PJ_SUCCESS) {
app_perror("...error: pj_gettimeofday()", rc);
return -10;
}
/* Sleep */
rc = pj_thread_sleep(duration[i]);
if (rc != PJ_SUCCESS) {
app_perror("...error: pj_thread_sleep()", rc);
return -20;
}
/* Mark end of test. */
rc = pj_gettimeofday(&stop);
/* Calculate duration (store in stop). */
PJ_TIME_VAL_SUB(stop, start);
/* Convert to msec. */
msec = PJ_TIME_VAL_MSEC(stop);
/* Check if it's within range. */
if (msec < duration[i] * (100-MIS)/100 ||
msec > duration[i] * (100+MIS)/100)
{
PJ_LOG(3,(THIS_FILE,
"...error: slept for %d ms instead of %d ms "
"(outside %d%% err window)",
msec, duration[i], MIS));
return -30;
}
}
/* Test pj_thread_sleep() and pj_get_timestamp() and friends */
for (i=0; i<PJ_ARRAY_SIZE(duration); ++i) {
pj_time_val t1, t2;
pj_timestamp start, stop;
pj_uint32_t msec;
pj_thread_sleep(0);
/* Mark start of test. */
rc = pj_get_timestamp(&start);
if (rc != PJ_SUCCESS) {
app_perror("...error: pj_get_timestamp()", rc);
return -60;
}
/* ..also with gettimeofday() */
pj_gettimeofday(&t1);
/* Sleep */
rc = pj_thread_sleep(duration[i]);
if (rc != PJ_SUCCESS) {
app_perror("...error: pj_thread_sleep()", rc);
return -70;
}
/* Mark end of test. */
pj_get_timestamp(&stop);
/* ..also with gettimeofday() */
pj_gettimeofday(&t2);
/* Compare t1 and t2. */
if (PJ_TIME_VAL_LT(t2, t1)) {
PJ_LOG(3,(THIS_FILE, "...error: t2 is less than t1!!"));
return -75;
}
/* Get elapsed time in msec */
msec = pj_elapsed_msec(&start, &stop);
/* Check if it's within range. */
if (msec < duration[i] * (100-MIS)/100 ||
msec > duration[i] * (100+MIS)/100)
{
PJ_LOG(3,(THIS_FILE,
"...error: slept for %d ms instead of %d ms "
"(outside %d%% err window)",
msec, duration[i], MIS));
PJ_TIME_VAL_SUB(t2, t1);
PJ_LOG(3,(THIS_FILE,
"...info: gettimeofday() reported duration is "
"%d msec",
PJ_TIME_VAL_MSEC(t2)));
return -76;
}
}
/* All done. */
return 0;
}
/* Test will perform multiple clients trying to connect to single server.
* Once SSL connection established, echo test will be performed.
*/
static int perf_test(unsigned clients, unsigned ms_handshake_timeout)
{
pj_pool_t *pool = NULL;
pj_ioqueue_t *ioqueue = NULL;
pj_timer_heap_t *timer = NULL;
pj_ssl_sock_t *ssock_serv = NULL;
pj_ssl_sock_t **ssock_cli = NULL;
pj_ssl_sock_param param;
struct test_state state_serv = { 0 };
struct test_state *state_cli = NULL;
pj_sockaddr addr, listen_addr;
pj_ssl_cert_t *cert = NULL;
pj_status_t status;
unsigned i, cli_err = 0, tot_sent = 0, tot_recv = 0;
pj_time_val start;
pool = pj_pool_create(mem, "ssl_perf", 256, 256, NULL);
status = pj_ioqueue_create(pool, PJ_IOQUEUE_MAX_HANDLES, &ioqueue);
if (status != PJ_SUCCESS) {
goto on_return;
}
status = pj_timer_heap_create(pool, PJ_IOQUEUE_MAX_HANDLES, &timer);
if (status != PJ_SUCCESS) {
goto on_return;
}
/* Set cert */
{
pj_str_t tmp1, tmp2, tmp3, tmp4;
status = pj_ssl_cert_load_from_files(pool,
pj_strset2(&tmp1, (char*)CERT_CA_FILE),
pj_strset2(&tmp2, (char*)CERT_FILE),
pj_strset2(&tmp3, (char*)CERT_PRIVKEY_FILE),
pj_strset2(&tmp4, (char*)CERT_PRIVKEY_PASS),
&cert);
if (status != PJ_SUCCESS) {
goto on_return;
}
}
pj_ssl_sock_param_default(¶m);
param.cb.on_accept_complete = &ssl_on_accept_complete;
param.cb.on_connect_complete = &ssl_on_connect_complete;
param.cb.on_data_read = &ssl_on_data_read;
param.cb.on_data_sent = &ssl_on_data_sent;
param.ioqueue = ioqueue;
param.timer_heap = timer;
param.timeout.sec = 0;
param.timeout.msec = ms_handshake_timeout;
pj_time_val_normalize(¶m.timeout);
/* Init default bind address */
{
pj_str_t tmp_st;
pj_sockaddr_init(PJ_AF_INET, &addr, pj_strset2(&tmp_st, "127.0.0.1"), 0);
}
/* SERVER */
param.user_data = &state_serv;
state_serv.pool = pool;
state_serv.echo = PJ_TRUE;
state_serv.is_server = PJ_TRUE;
status = pj_ssl_sock_create(pool, ¶m, &ssock_serv);
if (status != PJ_SUCCESS) {
goto on_return;
}
status = pj_ssl_sock_set_certificate(ssock_serv, pool, cert);
if (status != PJ_SUCCESS) {
goto on_return;
}
status = pj_ssl_sock_start_accept(ssock_serv, pool, &addr, pj_sockaddr_get_len(&addr));
if (status != PJ_SUCCESS) {
goto on_return;
}
/* Get listening address for clients to connect to */
{
pj_ssl_sock_info info;
char buf[64];
pj_ssl_sock_get_info(ssock_serv, &info);
pj_sockaddr_cp(&listen_addr, &info.local_addr);
pj_sockaddr_print((pj_sockaddr_t*)&listen_addr, buf, sizeof(buf), 1);
PJ_LOG(3, ("", "...Listener ready at %s", buf));
}
/* CLIENTS */
clients_num = clients;
param.timeout.sec = 0;
param.timeout.msec = 0;
/* Init random seed */
{
pj_time_val now;
pj_gettimeofday(&now);
pj_srand((unsigned)now.sec);
}
/* Allocate SSL socket pointers and test state */
ssock_cli = pj_pool_calloc(pool, clients, sizeof(pj_ssl_sock_t*));
state_cli = pj_pool_calloc(pool, clients, sizeof(struct test_state));
/* Get start timestamp */
pj_gettimeofday(&start);
/* Setup clients */
for (i = 0; i < clients; ++i) {
param.user_data = &state_cli[i];
state_cli[i].pool = pool;
state_cli[i].check_echo = PJ_TRUE;
state_cli[i].send_str_len = (pj_rand() % 5 + 1) * 1024 + pj_rand() % 1024;
state_cli[i].send_str = pj_pool_alloc(pool, state_cli[i].send_str_len);
{
unsigned j;
for (j = 0; j < state_cli[i].send_str_len; ++j)
state_cli[i].send_str[j] = (char)(pj_rand() % 256);
}
status = pj_ssl_sock_create(pool, ¶m, &ssock_cli[i]);
if (status != PJ_SUCCESS) {
app_perror("...ERROR pj_ssl_sock_create()", status);
cli_err++;
clients_num--;
continue;
}
status = pj_ssl_sock_start_connect(ssock_cli[i], pool, &addr, &listen_addr, pj_sockaddr_get_len(&addr));
if (status == PJ_SUCCESS) {
ssl_on_connect_complete(ssock_cli[i], PJ_SUCCESS);
} else if (status == PJ_EPENDING) {
status = PJ_SUCCESS;
} else {
app_perror("...ERROR pj_ssl_sock_create()", status);
pj_ssl_sock_close(ssock_cli[i]);
ssock_cli[i] = NULL;
clients_num--;
cli_err++;
continue;
}
/* Give chance to server to accept this client */
{
unsigned n = 5;
#ifdef PJ_SYMBIAN
while(n && pj_symbianos_poll(-1, 1000))
n--;
#else
pj_time_val delay = {0, 100};
while(n && pj_ioqueue_poll(ioqueue, &delay) > 0)
n--;
#endif
}
}
/* Wait until everything has been sent/received or error */
while (clients_num)
{
#ifdef PJ_SYMBIAN
pj_symbianos_poll(-1, 1000);
#else
pj_time_val delay = {0, 100};
pj_ioqueue_poll(ioqueue, &delay);
pj_timer_heap_poll(timer, &delay);
#endif
}
/* Clean up sockets */
{
pj_time_val delay = {0, 500};
while (pj_ioqueue_poll(ioqueue, &delay) > 0);
}
if (state_serv.err != PJ_SUCCESS) {
status = state_serv.err;
goto on_return;
}
PJ_LOG(3, ("", "...Done!"));
/* SSL setup and data transfer duration */
{
pj_time_val stop;
pj_gettimeofday(&stop);
PJ_TIME_VAL_SUB(stop, start);
PJ_LOG(3, ("", ".....Setup & data transfer duration: %d.%03ds", stop.sec, stop.msec));
}
/* Check clients status */
for (i = 0; i < clients; ++i) {
if (state_cli[i].err != PJ_SUCCESS)
cli_err++;
tot_sent += state_cli[1].sent;
tot_recv += state_cli[1].recv;
}
PJ_LOG(3, ("", ".....Clients: %d (%d errors)", clients, cli_err));
PJ_LOG(3, ("", ".....Total sent/recv: %d/%d bytes", tot_sent, tot_recv));
on_return:
if (ssock_serv)
pj_ssl_sock_close(ssock_serv);
for (i = 0; i < clients; ++i) {
if (ssock_cli[i] && !state_cli[i].err && !state_cli[i].done)
pj_ssl_sock_close(ssock_cli[i]);
}
if (ioqueue)
pj_ioqueue_destroy(ioqueue);
if (pool)
pj_pool_release(pool);
return status;
}
/*
* This is the handler to receive message for this test. It is used to
* control and verify the behavior of the message transmitted by the
* transaction.
*/
static pj_bool_t msg_receiver_on_rx_request(pjsip_rx_data *rdata)
{
if (pj_strcmp2(&rdata->msg_info.via->branch_param, TEST1_BRANCH_ID) == 0) {
/*
* The TEST1_BRANCH_ID test performs the verifications for transaction
* retransmission mechanism. It will not answer the incoming request
* with any response.
*/
pjsip_msg *msg = rdata->msg_info.msg;
PJ_LOG(4,(THIS_FILE, " received request"));
/* Only wants to take INVITE or OPTIONS method. */
if (msg->line.req.method.id != PJSIP_INVITE_METHOD &&
msg->line.req.method.id != PJSIP_OPTIONS_METHOD)
{
PJ_LOG(3,(THIS_FILE, " error: received unexpected method %.*s",
msg->line.req.method.name.slen,
msg->line.req.method.name.ptr));
test_complete = -600;
return PJ_TRUE;
}
if (recv_count == 0) {
recv_count++;
//pj_gettimeofday(&recv_last);
recv_last = rdata->pkt_info.timestamp;
} else {
pj_time_val now;
unsigned msec_expected, msec_elapsed;
int max_received;
//pj_gettimeofday(&now);
now = rdata->pkt_info.timestamp;
PJ_TIME_VAL_SUB(now, recv_last);
msec_elapsed = now.sec*1000 + now.msec;
++recv_count;
msec_expected = (1<<(recv_count-2))*PJSIP_T1_TIMEOUT;
if (msg->line.req.method.id != PJSIP_INVITE_METHOD) {
if (msec_expected > PJSIP_T2_TIMEOUT)
msec_expected = PJSIP_T2_TIMEOUT;
max_received = 11;
} else {
max_received = 7;
}
if (DIFF(msec_expected, msec_elapsed) > TEST1_ALLOWED_DIFF) {
PJ_LOG(3,(THIS_FILE,
" error: expecting retransmission no. %d in %d "
"ms, received in %d ms",
recv_count-1, msec_expected, msec_elapsed));
test_complete = -610;
}
if (recv_count > max_received) {
PJ_LOG(3,(THIS_FILE,
" error: too many messages (%d) received",
recv_count));
test_complete = -620;
}
//pj_gettimeofday(&recv_last);
recv_last = rdata->pkt_info.timestamp;
}
return PJ_TRUE;
} else
if (pj_strcmp2(&rdata->msg_info.via->branch_param, TEST4_BRANCH_ID) == 0) {
/*
* The TEST4_BRANCH_ID test simulates transport failure after several
* retransmissions.
*/
recv_count++;
if (recv_count == TEST4_RETRANSMIT_CNT) {
/* Simulate transport failure. */
pjsip_loop_set_failure(loop, 2, NULL);
} else if (recv_count > TEST4_RETRANSMIT_CNT) {
PJ_LOG(3,(THIS_FILE," error: not expecting %d-th packet!",
recv_count));
test_complete = -631;
}
return PJ_TRUE;
} else
if (pj_strcmp2(&rdata->msg_info.via->branch_param, TEST5_BRANCH_ID) == 0) {
/*
* The TEST5_BRANCH_ID test simulates user terminating the transaction
* after several retransmissions.
*/
recv_count++;
if (recv_count == TEST5_RETRANSMIT_CNT+1) {
pj_str_t key;
pjsip_transaction *tsx;
pjsip_tsx_create_key( rdata->tp_info.pool, &key, PJSIP_ROLE_UAC,
&rdata->msg_info.msg->line.req.method, rdata);
tsx = pjsip_tsx_layer_find_tsx(&key, PJ_TRUE);
if (tsx) {
pjsip_tsx_terminate(tsx, PJSIP_SC_REQUEST_TERMINATED);
pj_mutex_unlock(tsx->mutex);
} else {
PJ_LOG(3,(THIS_FILE, " error: uac transaction not found!"));
test_complete = -633;
}
} else if (recv_count > TEST5_RETRANSMIT_CNT+1) {
PJ_LOG(3,(THIS_FILE," error: not expecting %d-th packet!",
recv_count));
test_complete = -634;
}
return PJ_TRUE;
} else
if (pj_strcmp2(&rdata->msg_info.via->branch_param, TEST6_BRANCH_ID) == 0) {
/*
* The TEST6_BRANCH_ID test successfull non-INVITE transaction.
*/
pj_status_t status;
recv_count++;
if (recv_count > 1) {
PJ_LOG(3,(THIS_FILE," error: not expecting %d-th packet!",
recv_count));
test_complete = -635;
}
status = pjsip_endpt_respond_stateless(endpt, rdata, 202, NULL,
NULL, NULL);
if (status != PJ_SUCCESS) {
app_perror(" error: unable to send response", status);
test_complete = -636;
}
return PJ_TRUE;
} else
if (pj_strcmp2(&rdata->msg_info.via->branch_param, TEST7_BRANCH_ID) == 0) {
/*
* The TEST7_BRANCH_ID test successfull non-INVITE transaction
* with provisional response.
*/
pj_status_t status;
pjsip_response_addr res_addr;
struct response *r;
pjsip_tx_data *tdata;
pj_time_val delay = { 2, 0 };
recv_count++;
if (recv_count > 1) {
PJ_LOG(3,(THIS_FILE," error: not expecting %d-th packet!",
recv_count));
test_complete = -640;
return PJ_TRUE;
}
/* Respond with provisional response */
status = pjsip_endpt_create_response(endpt, rdata, 100, NULL, &tdata);
pj_assert(status == PJ_SUCCESS);
status = pjsip_get_response_addr(tdata->pool, rdata, &res_addr);
pj_assert(status == PJ_SUCCESS);
status = pjsip_endpt_send_response(endpt, &res_addr, tdata,
NULL, NULL);
pj_assert(status == PJ_SUCCESS);
/* Create the final response. */
status = pjsip_endpt_create_response(endpt, rdata, 202, NULL, &tdata);
pj_assert(status == PJ_SUCCESS);
/* Schedule sending final response in couple of of secs. */
r = pj_pool_alloc(tdata->pool, sizeof(*r));
r->res_addr = res_addr;
r->tdata = tdata;
if (r->res_addr.transport)
pjsip_transport_add_ref(r->res_addr.transport);
timer.entry.cb = &send_response_callback;
timer.entry.user_data = r;
pjsip_endpt_schedule_timer(endpt, &timer.entry, &delay);
return PJ_TRUE;
} else
if (pj_strcmp2(&rdata->msg_info.via->branch_param, TEST8_BRANCH_ID) == 0) {
/*
* The TEST8_BRANCH_ID test failed INVITE transaction.
*/
pjsip_method *method;
pj_status_t status;
method = &rdata->msg_info.msg->line.req.method;
recv_count++;
if (method->id == PJSIP_INVITE_METHOD) {
if (recv_count > 1) {
PJ_LOG(3,(THIS_FILE," error: not expecting %d-th packet!",
recv_count));
test_complete = -635;
}
status = pjsip_endpt_respond_stateless(endpt, rdata, 301, NULL,
NULL, NULL);
if (status != PJ_SUCCESS) {
app_perror(" error: unable to send response", status);
test_complete = -636;
}
} else if (method->id == PJSIP_ACK_METHOD) {
if (recv_count == 2) {
pj_str_t key;
pj_time_val delay = { 5, 0 };
/* Schedule timer to destroy transaction after 5 seconds.
* This is to make sure that transaction does not
* retransmit ACK.
*/
pjsip_tsx_create_key(rdata->tp_info.pool, &key,
PJSIP_ROLE_UAC, &pjsip_invite_method,
rdata);
pj_strcpy(&timer.tsx_key, &key);
timer.entry.id = 301;
timer.entry.cb = &terminate_tsx_callback;
pjsip_endpt_schedule_timer(endpt, &timer.entry, &delay);
}
if (recv_count > 2) {
PJ_LOG(3,(THIS_FILE," error: not expecting %d-th packet!",
recv_count));
test_complete = -638;
}
} else {
PJ_LOG(3,(THIS_FILE," error: not expecting %s",
pjsip_rx_data_get_info(rdata)));
test_complete = -639;
}
} else
if (pj_strcmp2(&rdata->msg_info.via->branch_param, TEST9_BRANCH_ID) == 0) {
/*
* The TEST9_BRANCH_ID test failed INVITE transaction with
* provisional response.
*/
pjsip_method *method;
pj_status_t status;
method = &rdata->msg_info.msg->line.req.method;
recv_count++;
if (method->id == PJSIP_INVITE_METHOD) {
pjsip_response_addr res_addr;
struct response *r;
pjsip_tx_data *tdata;
pj_time_val delay = { 2, 0 };
if (recv_count > 1) {
PJ_LOG(3,(THIS_FILE," error: not expecting %d-th packet!",
recv_count));
test_complete = -650;
return PJ_TRUE;
}
/* Respond with provisional response */
status = pjsip_endpt_create_response(endpt, rdata, 100, NULL,
&tdata);
pj_assert(status == PJ_SUCCESS);
status = pjsip_get_response_addr(tdata->pool, rdata, &res_addr);
pj_assert(status == PJ_SUCCESS);
status = pjsip_endpt_send_response(endpt, &res_addr, tdata,
NULL, NULL);
pj_assert(status == PJ_SUCCESS);
/* Create the final response. */
status = pjsip_endpt_create_response(endpt, rdata, 302, NULL,
&tdata);
pj_assert(status == PJ_SUCCESS);
/* Schedule sending final response in couple of of secs. */
r = pj_pool_alloc(tdata->pool, sizeof(*r));
r->res_addr = res_addr;
r->tdata = tdata;
if (r->res_addr.transport)
pjsip_transport_add_ref(r->res_addr.transport);
timer.entry.cb = &send_response_callback;
timer.entry.user_data = r;
pjsip_endpt_schedule_timer(endpt, &timer.entry, &delay);
} else if (method->id == PJSIP_ACK_METHOD) {
if (recv_count == 2) {
pj_str_t key;
pj_time_val delay = { 5, 0 };
/* Schedule timer to destroy transaction after 5 seconds.
* This is to make sure that transaction does not
* retransmit ACK.
*/
pjsip_tsx_create_key(rdata->tp_info.pool, &key,
PJSIP_ROLE_UAC, &pjsip_invite_method,
rdata);
pj_strcpy(&timer.tsx_key, &key);
timer.entry.id = 302;
timer.entry.cb = &terminate_tsx_callback;
pjsip_endpt_schedule_timer(endpt, &timer.entry, &delay);
}
if (recv_count > 2) {
PJ_LOG(3,(THIS_FILE," error: not expecting %d-th packet!",
recv_count));
test_complete = -638;
}
} else {
PJ_LOG(3,(THIS_FILE," error: not expecting %s",
pjsip_rx_data_get_info(rdata)));
test_complete = -639;
}
return PJ_TRUE;
}
return PJ_FALSE;
}
/*
* Message receiver handler.
*/
static pj_bool_t on_rx_message(pjsip_rx_data *rdata)
{
pjsip_msg *msg = rdata->msg_info.msg;
pj_str_t branch_param = rdata->msg_info.via->branch_param;
pj_status_t status;
if (pj_stricmp2(&branch_param, TEST1_BRANCH_ID) == 0 ||
pj_stricmp2(&branch_param, TEST2_BRANCH_ID) == 0)
{
/*
* TEST1_BRANCH_ID tests that non-INVITE transaction transmits 2xx
* final response using correct transport and terminates transaction
* after 32 seconds.
*
* TEST2_BRANCH_ID performs similar test for non-2xx final response.
*/
int status_code = (pj_stricmp2(&branch_param, TEST1_BRANCH_ID) == 0) ?
TEST1_STATUS_CODE : TEST2_STATUS_CODE;
if (msg->type == PJSIP_REQUEST_MSG) {
/* On received request, create UAS and respond with final
* response.
*/
pjsip_transaction *tsx;
status = pjsip_tsx_create_uas(&tsx_user, rdata, &tsx);
if (status != PJ_SUCCESS) {
app_perror(" error: unable to create transaction", status);
test_complete = -110;
return PJ_TRUE;
}
pjsip_tsx_recv_msg(tsx, rdata);
save_key(tsx);
send_response(rdata, tsx, status_code);
} else {
/* Verify the response received. */
++recv_count;
/* Verify status code. */
if (msg->line.status.code != status_code) {
PJ_LOG(3,(THIS_FILE, " error: incorrect status code"));
test_complete = -113;
}
/* Verify that no retransmissions is received. */
if (recv_count > 1) {
PJ_LOG(3,(THIS_FILE, " error: retransmission received"));
test_complete = -114;
}
}
return PJ_TRUE;
} else if (pj_stricmp2(&branch_param, TEST3_BRANCH_ID) == 0) {
/* TEST3_BRANCH_ID tests provisional response. */
if (msg->type == PJSIP_REQUEST_MSG) {
/* On received request, create UAS and respond with provisional
* response, then schedule timer to send final response.
*/
pjsip_transaction *tsx;
status = pjsip_tsx_create_uas(&tsx_user, rdata, &tsx);
if (status != PJ_SUCCESS) {
app_perror(" error: unable to create transaction", status);
test_complete = -116;
return PJ_TRUE;
}
pjsip_tsx_recv_msg(tsx, rdata);
save_key(tsx);
send_response(rdata, tsx, TEST3_PROVISIONAL_CODE);
schedule_send_response(rdata, &tsx->transaction_key,
TEST3_STATUS_CODE, 2000);
} else {
/* Verify the response received. */
++recv_count;
if (recv_count == 1) {
/* Verify status code. */
if (msg->line.status.code != TEST3_PROVISIONAL_CODE) {
PJ_LOG(3,(THIS_FILE, " error: incorrect status code"));
test_complete = -123;
}
} else if (recv_count == 2) {
/* Verify status code. */
if (msg->line.status.code != TEST3_STATUS_CODE) {
PJ_LOG(3,(THIS_FILE, " error: incorrect status code"));
test_complete = -124;
}
} else {
PJ_LOG(3,(THIS_FILE, " error: retransmission received"));
test_complete = -125;
}
}
return PJ_TRUE;
} else if (pj_stricmp2(&branch_param, TEST4_BRANCH_ID) == 0 ||
pj_stricmp2(&branch_param, TEST5_BRANCH_ID) == 0 ||
pj_stricmp2(&branch_param, TEST6_BRANCH_ID) == 0)
{
/* TEST4_BRANCH_ID: absorbs retransmissions in TRYING state. */
/* TEST5_BRANCH_ID: retransmit last response in PROCEEDING state. */
/* TEST6_BRANCH_ID: retransmit last response in COMPLETED state. */
if (msg->type == PJSIP_REQUEST_MSG) {
/* On received request, create UAS. */
pjsip_transaction *tsx;
PJ_LOG(4,(THIS_FILE, " received request (probably retransmission)"));
status = pjsip_tsx_create_uas(&tsx_user, rdata, &tsx);
if (status != PJ_SUCCESS) {
app_perror(" error: unable to create transaction", status);
test_complete = -130;
return PJ_TRUE;
}
pjsip_tsx_recv_msg(tsx, rdata);
save_key(tsx);
if (pj_stricmp2(&branch_param, TEST4_BRANCH_ID) == 0) {
} else if (pj_stricmp2(&branch_param, TEST5_BRANCH_ID) == 0) {
send_response(rdata, tsx, TEST5_PROVISIONAL_CODE);
} else if (pj_stricmp2(&branch_param, TEST6_BRANCH_ID) == 0) {
PJ_LOG(4,(THIS_FILE, " sending provisional response"));
send_response(rdata, tsx, TEST6_PROVISIONAL_CODE);
PJ_LOG(4,(THIS_FILE, " sending final response"));
send_response(rdata, tsx, TEST6_STATUS_CODE);
}
} else {
/* Verify the response received. */
PJ_LOG(4,(THIS_FILE, " received response number %d", recv_count));
++recv_count;
if (pj_stricmp2(&branch_param, TEST4_BRANCH_ID) == 0) {
PJ_LOG(3,(THIS_FILE, " error: not expecting response!"));
test_complete = -132;
} else if (pj_stricmp2(&branch_param, TEST5_BRANCH_ID) == 0) {
if (rdata->msg_info.msg->line.status.code!=TEST5_PROVISIONAL_CODE) {
PJ_LOG(3,(THIS_FILE, " error: incorrect status code!"));
test_complete = -133;
}
if (recv_count > TEST5_RESPONSE_COUNT) {
PJ_LOG(3,(THIS_FILE, " error: not expecting response!"));
test_complete = -134;
}
} else if (pj_stricmp2(&branch_param, TEST6_BRANCH_ID) == 0) {
int code = rdata->msg_info.msg->line.status.code;
switch (recv_count) {
case 1:
if (code != TEST6_PROVISIONAL_CODE) {
PJ_LOG(3,(THIS_FILE, " error: invalid code!"));
test_complete = -135;
}
break;
case 2:
case 3:
if (code != TEST6_STATUS_CODE) {
PJ_LOG(3,(THIS_FILE, " error: invalid code %d "
"(expecting %d)", code, TEST6_STATUS_CODE));
test_complete = -136;
}
break;
default:
PJ_LOG(3,(THIS_FILE, " error: not expecting response"));
test_complete = -137;
break;
}
}
}
return PJ_TRUE;
} else if (pj_stricmp2(&branch_param, TEST7_BRANCH_ID) == 0 ||
pj_stricmp2(&branch_param, TEST8_BRANCH_ID) == 0)
{
/*
* TEST7_BRANCH_ID and TEST8_BRANCH_ID test the retransmission
* of INVITE final response
*/
if (msg->type == PJSIP_REQUEST_MSG) {
/* On received request, create UAS. */
pjsip_transaction *tsx;
status = pjsip_tsx_create_uas(&tsx_user, rdata, &tsx);
if (status != PJ_SUCCESS) {
app_perror(" error: unable to create transaction", status);
test_complete = -140;
return PJ_TRUE;
}
pjsip_tsx_recv_msg(tsx, rdata);
save_key(tsx);
if (pj_stricmp2(&branch_param, TEST7_BRANCH_ID) == 0) {
send_response(rdata, tsx, TEST7_STATUS_CODE);
} else {
send_response(rdata, tsx, TEST8_STATUS_CODE);
}
} else {
int code;
++recv_count;
if (pj_stricmp2(&branch_param, TEST7_BRANCH_ID) == 0)
code = TEST7_STATUS_CODE;
else
code = TEST8_STATUS_CODE;
if (recv_count==1) {
if (rdata->msg_info.msg->line.status.code != code) {
PJ_LOG(3,(THIS_FILE," error: invalid status code"));
test_complete = -141;
}
recv_last = rdata->pkt_info.timestamp;
} else {
pj_time_val now;
unsigned msec, msec_expected;
now = rdata->pkt_info.timestamp;
PJ_TIME_VAL_SUB(now, recv_last);
msec = now.sec*1000 + now.msec;
msec_expected = (1 << (recv_count-2)) * pjsip_cfg()->tsx.t1;
if (msec_expected > pjsip_cfg()->tsx.t2)
msec_expected = pjsip_cfg()->tsx.t2;
if (DIFF(msec, msec_expected) > MAX_ALLOWED_DIFF) {
PJ_LOG(3,(THIS_FILE,
" error: incorrect retransmission "
"time (%d ms expected, %d ms received",
msec_expected, msec));
test_complete = -142;
}
if (recv_count > 11) {
PJ_LOG(3,(THIS_FILE," error: too many responses (%d)",
recv_count));
test_complete = -143;
}
recv_last = rdata->pkt_info.timestamp;
}
}
return PJ_TRUE;
} else if (pj_stricmp2(&branch_param, TEST9_BRANCH_ID) == 0) {
/*
* TEST9_BRANCH_ID tests that the retransmission of INVITE final
* response should cease when ACK is received. Transaction also MUST
* terminate in T4 seconds.
*/
if (msg->type == PJSIP_REQUEST_MSG) {
/* On received request, create UAS. */
pjsip_transaction *tsx;
status = pjsip_tsx_create_uas(&tsx_user, rdata, &tsx);
if (status != PJ_SUCCESS) {
app_perror(" error: unable to create transaction", status);
test_complete = -150;
return PJ_TRUE;
}
pjsip_tsx_recv_msg(tsx, rdata);
save_key(tsx);
send_response(rdata, tsx, TEST9_STATUS_CODE);
} else {
++recv_count;
if (rdata->msg_info.msg->line.status.code != TEST9_STATUS_CODE) {
PJ_LOG(3,(THIS_FILE," error: invalid status code"));
test_complete = -151;
}
if (recv_count==1) {
recv_last = rdata->pkt_info.timestamp;
} else if (recv_count < 5) {
/* Let UAS retransmit some messages before we send ACK. */
pj_time_val now;
unsigned msec, msec_expected;
now = rdata->pkt_info.timestamp;
PJ_TIME_VAL_SUB(now, recv_last);
msec = now.sec*1000 + now.msec;
msec_expected = (1 << (recv_count-2)) * pjsip_cfg()->tsx.t1;
if (msec_expected > pjsip_cfg()->tsx.t2)
msec_expected = pjsip_cfg()->tsx.t2;
if (DIFF(msec, msec_expected) > MAX_ALLOWED_DIFF) {
PJ_LOG(3,(THIS_FILE,
" error: incorrect retransmission "
"time (%d ms expected, %d ms received",
msec_expected, msec));
test_complete = -152;
}
recv_last = rdata->pkt_info.timestamp;
} else if (recv_count == 5) {
pjsip_tx_data *tdata;
pjsip_sip_uri *uri;
pjsip_via_hdr *via;
status = pjsip_endpt_create_request_from_hdr(
endpt, &pjsip_ack_method,
rdata->msg_info.to->uri,
rdata->msg_info.from,
rdata->msg_info.to,
NULL,
rdata->msg_info.cid,
rdata->msg_info.cseq->cseq,
NULL,
&tdata);
if (status != PJ_SUCCESS) {
app_perror(" error: unable to create ACK", status);
test_complete = -153;
return PJ_TRUE;
}
uri=(pjsip_sip_uri*)pjsip_uri_get_uri(tdata->msg->line.req.uri);
uri->transport_param = pj_str("loop-dgram");
via = (pjsip_via_hdr*) pjsip_msg_find_hdr(tdata->msg, PJSIP_H_VIA, NULL);
via->branch_param = pj_str(TEST9_BRANCH_ID);
status = pjsip_endpt_send_request_stateless(endpt, tdata,
NULL, NULL);
if (status != PJ_SUCCESS) {
app_perror(" error: unable to send ACK", status);
test_complete = -154;
}
} else {
PJ_LOG(3,(THIS_FILE," error: too many responses (%d)",
recv_count));
test_complete = -155;
}
}
return PJ_TRUE;
} else if (pj_stricmp2(&branch_param, TEST10_BRANCH_ID) == 0 ||
pj_stricmp2(&branch_param, TEST11_BRANCH_ID) == 0 ||
pj_stricmp2(&branch_param, TEST12_BRANCH_ID) == 0)
{
int test_num, code1, code2;
if (pj_stricmp2(&branch_param, TEST10_BRANCH_ID) == 0)
test_num=10, code1 = 100, code2 = 0;
else if (pj_stricmp2(&branch_param, TEST11_BRANCH_ID) == 0)
test_num=11, code1 = 100, code2 = 200;
else
test_num=12, code1 = 200, code2 = 0;
if (rdata->msg_info.msg->type == PJSIP_REQUEST_MSG) {
/* On received response, create UAS. */
pjsip_transaction *tsx;
status = pjsip_tsx_create_uas(&tsx_user, rdata, &tsx);
if (status != PJ_SUCCESS) {
app_perror(" error: unable to create transaction", status);
test_complete = -150;
return PJ_TRUE;
}
pjsip_tsx_recv_msg(tsx, rdata);
save_key(tsx);
schedule_send_response(rdata, &tsx_key, code1, 1000);
if (code2)
schedule_send_response(rdata, &tsx_key, code2, 2000);
} else {
}
return PJ_TRUE;
}
return PJ_FALSE;
}
/*
* Get NTP time.
*/
PJ_DEF(pj_status_t) pjmedia_rtcp_get_ntp_time(const pjmedia_rtcp_session *sess,
pjmedia_rtcp_ntp_rec *ntp)
{
/* Seconds between 1900-01-01 to 1970-01-01 */
#define JAN_1970 (2208988800UL)
pj_timestamp ts;
pj_status_t status;
status = pj_get_timestamp(&ts);
/* Fill up the high 32bit part */
ntp->hi = (pj_uint32_t)((ts.u64 - sess->ts_base.u64) / sess->ts_freq.u64)
+ sess->tv_base.sec + JAN_1970;
/* Calculate seconds fractions */
ts.u64 = (ts.u64 - sess->ts_base.u64) % sess->ts_freq.u64;
pj_assert(ts.u64 < sess->ts_freq.u64);
ts.u64 = (ts.u64 << 32) / sess->ts_freq.u64;
/* Fill up the low 32bit part */
ntp->lo = ts.u32.lo;
#if (defined(PJ_WIN32) && PJ_WIN32!=0) || \
(defined(PJ_WIN32_WINCE) && PJ_WIN32_WINCE!=0)
/* On Win32, since we use QueryPerformanceCounter() as the backend
* timestamp API, we need to protect against this bug:
* Performance counter value may unexpectedly leap forward
* http://support.microsoft.com/default.aspx?scid=KB;EN-US;Q274323
*/
{
/*
* Compare elapsed time reported by timestamp with actual elapsed
* time. If the difference is too excessive, then we use system
* time instead.
*/
/* MIN_DIFF needs to be large enough so that "normal" diff caused
* by system activity or context switch doesn't trigger the time
* correction.
*/
enum { MIN_DIFF = 400 };
pj_time_val ts_time, elapsed, diff;
pj_gettimeofday(&elapsed);
ts_time.sec = ntp->hi - sess->tv_base.sec - JAN_1970;
ts_time.msec = (long)(ntp->lo * 1000.0 / 0xFFFFFFFF);
PJ_TIME_VAL_SUB(elapsed, sess->tv_base);
if (PJ_TIME_VAL_LT(ts_time, elapsed)) {
diff = elapsed;
PJ_TIME_VAL_SUB(diff, ts_time);
} else {
diff = ts_time;
PJ_TIME_VAL_SUB(diff, elapsed);
}
if (PJ_TIME_VAL_MSEC(diff) >= MIN_DIFF) {
TRACE_((sess->name, "RTCP NTP timestamp corrected by %d ms",
PJ_TIME_VAL_MSEC(diff)));
ntp->hi = elapsed.sec + sess->tv_base.sec + JAN_1970;
ntp->lo = (elapsed.msec * 65536 / 1000) << 16;
}
}
#endif
return status;
}
PJ_DECL(pj_status_t) pjstun_get_mapped_addr( pj_pool_factory *pf,
int sock_cnt, pj_sock_t sock[],
const pj_str_t *srv1, int port1,
const pj_str_t *srv2, int port2,
pj_sockaddr_in mapped_addr[])
{
pj_sockaddr_in srv_addr[2];
int i, j, send_cnt = 0;
pj_pool_t *pool;
struct {
struct {
pj_uint32_t mapped_addr;
pj_uint32_t mapped_port;
} srv[2];
} *rec;
void *out_msg;
pj_size_t out_msg_len;
int wait_resp = 0;
pj_status_t status;
PJ_CHECK_STACK();
/* Create pool. */
pool = pj_pool_create(pf, "stun%p", 1024, 1024, NULL);
if (!pool)
return PJ_ENOMEM;
/* Allocate client records */
rec = pj_pool_calloc(pool, sock_cnt, sizeof(*rec));
if (!rec) {
status = PJ_ENOMEM;
goto on_error;
}
/* Create the outgoing BIND REQUEST message template */
status = pjstun_create_bind_req( pool, &out_msg, &out_msg_len,
pj_rand(), pj_rand());
if (status != PJ_SUCCESS)
goto on_error;
/* Resolve servers. */
status = pj_sockaddr_in_init(&srv_addr[0], srv1, (pj_uint16_t)port1);
if (status != PJ_SUCCESS)
goto on_error;
status = pj_sockaddr_in_init(&srv_addr[1], srv2, (pj_uint16_t)port2);
if (status != PJ_SUCCESS)
goto on_error;
/* Init mapped addresses to zero */
pj_memset(mapped_addr, 0, sock_cnt * sizeof(pj_sockaddr_in));
/* Main retransmission loop. */
for (send_cnt=0; send_cnt<MAX_REQUEST; ++send_cnt) {
pj_time_val next_tx, now;
pj_fd_set_t r;
int select_rc;
PJ_FD_ZERO(&r);
/* Send messages to servers that has not given us response. */
for (i=0; i<sock_cnt && status==PJ_SUCCESS; ++i) {
for (j=0; j<2 && status==PJ_SUCCESS; ++j) {
pjstun_msg_hdr *msg_hdr = out_msg;
pj_ssize_t sent_len;
if (rec[i].srv[j].mapped_port != 0)
continue;
/* Modify message so that we can distinguish response. */
msg_hdr->tsx[2] = pj_htonl(i);
msg_hdr->tsx[3] = pj_htonl(j);
/* Send! */
sent_len = out_msg_len;
status = pj_sock_sendto(sock[i], out_msg, &sent_len, 0,
(pj_sockaddr_t*)&srv_addr[j],
sizeof(pj_sockaddr_in));
if (status == PJ_SUCCESS)
++wait_resp;
}
}
/* All requests sent.
* The loop below will wait for responses until all responses have
* been received (i.e. wait_resp==0) or timeout occurs, which then
* we'll go to the next retransmission iteration.
*/
/* Calculate time of next retransmission. */
pj_gettimeofday(&next_tx);
next_tx.sec += (stun_timer[send_cnt]/1000);
next_tx.msec += (stun_timer[send_cnt]%1000);
pj_time_val_normalize(&next_tx);
for (pj_gettimeofday(&now), select_rc=1;
status==PJ_SUCCESS && select_rc==1 && wait_resp>0
&& PJ_TIME_VAL_LT(now, next_tx);
pj_gettimeofday(&now))
{
pj_time_val timeout;
timeout = next_tx;
PJ_TIME_VAL_SUB(timeout, now);
for (i=0; i<sock_cnt; ++i) {
PJ_FD_SET(sock[i], &r);
}
select_rc = pj_sock_select(FD_SETSIZE, &r, NULL, NULL, &timeout);
if (select_rc < 1)
continue;
for (i=0; i<sock_cnt; ++i) {
int sock_idx, srv_idx;
pj_ssize_t len;
pjstun_msg msg;
pj_sockaddr_in addr;
int addrlen = sizeof(addr);
pjstun_mapped_addr_attr *attr;
char recv_buf[128];
if (!PJ_FD_ISSET(sock[i], &r))
continue;
len = sizeof(recv_buf);
status = pj_sock_recvfrom( sock[i], recv_buf,
&len, 0,
(pj_sockaddr_t*)&addr,
&addrlen);
--wait_resp;
if (status != PJ_SUCCESS)
continue;
status = pjstun_parse_msg(recv_buf, len, &msg);
if (status != PJ_SUCCESS) {
continue;
}
sock_idx = pj_ntohl(msg.hdr->tsx[2]);
srv_idx = pj_ntohl(msg.hdr->tsx[3]);
if (sock_idx<0 || sock_idx>=sock_cnt || srv_idx<0 || srv_idx>=2) {
status = PJLIB_UTIL_ESTUNININDEX;
continue;
}
if (pj_ntohs(msg.hdr->type) != PJSTUN_BINDING_RESPONSE) {
status = PJLIB_UTIL_ESTUNNOBINDRES;
continue;
}
if (pjstun_msg_find_attr(&msg, PJSTUN_ATTR_ERROR_CODE) != NULL) {
status = PJLIB_UTIL_ESTUNRECVERRATTR;
continue;
}
attr = (void*)pjstun_msg_find_attr(&msg, PJSTUN_ATTR_MAPPED_ADDR);
if (!attr) {
status = PJLIB_UTIL_ESTUNNOMAP;
continue;
}
rec[sock_idx].srv[srv_idx].mapped_addr = attr->addr;
rec[sock_idx].srv[srv_idx].mapped_port = attr->port;
}
}
/* The best scenario is if all requests have been replied.
* Then we don't need to go to the next retransmission iteration.
*/
if (wait_resp <= 0)
break;
}
for (i=0; i<sock_cnt && status==PJ_SUCCESS; ++i) {
if (rec[i].srv[0].mapped_addr == rec[i].srv[1].mapped_addr &&
rec[i].srv[0].mapped_port == rec[i].srv[1].mapped_port)
{
mapped_addr[i].sin_family = PJ_AF_INET;
mapped_addr[i].sin_addr.s_addr = rec[i].srv[0].mapped_addr;
mapped_addr[i].sin_port = (pj_uint16_t)rec[i].srv[0].mapped_port;
if (rec[i].srv[0].mapped_addr == 0 || rec[i].srv[0].mapped_port == 0) {
status = PJLIB_UTIL_ESTUNNOTRESPOND;
break;
}
} else {
status = PJLIB_UTIL_ESTUNSYMMETRIC;
break;
}
}
pj_pool_release(pool);
return status;
on_error:
if (pool) pj_pool_release(pool);
return status;
}
Pj_Time_Val & operator -= (const Pj_Time_Val &rhs)
{
PJ_TIME_VAL_SUB((*this), rhs);
return *this;
}
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);
}
