void
print_pulse(pps_info_ffc_t *pi)
{
ffcounter delta_ffc;
struct timespec delta_ts;
struct timespec *assert_ts, *clear_ts;
assert_ts = (struct timespec *) &(pi->assert_tu);
clear_ts = (struct timespec *) &(pi->clear_tu);
delta_ts = *clear_ts;
ts_sub(&delta_ts, assert_ts);
delta_ffc = pi->clear_ffcount - pi->assert_ffcount;
fprintf(stdout, "ASSERT: %llu %ld.%09lu %8d | "
"CLEAR: %llu %ld.%09lu %8d | "
"DELTA: %8llu %2ld.%09lu | "
"MODE: %d\n",
(long long unsigned)pi->assert_ffcount,
assert_ts->tv_sec, assert_ts->tv_nsec,
pi->assert_sequence,
(long long unsigned) pi->clear_ffcount,
clear_ts->tv_sec, clear_ts->tv_nsec, pi->clear_sequence,
(long long unsigned)delta_ffc, delta_ts.tv_sec, delta_ts.tv_nsec,
pi->current_mode);
fflush(stdout);
}
/// Replacement pthread_cond_timedwait()
///
/// WARNING: This replacement calls through to the 2.3.2 version of the
/// real pthread_cond_timedwait, regardless of the version the calling code
/// assumed it would be calling. This will need updating to support other
/// libc versions.
///
/// WARNING THE SECOND: This assumes that the condition variable was created
/// with a condattr that specifies CLOCK_MONOTONIC.
///
/// http://blog.fesnel.com/blog/2009/08/25/preloading-with-multiple-symbol-versions/
int pthread_cond_timedwait(pthread_cond_t* cond,
pthread_mutex_t* mutex,
const struct timespec* abstime)
{
struct timespec fixed_time;
if (!real_pthread_cond_timedwait)
{
real_pthread_cond_timedwait = (pthread_cond_timedwait_func_t)(intptr_t)dlvsym(RTLD_NEXT, "pthread_cond_timedwait", "GLIBC_2.3.2");
}
// Subtract our fake time and add the real time, this means the
// relative delay is correct while allowing the calling code to think
// it's woking with absolute time.
//
// Note we call the fake clock_gettime first, meaning that real_clock_gettime
// will be set before the call to it in the next line.
struct timespec fake_time;
struct timespec real_time;
struct timespec delta_time;
clock_gettime(CLOCK_MONOTONIC, &fake_time);
real_clock_gettime(CLOCK_MONOTONIC, &real_time);
ts_sub(*abstime, fake_time, delta_time);
ts_add(real_time, delta_time, fixed_time);
return real_pthread_cond_timedwait(cond, mutex, &fixed_time);
}
int main(int argc, char **argv)
{
long long tnow, tlast;
struct timespec t1, dtmin, dtminp, dtmax;
int print_interval = 50000;
int print_countdown = 1;
int clock_id = CLOCK_MONOTONIC;
dtmin.tv_sec = INT_MAX;
dtmin.tv_nsec = 0;
dtminp.tv_sec = INT_MAX;
dtminp.tv_nsec = 0;
dtmax.tv_sec = 0;
dtmax.tv_nsec = 0;
tlast = 0;
if(argc == 2) {
clock_id = atoi(argv[1]);
printf("using clock %d\n", clock_id);
}
clock_gettime(clock_id, &t1);
for(;;) {
struct timespec t, dt;
clock_gettime(clock_id, &t);
dt = ts_sub(t, t1);
t1 = t;
dtmin = ts_min(dtmin, dt);
if(dt.tv_sec > 0 || dt.tv_nsec > 0)
dtminp = ts_min(dtminp, dt);
if(print_countdown != print_interval)
dtmax = ts_max(dtmax, dt);
if(--print_countdown == 0) {
fprintf(stderr,"%09ld.%09ld, dt %ld.%09ld, min %ld.%09ld, minp %ld.%09ld, max %ld.%09ld\n",
t.tv_sec, t.tv_nsec, dt.tv_sec, dt.tv_nsec,
dtmin.tv_sec, dtmin.tv_nsec, dtminp.tv_sec, dtminp.tv_nsec,
dtmax.tv_sec, dtmax.tv_nsec);
print_countdown = print_interval;
}
}
for(;;) {
tnow = nanotime();
if(tnow < tlast) {
#if 0
fprintf(stderr,"time went backwards: %lld -> %lld\n",
tlast, tnow);
exit(1);
#endif
fprintf(stderr,"%lld ROLLBACK\n", tnow);
} else {
fprintf(stderr,"%lld\n", tnow);
}
tlast = tnow;
}
return 0;
}
void timestamps_to_intervals(ts_t *ti, ts_t *tf, long *dt, int size) {
ts_t *ti_ptr = ti;
ts_t *tf_ptr = tf;
long *dt_ptr = dt;
int i;
ts_t interval;
for(i =0; i < size; i++, ti_ptr++, tf_ptr++, dt_ptr++) {
interval = ts_sub(ti_ptr, tf_ptr);
*dt_ptr = ts_to_l(&interval);
}
}
void
pb_shift_forward(pb_t *pb, timestamp_t delta)
{
pb_node_t *stop, *curr;
pb_validate(pb);
stop = pb->psentinel;
curr = pb->psentinel->next;
while(curr != stop) {
curr->playout = ts_sub(curr->playout, delta);
curr = curr->next;
}
pb_validate(pb);
}
timestamp_t
playout_calc(session_t *sp, uint32_t ssrc, timestamp_t transit, int new_spurt)
/*****************************************************************************/
/* The primary purpose of this function is to calculate the playout point */
/* for new talkspurts (new_spurt). It also maintains the jitter and transit */
/* time estimates from the source to us. The value returned is the local */
/* playout time. */
/*****************************************************************************/
{
timestamp_t delta_transit;
pdb_entry_t *e;
pdb_item_get(sp->pdb, ssrc, &e);
assert(e != NULL);
delta_transit = ts_abs_diff(transit, e->avg_transit);
if (ts_gt(transit, e->avg_transit)) {
e->avg_transit = ts_add(e->avg_transit, ts_div(delta_transit,16));
} else {
e->avg_transit = ts_sub(e->avg_transit, ts_div(delta_transit,16));
}
if (new_spurt == TRUE) {
timestamp_t hvar, jvar; /* Host and jitter components */
debug_msg("New talkspurt\n");
hvar = playout_constraints_component(sp, e);
jvar = ts_mul(e->jitter, PLAYOUT_JITTER_SCALE);
if (ts_gt(hvar, jvar)) {
e->playout = hvar;
} else {
e->playout = jvar;
}
e->transit = e->avg_transit;
} else {
/* delta_transit is abs((s[j+1] - d[j+1]) - (s[j] - d[j])) */
delta_transit = ts_abs_diff(transit, e->last_transit);
/* Update jitter estimate using */
/* jitter = (7/8)jitter + (1/8) new_jitter */
e->jitter = ts_mul(e->jitter, 7);
e->jitter = ts_add(e->jitter, delta_transit);
e->jitter = ts_div(e->jitter, 8);
}
e->last_transit = transit;
return e->playout;
}
int
pb_iterator_audit(pb_iterator_t *pi, timestamp_t history_len)
{
timestamp_t cutoff;
int removed;
pb_node_t *stop, *curr, *next;
pb_t *pb;
#ifdef DEBUG
/* If we are debugging we check we are not deleting
* nodes pointed to by other iterators since this *BAD*
*/
uint16_t i, n_iterators;
pb_iterator_t *iterators = pi->buffer->iterators;
n_iterators = pi->buffer->n_iterators;
#endif
pb_validate(pi->buffer);
pb = pi->buffer;
stop = pi->node;
removed = 0;
if (pi->node != pb->psentinel) {
curr = pb->psentinel->next; /* head */;
cutoff = ts_sub(pi->node->playout, history_len);
while(ts_gt(cutoff, curr->playout)) {
/* About to erase a block an iterator is using! */
#ifdef DEBUG
for(i = 0; i < n_iterators; i++) {
assert(iterators[i].node != curr);
}
#endif
next = curr->next;
curr->next->prev = curr->prev;
curr->prev->next = curr->next;
pb->freeproc(&curr->data, curr->data_len);
pb->n_nodes--;
block_free(curr, sizeof(pb_node_t));
curr = next;
removed ++;
}
}
return removed;
}
void *thread_worker(void* arg)
{
struct timespec start, stop;
int i;
unsigned long long delta;
unsigned long long min=-1, max=0;
stats_container_t dat;
stats_record_t rec;
stats_container_init(&dat, NUMRUNS);
for (i=0; i < NUMRUNS; i++) {
do_work(1); /* warm cache */
/* do test */
clock_gettime(CLOCK_MONOTONIC, &start);
do_work(NUMLOOPS);
clock_gettime(CLOCK_MONOTONIC, &stop);
/* calc delta, min and max */
delta = ts_sub(stop, start);
if (delta < min)
min = delta;
if (delta> max)
max = delta;
rec.x = i;
rec.y = delta;
stats_container_append(&dat, rec);
printf("delta: %llu ns\n", delta);
usleep(1); /* let other things happen */
}
printf("max jitter: ");
print_unit(max - min);
stats_container_save("samples", "Scheduling Jitter Scatter Plot",\
"Iteration", "Delay (ns)", &dat, "points");
return NULL;
}
void ib_ctx_time_converter::fix_hw_clock_deviation(){
ctx_timestamping_params_t* current_parameters_set = &m_ctx_convert_parmeters[m_ctx_parmeters_id];
if (!current_parameters_set->hca_core_clock) {
return;
}
struct timespec current_time, diff_systime;
uint64_t diff_hw_time, diff_systime_nano, estimated_hw_time, hw_clock;
int next_id = (m_ctx_parmeters_id + 1) % 2;
ctx_timestamping_params_t* next_parameters_set = &m_ctx_convert_parmeters[next_id];
int64_t deviation_hw;
if (!sync_clocks(¤t_time, &hw_clock)) {
return;
}
ts_sub(¤t_time, ¤t_parameters_set->sync_systime, &diff_systime);
diff_hw_time = hw_clock - current_parameters_set->sync_hw_clock;
diff_systime_nano = diff_systime.tv_sec * NSEC_PER_SEC + diff_systime.tv_nsec;
estimated_hw_time = (diff_systime.tv_sec * current_parameters_set->hca_core_clock) + (diff_systime.tv_nsec * current_parameters_set->hca_core_clock / NSEC_PER_SEC);
deviation_hw = estimated_hw_time - diff_hw_time;
ibchtc_logdbg("ibv device '%s' [%p] : fix_hw_clock_deviation parameters status : %ld.%09ld since last deviation fix, \nUPDATE_HW_TIMER_PERIOD_MS = %d, current_parameters_set = %p, "
"estimated_hw_time = %ld, diff_hw_time = %ld, diff = %ld ,m_hca_core_clock = %ld", m_p_ibv_context->device->name, m_p_ibv_context->device, diff_systime.tv_sec, diff_systime.tv_nsec,
UPDATE_HW_TIMER_PERIOD_MS, current_parameters_set, estimated_hw_time, diff_hw_time, deviation_hw, current_parameters_set->hca_core_clock);
if (abs(deviation_hw) < IB_CTX_TC_DEVIATION_THRESHOLD) {
return;
}
next_parameters_set->hca_core_clock = (diff_hw_time * NSEC_PER_SEC) / diff_systime_nano;
next_parameters_set->sync_hw_clock = hw_clock;
next_parameters_set->sync_systime = current_time;
m_ctx_parmeters_id = next_id;
}
static void
redundancy_decoder_output(channel_unit *chu, struct s_pb *out, timestamp_t playout)
{
const codec_format_t *cf;
codec_id_t cid;
u_char *hp, *dp, *de, ppt, bpt;
uint32_t hdr32, blen, boff;
timestamp_t ts_max_off, ts_blk_off, this_playout;
hp = dp = chu->data;
de = chu->data + chu->data_len;
/* move data pointer past header */
while (ntohl(*((uint32_t*)dp)) & RED_HDR32_PAT) {
dp += 4;
}
if (dp == hp) {
debug_msg("Not a redundant block\n");
return;
}
/* At this point dp points to primary payload type.
* This is a most useful quantity... */
ppt = *dp;
dp += 1;
assert(dp < de);
/* Max offset should be in first header. Want max offset
* as we nobble timestamps to be:
* playout + max_offset - this_offset
*/
cid = codec_get_by_payload(ppt);
if (codec_id_is_valid(cid) == FALSE) {
debug_msg("Primary not recognized.\n");
return;
}
cf = codec_get_format(cid);
assert(cf != NULL);
hdr32 = ntohl(*(uint32_t*)hp);
ts_max_off = ts_map32(cf->format.sample_rate, RED_HDR32_GET_OFF(hdr32));
blen = 0;
while (hdr32 & RED_HDR32_PAT) {
boff = RED_HDR32_GET_OFF(hdr32);
blen = RED_HDR32_GET_LEN(hdr32);
bpt = (u_char)RED_HDR32_GET_PT(hdr32);
/* Calculate playout point = playout + max_offset - offset */
ts_blk_off = ts_map32(cf->format.sample_rate, boff);
this_playout = ts_add(playout, ts_max_off);
this_playout = ts_sub(this_playout, ts_blk_off);
hp += 4; /* hdr */
red_split_unit(ppt, bpt, dp, blen, this_playout, out);
xmemchk();
dp += blen;
hdr32 = ntohl(*(uint32_t*)hp);
}
this_playout = ts_add(playout, ts_max_off);
hp += 1;
blen = (uint32_t) (de - dp);
red_split_unit(ppt, ppt, dp, blen, this_playout, out);
xmemchk();
}
int main(int argc, char* argv[])
{
struct sched_param sp;
sp.sched_priority = 30;
sched_setscheduler(0, SCHED_FIFO, &sp);
std::cout << "--------------------------------------------------------------------------------" << std::endl;
std::cout << "" << std::endl;
std::cout << "" << std::endl;
std::cout << "Get time using clock_gettime(CLOCK_MONOTONIC):" << std::endl;
int64_t timeall = 0;
timespec* times1 = new timespec[ITERATION_NUM];
for(int i=0;i<ITERATION_NUM;i++){
gettime(×1[i]);
}
for(int i=0;i<ITERATION_NUM-1;i++){
timespec m_elapsed = TIMESPEC_INITIALIZER;
ts_sub(×1[i+1], ×1[i], &m_elapsed);
timeall += ts_to_nsec(&m_elapsed);
//std::cout << i << ": " << ts_to_nsec(&m_elapsed) << std::endl;
}
double clockmon_avg = ((double)timeall)/(ITERATION_NUM-1);
std::cout << "clock_gettime(CLOCK_MONOTONIC) AVG: " << clockmon_avg << " nsec" << std::endl;
std::cout << "--------------------------------------------------------------------------------" << std::endl;
std::cout << "" << std::endl;
std::cout << "" << std::endl;
std::cout << "Get time using RDTSC:" << std::endl;
timeall = 0;
timespec* times2 = new timespec[ITERATION_NUM];
for(int i=0;i<ITERATION_NUM;i++){
gettimerdtsc(×2[i]);
}
for(int i=0;i<ITERATION_NUM-1;i++){
timespec m_elapsed = TIMESPEC_INITIALIZER;
ts_sub(×2[i+1], ×2[i], &m_elapsed);
if (i > 0) timeall += ts_to_nsec(&m_elapsed);
//std::cout << i << ": " << ts_to_nsec(&m_elapsed) << std::endl;
}
double rdtsc_avg = ((double)timeall)/(ITERATION_NUM-2);
std::cout << "RDTSC AVG: " << rdtsc_avg << " nsec" << std::endl;
std::cout << "--------------------------------------------------------------------------------" << std::endl;
std::cout << "" << std::endl;
std::cout << "" << std::endl;
std::cout << "Get time using gettimeofday:" << std::endl;
timeall = 0;
timeval* times = new timeval[ITERATION_NUM];
for(int i=0;i<ITERATION_NUM;i++){
gettime(×[i]);
}
for(int i=0;i<ITERATION_NUM-1;i++){
timeval m_elapsed = TIMEVAL_INITIALIZER;
tv_sub(×[i+1], ×[i], &m_elapsed);
timeall += tv_to_nsec(&m_elapsed);
//std::cout << i << ": " << tv_to_nsec(&m_elapsed) << std::endl;
}
double timeofday_avg = ((double)timeall)/(ITERATION_NUM-1);
std::cout << "gettimeofday AVG: " << timeofday_avg << " nsec" << std::endl;
std::cout << "--------------------------------------------------------------------------------" << std::endl;
std::cout << "" << std::endl;
std::cout << "" << std::endl;
std::cout << "Get time using clock_gettime(CLOCK_MONOTONIC) - low pps:" << std::endl;
timeall = 0;
for(int i=0;i<ITERATION_NUM_LOW_PPS;i++){
usleep(LOW_PPS_SLEEP_USEC);
timespec m_start = TIMESPEC_INITIALIZER;
timespec m_elapsed = TIMESPEC_INITIALIZER;
timespec m_current = TIMESPEC_INITIALIZER;
gettime(&m_start);
gettime(&m_current);
ts_sub(&m_current, &m_start, &m_elapsed);
timeall += ts_to_nsec(&m_elapsed);
//std::cout << i << ": " << ts_to_nsec(&m_elapsed) << std::endl;
}
double clockmon_avg_lowpps = ((double)timeall)/(ITERATION_NUM_LOW_PPS-1);
std::cout << "clock_gettime(CLOCK_MONOTONIC) - low pps AVG: " << clockmon_avg_lowpps << " nsec" << std::endl;
std::cout << "--------------------------------------------------------------------------------" << std::endl;
std::cout << "" << std::endl;
std::cout << "" << std::endl;
std::cout << "Get time using RDTSC - low pps:" << std::endl;
timeall = 0;
for(int i=0;i<ITERATION_NUM_LOW_PPS;i++){
usleep(LOW_PPS_SLEEP_USEC);
timespec m_start = TIMESPEC_INITIALIZER;
timespec m_elapsed = TIMESPEC_INITIALIZER;
timespec m_current = TIMESPEC_INITIALIZER;
gettimerdtsc(&m_start);
gettimerdtsc(&m_current);
ts_sub(&m_current, &m_start, &m_elapsed);
if(i > 0) timeall += ts_to_nsec(&m_elapsed);
//std::cout << i << ": " << ts_to_nsec(&m_elapsed) << std::endl;
}
double rdtsc_avg_lowpps = ((double)timeall)/(ITERATION_NUM_LOW_PPS-2);
std::cout << "RDTSC - low pps AVG: " << rdtsc_avg_lowpps << " nsec" << std::endl;
std::cout << "--------------------------------------------------------------------------------" << std::endl;
std::cout << "" << std::endl;
std::cout << "" << std::endl;
std::cout << "Get time using gettimeofday - low pps:" << std::endl;
timeall = 0;
for(int i=0;i<ITERATION_NUM_LOW_PPS;i++){
usleep(LOW_PPS_SLEEP_USEC);
timeval start = TIMEVAL_INITIALIZER, current = TIMEVAL_INITIALIZER, elapsed = TIMEVAL_INITIALIZER;
gettime(&start);
gettime(¤t);
tv_sub(¤t, &start, &elapsed);
timeall += tv_to_nsec(&elapsed);
//std::cout << i << ": " << tv_to_nsec(&elapsed) << std::endl;
}
double timeofday_avg_lowpps = ((double)timeall)/(ITERATION_NUM_LOW_PPS-1);
std::cout << "gettimeofday - low pps AVG: " << timeofday_avg_lowpps << " nsec" << std::endl;
std::cout << "--------------------------------------------------------------------------------" << std::endl;
std::cout << "" << std::endl;
std::cout << "" << std::endl;
std::cout << "" << std::endl;
std::cout << "SUMMARY:" << std::endl;
std::cout << "" << std::endl;
std::cout << "Timer resolution:" << std::endl;
std::cout << "------------------" << std::endl;
std::cout << "clock_gettime(CLOCK_MONOTONIC) AVG: " << clockmon_avg << " nsec" << std::endl;
std::cout << "RDTSC AVG: " << rdtsc_avg << " nsec" << std::endl;
std::cout << "gettimeofday AVG: " << timeofday_avg << " nsec" << std::endl;
std::cout << "" << std::endl;
std::cout << "Timer resolution - 100 samples per sec:" << std::endl;
std::cout << "----------------------------------------" << std::endl;
std::cout << "clock_gettime(CLOCK_MONOTONIC) - low pps AVG: " << clockmon_avg_lowpps << " nsec" << std::endl;
std::cout << "RDTSC - low pps AVG: " << rdtsc_avg_lowpps << " nsec" << std::endl;
std::cout << "gettimeofday - low pps AVG: " << timeofday_avg_lowpps << " nsec" << std::endl;
delete [] times;
delete [] times1;
delete [] times2;
return 0;
}
/* report bandwidth and t1 */
void TrainEngine::reporting()
{
int s = 0, e = 0, num = 0;
struct timespec tmp;
double min;
int minIndex;
Packet *start[2], *end[2]; // start and end request and response packets
start[0] = NULL;
start[1] = NULL;
end[0] = NULL;
end[1] = NULL;
if (!request_ || !response_)
{
logger->PrintDebug("No train data so no report!\n");
return;
}
for (int i=0; i < trainSize; i++)
{
// find the first packet
if (request_[i] && response_[i])
{
s = i;
break;
}
}
for (int i=trainSize-1; i >= 0; i--)
{
// find the last packet
if (request_[i] && response_[i])
{
e = i;
break;
}
}
for (int i=s; i<=e; i++)
{
// find how many packets between start and end
if (request_[i] && response_[i])
{
if (start[0]==NULL)
{
start[0] = request_[i];
start[1] = response_[i];
end[0] = request_[i];
end[1] = response_[i];
}
else
{
if (start[1]->get_ts().tv_sec > response_[i]->get_ts().tv_sec || (start[1]->get_ts().tv_sec == response_[i]->get_ts().tv_sec && start[1]->get_ts().tv_nsec > response_[i]->get_ts().tv_nsec))
{
start[0] = request_[i];
start[1] = response_[i];
}
if (end[1]->get_ts().tv_sec < response_[i]->get_ts().tv_sec || (end[1]->get_ts().tv_sec == response_[i]->get_ts().tv_sec && end[1]->get_ts().tv_nsec < response_[i]->get_ts().tv_nsec))
{
end[0] = request_[i];
end[1] = response_[i];
}
}
num++;
}
}
num--;
if (num>0)
{
// first packet delay
tmp = start[1]->get_ts();
ts_sub(&tmp, start[0]->get_ts());
t1 = ts2double(tmp);
logger->PrintLog("t1 is %f sec\n", t1);
// bandwidth can be calculated
tmp = end[1]->get_ts();
ts_sub(&tmp, start[1]->get_ts());
logger->PrintLog("e-s is %d, num is %d, delta t is %f sec\n", e-s, num, ts2double(tmp));
//bw = (DEFAULT_MSS*8*(e-s))/ts2double(tmp);
bw = (DEFAULT_MSS*8*num)/ts2double(tmp);
logger->PrintLog("bandwidth is %f bps\n", bw);
}
// tailed dropNum can be calculated
dropNum=trainSize-1-e;
logger->PrintLog("the number of packets dropped at the end is %f\n", dropNum);
// for capacity calculation
for (int j=0; j < trainSize; j++)
{
min = 100000;
minIndex = -1;
for (int i=0; i < trainSize; i++)
{
if (response_[i])
{
if (minIndex == -1 || ts2double(response_[i]->get_ts()) < min)
{
min = ts2double(response_[i]->get_ts());
minIndex = i;
}
}
}
if (minIndex == -1)
{
break;
}
else
{
delete response_[minIndex];
response_[minIndex] = NULL;
}
if (min-ts2double(request_[0]->get_ts()) < minDelay[j])
{
minDelay[j]=min-ts2double(request_[0]->get_ts());
}
}
// minimal delay now
logger->PrintLog("minimal delay: ");
for (int i=0; i<CAPNUM; i++)
{
if (minDelay[i] != 10000)
{
fprintf(stdout, "m[%d]=%f, ", i, minDelay[i]);
}
}
fprintf(stdout, "\n");
// dispersion now
logger->PrintLog("dispersion now: ");
for (int i=1; i<CAPNUM; i++)
{
if (minDelay[i] != 10000)
{
fprintf(stdout, "d[%d]=%f, ", i, minDelay[i]-minDelay[i-1]);
}
}
fprintf(stdout, "\n");
}
