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"); }